Home | History | Annotate | Download | only in src
      1 // Copyright 2012 the V8 project authors. All rights reserved.
      2 // Use of this source code is governed by a BSD-style license that can be
      3 // found in the LICENSE file.
      4 
      5 #ifndef V8_LOG_H_
      6 #define V8_LOG_H_
      7 
      8 #include <string>
      9 
     10 #include "src/allocation.h"
     11 #include "src/base/compiler-specific.h"
     12 #include "src/base/platform/elapsed-timer.h"
     13 #include "src/base/platform/platform.h"
     14 #include "src/code-events.h"
     15 #include "src/isolate.h"
     16 #include "src/objects.h"
     17 
     18 namespace v8 {
     19 
     20 namespace base {
     21 class Semaphore;
     22 }
     23 
     24 namespace sampler {
     25 class Sampler;
     26 }
     27 
     28 namespace internal {
     29 
     30 // Logger is used for collecting logging information from V8 during
     31 // execution. The result is dumped to a file.
     32 //
     33 // Available command line flags:
     34 //
     35 //  --log
     36 // Minimal logging (no API, code, or GC sample events), default is off.
     37 //
     38 // --log-all
     39 // Log all events to the file, default is off.  This is the same as combining
     40 // --log-api, --log-code, --log-gc, and --log-regexp.
     41 //
     42 // --log-api
     43 // Log API events to the logfile, default is off.  --log-api implies --log.
     44 //
     45 // --log-code
     46 // Log code (create, move, and delete) events to the logfile, default is off.
     47 // --log-code implies --log.
     48 //
     49 // --log-gc
     50 // Log GC heap samples after each GC that can be processed by hp2ps, default
     51 // is off.  --log-gc implies --log.
     52 //
     53 // --log-regexp
     54 // Log creation and use of regular expressions, Default is off.
     55 // --log-regexp implies --log.
     56 //
     57 // --logfile <filename>
     58 // Specify the name of the logfile, default is "v8.log".
     59 //
     60 // --prof
     61 // Collect statistical profiling information (ticks), default is off.  The
     62 // tick profiler requires code events, so --prof implies --log-code.
     63 
     64 // Forward declarations.
     65 class CodeEventListener;
     66 class CpuProfiler;
     67 class Isolate;
     68 class Log;
     69 class PositionsRecorder;
     70 class Profiler;
     71 class Ticker;
     72 struct TickSample;
     73 class RuntimeCallTimer;
     74 
     75 #undef LOG
     76 #define LOG(isolate, Call)                              \
     77   do {                                                  \
     78     v8::internal::Logger* logger = (isolate)->logger(); \
     79     if (logger->is_logging()) logger->Call;             \
     80   } while (false)
     81 
     82 #define LOG_CODE_EVENT(isolate, Call)                   \
     83   do {                                                  \
     84     v8::internal::Logger* logger = (isolate)->logger(); \
     85     if (logger->is_logging_code_events()) logger->Call; \
     86   } while (false)
     87 
     88 class JitLogger;
     89 class PerfBasicLogger;
     90 class LowLevelLogger;
     91 class PerfJitLogger;
     92 class ProfilerListener;
     93 
     94 class Logger : public CodeEventListener {
     95  public:
     96   enum StartEnd { START = 0, END = 1 };
     97 
     98   // Acquires resources for logging if the right flags are set.
     99   bool SetUp(Isolate* isolate);
    100 
    101   // Sets the current code event handler.
    102   void SetCodeEventHandler(uint32_t options,
    103                            JitCodeEventHandler event_handler);
    104 
    105   // Sets up ProfilerListener.
    106   void SetUpProfilerListener();
    107 
    108   // Tear down ProfilerListener if it has no observers.
    109   void TearDownProfilerListener();
    110 
    111   sampler::Sampler* sampler();
    112 
    113   ProfilerListener* profiler_listener() { return profiler_listener_.get(); }
    114 
    115   // Frees resources acquired in SetUp.
    116   // When a temporary file is used for the log, returns its stream descriptor,
    117   // leaving the file open.
    118   FILE* TearDown();
    119 
    120   // Emits an event with a string value -> (name, value).
    121   void StringEvent(const char* name, const char* value);
    122 
    123   // Emits an event with an int value -> (name, value).
    124   void IntEvent(const char* name, int value);
    125   void IntPtrTEvent(const char* name, intptr_t value);
    126 
    127   // Emits an event with an handle value -> (name, location).
    128   void HandleEvent(const char* name, Object** location);
    129 
    130   // Emits memory management events for C allocated structures.
    131   void NewEvent(const char* name, void* object, size_t size);
    132   void DeleteEvent(const char* name, void* object);
    133 
    134   // Emits an event with a tag, and some resource usage information.
    135   // -> (name, tag, <rusage information>).
    136   // Currently, the resource usage information is a process time stamp
    137   // and a real time timestamp.
    138   void ResourceEvent(const char* name, const char* tag);
    139 
    140   // Emits an event that an undefined property was read from an
    141   // object.
    142   void SuspectReadEvent(Name* name, Object* obj);
    143 
    144   // Emits an event when a message is put on or read from a debugging queue.
    145   // DebugTag lets us put a call-site specific label on the event.
    146   void DebugTag(const char* call_site_tag);
    147   void DebugEvent(const char* event_type, Vector<uint16_t> parameter);
    148 
    149 
    150   // ==== Events logged by --log-api. ====
    151   void ApiSecurityCheck();
    152   void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
    153   void ApiIndexedPropertyAccess(const char* tag,
    154                                 JSObject* holder,
    155                                 uint32_t index);
    156   void ApiObjectAccess(const char* tag, JSObject* obj);
    157   void ApiEntryCall(const char* name);
    158 
    159   // ==== Events logged by --log-code. ====
    160   void addCodeEventListener(CodeEventListener* listener);
    161   void removeCodeEventListener(CodeEventListener* listener);
    162 
    163   // Emits a code event for a callback function.
    164   void CallbackEvent(Name* name, Address entry_point);
    165   void GetterCallbackEvent(Name* name, Address entry_point);
    166   void SetterCallbackEvent(Name* name, Address entry_point);
    167   // Emits a code create event.
    168   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    169                        AbstractCode* code, const char* source);
    170   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    171                        AbstractCode* code, Name* name);
    172   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    173                        AbstractCode* code, SharedFunctionInfo* shared,
    174                        Name* name);
    175   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    176                        AbstractCode* code, SharedFunctionInfo* shared,
    177                        Name* source, int line, int column);
    178   void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
    179                        AbstractCode* code, int args_count);
    180   // Emits a code deoptimization event.
    181   void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared);
    182   void CodeMovingGCEvent();
    183   // Emits a code create event for a RegExp.
    184   void RegExpCodeCreateEvent(AbstractCode* code, String* source);
    185   // Emits a code move event.
    186   void CodeMoveEvent(AbstractCode* from, Address to);
    187   // Emits a code line info add event with Postion type.
    188   void CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
    189                                        int pc_offset,
    190                                        int position);
    191   // Emits a code line info add event with StatementPostion type.
    192   void CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
    193                                                 int pc_offset,
    194                                                 int position);
    195   // Emits a code line info start to record event
    196   void CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder);
    197   // Emits a code line info finish record event.
    198   // It's the callee's responsibility to dispose the parameter jit_handler_data.
    199   void CodeEndLinePosInfoRecordEvent(AbstractCode* code,
    200                                      void* jit_handler_data);
    201 
    202   void SharedFunctionInfoMoveEvent(Address from, Address to);
    203 
    204   void CodeNameEvent(Address addr, int pos, const char* code_name);
    205 
    206   void CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta);
    207 
    208   // ==== Events logged by --log-gc. ====
    209   // Heap sampling events: start, end, and individual types.
    210   void HeapSampleBeginEvent(const char* space, const char* kind);
    211   void HeapSampleEndEvent(const char* space, const char* kind);
    212   void HeapSampleItemEvent(const char* type, int number, int bytes);
    213   void HeapSampleJSConstructorEvent(const char* constructor,
    214                                     int number, int bytes);
    215   void HeapSampleJSRetainersEvent(const char* constructor,
    216                                          const char* event);
    217   void HeapSampleJSProducerEvent(const char* constructor,
    218                                  Address* stack);
    219   void HeapSampleStats(const char* space, const char* kind,
    220                        intptr_t capacity, intptr_t used);
    221 
    222   void SharedLibraryEvent(const std::string& library_path, uintptr_t start,
    223                           uintptr_t end, intptr_t aslr_slide);
    224 
    225   void CurrentTimeEvent();
    226 
    227   void TimerEvent(StartEnd se, const char* name);
    228 
    229   static void EnterExternal(Isolate* isolate);
    230   static void LeaveExternal(Isolate* isolate);
    231 
    232   static void DefaultEventLoggerSentinel(const char* name, int event) {}
    233 
    234   INLINE(static void CallEventLogger(Isolate* isolate, const char* name,
    235                                      StartEnd se, bool expose_to_api));
    236 
    237   // ==== Events logged by --log-regexp ====
    238   // Regexp compilation and execution events.
    239 
    240   void RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache);
    241 
    242   bool is_logging() {
    243     return is_logging_;
    244   }
    245 
    246   bool is_logging_code_events() {
    247     return is_logging() || jit_logger_ != NULL;
    248   }
    249 
    250   // Stop collection of profiling data.
    251   // When data collection is paused, CPU Tick events are discarded.
    252   void StopProfiler();
    253 
    254   void LogExistingFunction(Handle<SharedFunctionInfo> shared,
    255                            Handle<AbstractCode> code);
    256   // Logs all compiled functions found in the heap.
    257   void LogCompiledFunctions();
    258   // Logs all accessor callbacks found in the heap.
    259   void LogAccessorCallbacks();
    260   // Used for logging stubs found in the snapshot.
    261   void LogCodeObjects();
    262   // Used for logging bytecode handlers found in the snapshot.
    263   void LogBytecodeHandlers();
    264 
    265   // Converts tag to a corresponding NATIVE_... if the script is native.
    266   INLINE(static CodeEventListener::LogEventsAndTags ToNativeByScript(
    267       CodeEventListener::LogEventsAndTags, Script*));
    268 
    269   // Profiler's sampling interval (in milliseconds).
    270 #if defined(ANDROID)
    271   // Phones and tablets have processors that are much slower than desktop
    272   // and laptop computers for which current heuristics are tuned.
    273   static const int kSamplingIntervalMs = 5;
    274 #else
    275   static const int kSamplingIntervalMs = 1;
    276 #endif
    277 
    278   // Callback from Log, stops profiling in case of insufficient resources.
    279   void LogFailure();
    280 
    281  private:
    282   explicit Logger(Isolate* isolate);
    283   ~Logger();
    284 
    285   // Emits the profiler's first message.
    286   void ProfilerBeginEvent();
    287 
    288   // Emits callback event messages.
    289   void CallbackEventInternal(const char* prefix,
    290                              Name* name,
    291                              Address entry_point);
    292 
    293   // Internal configurable move event.
    294   void MoveEventInternal(CodeEventListener::LogEventsAndTags event,
    295                          Address from, Address to);
    296 
    297   // Used for logging stubs found in the snapshot.
    298   void LogCodeObject(Object* code_object);
    299 
    300   // Helper method. It resets name_buffer_ and add tag name into it.
    301   void InitNameBuffer(CodeEventListener::LogEventsAndTags tag);
    302 
    303   // Emits a profiler tick event. Used by the profiler thread.
    304   void TickEvent(TickSample* sample, bool overflow);
    305   void RuntimeCallTimerEvent();
    306 
    307   PRINTF_FORMAT(2, 3) void ApiEvent(const char* format, ...);
    308 
    309   // Logs a StringEvent regardless of whether FLAG_log is true.
    310   void UncheckedStringEvent(const char* name, const char* value);
    311 
    312   // Logs an IntEvent regardless of whether FLAG_log is true.
    313   void UncheckedIntEvent(const char* name, int value);
    314   void UncheckedIntPtrTEvent(const char* name, intptr_t value);
    315 
    316   Isolate* isolate_;
    317 
    318   // The sampler used by the profiler and the sliding state window.
    319   Ticker* ticker_;
    320 
    321   // When the statistical profile is active, profiler_
    322   // points to a Profiler, that handles collection
    323   // of samples.
    324   Profiler* profiler_;
    325 
    326   // An array of log events names.
    327   const char* const* log_events_;
    328 
    329   // Internal implementation classes with access to
    330   // private members.
    331   friend class EventLog;
    332   friend class Isolate;
    333   friend class TimeLog;
    334   friend class Profiler;
    335   template <StateTag Tag> friend class VMState;
    336   friend class LoggerTestHelper;
    337 
    338   bool is_logging_;
    339   Log* log_;
    340   PerfBasicLogger* perf_basic_logger_;
    341   PerfJitLogger* perf_jit_logger_;
    342   LowLevelLogger* ll_logger_;
    343   JitLogger* jit_logger_;
    344   std::unique_ptr<ProfilerListener> profiler_listener_;
    345   List<CodeEventListener*> listeners_;
    346 
    347   // Guards against multiple calls to TearDown() that can happen in some tests.
    348   // 'true' between SetUp() and TearDown().
    349   bool is_initialized_;
    350 
    351   base::ElapsedTimer timer_;
    352 
    353   friend class CpuProfiler;
    354 };
    355 
    356 #define TIMER_EVENTS_LIST(V)    \
    357   V(RecompileSynchronous, true) \
    358   V(RecompileConcurrent, true)  \
    359   V(CompileIgnition, true)      \
    360   V(CompileFullCode, true)      \
    361   V(OptimizeCode, true)         \
    362   V(CompileCode, true)          \
    363   V(DeoptimizeCode, true)       \
    364   V(Execute, true)              \
    365   V(External, true)             \
    366   V(IcMiss, false)
    367 
    368 #define V(TimerName, expose)                                                  \
    369   class TimerEvent##TimerName : public AllStatic {                            \
    370    public:                                                                    \
    371     static const char* name(void* unused = NULL) { return "V8." #TimerName; } \
    372     static bool expose_to_api() { return expose; }                            \
    373   };
    374 TIMER_EVENTS_LIST(V)
    375 #undef V
    376 
    377 
    378 template <class TimerEvent>
    379 class TimerEventScope {
    380  public:
    381   explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
    382     LogTimerEvent(Logger::START);
    383   }
    384 
    385   ~TimerEventScope() { LogTimerEvent(Logger::END); }
    386 
    387   void LogTimerEvent(Logger::StartEnd se);
    388 
    389  private:
    390   Isolate* isolate_;
    391 };
    392 
    393 class PositionsRecorder BASE_EMBEDDED {
    394  public:
    395   PositionsRecorder() { jit_handler_data_ = NULL; }
    396 
    397   void AttachJITHandlerData(void* user_data) { jit_handler_data_ = user_data; }
    398 
    399   void* DetachJITHandlerData() {
    400     void* old_data = jit_handler_data_;
    401     jit_handler_data_ = NULL;
    402     return old_data;
    403   }
    404 
    405  protected:
    406   // Currently jit_handler_data_ is used to store JITHandler-specific data
    407   // over the lifetime of a PositionsRecorder
    408   void* jit_handler_data_;
    409 
    410  private:
    411   DISALLOW_COPY_AND_ASSIGN(PositionsRecorder);
    412 };
    413 
    414 class CodeEventLogger : public CodeEventListener {
    415  public:
    416   CodeEventLogger();
    417   ~CodeEventLogger() override;
    418 
    419   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
    420                        const char* comment) override;
    421   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
    422                        Name* name) override;
    423   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
    424                        int args_count) override;
    425   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
    426                        SharedFunctionInfo* shared, Name* name) override;
    427   void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
    428                        SharedFunctionInfo* shared, Name* source, int line,
    429                        int column) override;
    430   void RegExpCodeCreateEvent(AbstractCode* code, String* source) override;
    431 
    432   void CallbackEvent(Name* name, Address entry_point) override {}
    433   void GetterCallbackEvent(Name* name, Address entry_point) override {}
    434   void SetterCallbackEvent(Name* name, Address entry_point) override {}
    435   void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
    436   void CodeMovingGCEvent() override {}
    437   void CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta) override {}
    438 
    439  private:
    440   class NameBuffer;
    441 
    442   virtual void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
    443                                  const char* name, int length) = 0;
    444 
    445   NameBuffer* name_buffer_;
    446 };
    447 
    448 
    449 }  // namespace internal
    450 }  // namespace v8
    451 
    452 
    453 #endif  // V8_LOG_H_
    454