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/platform/elapsed-timer.h"
     12 #include "src/base/platform/platform.h"
     13 #include "src/objects.h"
     14 
     15 namespace v8 {
     16 
     17 namespace base {
     18 class Semaphore;
     19 }
     20 
     21 namespace internal {
     22 
     23 // Logger is used for collecting logging information from V8 during
     24 // execution. The result is dumped to a file.
     25 //
     26 // Available command line flags:
     27 //
     28 //  --log
     29 // Minimal logging (no API, code, or GC sample events), default is off.
     30 //
     31 // --log-all
     32 // Log all events to the file, default is off.  This is the same as combining
     33 // --log-api, --log-code, --log-gc, and --log-regexp.
     34 //
     35 // --log-api
     36 // Log API events to the logfile, default is off.  --log-api implies --log.
     37 //
     38 // --log-code
     39 // Log code (create, move, and delete) events to the logfile, default is off.
     40 // --log-code implies --log.
     41 //
     42 // --log-gc
     43 // Log GC heap samples after each GC that can be processed by hp2ps, default
     44 // is off.  --log-gc implies --log.
     45 //
     46 // --log-regexp
     47 // Log creation and use of regular expressions, Default is off.
     48 // --log-regexp implies --log.
     49 //
     50 // --logfile <filename>
     51 // Specify the name of the logfile, default is "v8.log".
     52 //
     53 // --prof
     54 // Collect statistical profiling information (ticks), default is off.  The
     55 // tick profiler requires code events, so --prof implies --log-code.
     56 
     57 // Forward declarations.
     58 class CodeEventListener;
     59 class CompilationInfo;
     60 class CpuProfiler;
     61 class Isolate;
     62 class Log;
     63 class PositionsRecorder;
     64 class Profiler;
     65 class Ticker;
     66 struct TickSample;
     67 
     68 #undef LOG
     69 #define LOG(isolate, Call)                          \
     70   do {                                              \
     71     v8::internal::Logger* logger =                  \
     72         (isolate)->logger();                        \
     73     if (logger->is_logging())                       \
     74       logger->Call;                                 \
     75   } while (false)
     76 
     77 #define LOG_CODE_EVENT(isolate, Call)               \
     78   do {                                              \
     79     v8::internal::Logger* logger =                  \
     80         (isolate)->logger();                        \
     81     if (logger->is_logging_code_events())           \
     82       logger->Call;                                 \
     83   } while (false)
     84 
     85 
     86 #define LOG_EVENTS_AND_TAGS_LIST(V)                                     \
     87   V(CODE_CREATION_EVENT,            "code-creation")                    \
     88   V(CODE_DISABLE_OPT_EVENT,         "code-disable-optimization")        \
     89   V(CODE_MOVE_EVENT,                "code-move")                        \
     90   V(CODE_DELETE_EVENT,              "code-delete")                      \
     91   V(CODE_MOVING_GC,                 "code-moving-gc")                   \
     92   V(SHARED_FUNC_MOVE_EVENT,         "sfi-move")                         \
     93   V(SNAPSHOT_POSITION_EVENT,        "snapshot-pos")                     \
     94   V(SNAPSHOT_CODE_NAME_EVENT,       "snapshot-code-name")               \
     95   V(TICK_EVENT,                     "tick")                             \
     96   V(REPEAT_META_EVENT,              "repeat")                           \
     97   V(BUILTIN_TAG,                    "Builtin")                          \
     98   V(CALL_DEBUG_BREAK_TAG,           "CallDebugBreak")                   \
     99   V(CALL_DEBUG_PREPARE_STEP_IN_TAG, "CallDebugPrepareStepIn")           \
    100   V(CALL_INITIALIZE_TAG,            "CallInitialize")                   \
    101   V(CALL_MEGAMORPHIC_TAG,           "CallMegamorphic")                  \
    102   V(CALL_MISS_TAG,                  "CallMiss")                         \
    103   V(CALL_NORMAL_TAG,                "CallNormal")                       \
    104   V(CALL_PRE_MONOMORPHIC_TAG,       "CallPreMonomorphic")               \
    105   V(LOAD_INITIALIZE_TAG,            "LoadInitialize")                   \
    106   V(LOAD_PREMONOMORPHIC_TAG,        "LoadPreMonomorphic")               \
    107   V(LOAD_MEGAMORPHIC_TAG,           "LoadMegamorphic")                  \
    108   V(STORE_INITIALIZE_TAG,           "StoreInitialize")                  \
    109   V(STORE_PREMONOMORPHIC_TAG,       "StorePreMonomorphic")              \
    110   V(STORE_GENERIC_TAG,              "StoreGeneric")                     \
    111   V(STORE_MEGAMORPHIC_TAG,          "StoreMegamorphic")                 \
    112   V(KEYED_CALL_DEBUG_BREAK_TAG,     "KeyedCallDebugBreak")              \
    113   V(KEYED_CALL_DEBUG_PREPARE_STEP_IN_TAG,                               \
    114     "KeyedCallDebugPrepareStepIn")                                      \
    115   V(KEYED_CALL_INITIALIZE_TAG,      "KeyedCallInitialize")              \
    116   V(KEYED_CALL_MEGAMORPHIC_TAG,     "KeyedCallMegamorphic")             \
    117   V(KEYED_CALL_MISS_TAG,            "KeyedCallMiss")                    \
    118   V(KEYED_CALL_NORMAL_TAG,          "KeyedCallNormal")                  \
    119   V(KEYED_CALL_PRE_MONOMORPHIC_TAG, "KeyedCallPreMonomorphic")          \
    120   V(CALLBACK_TAG,                   "Callback")                         \
    121   V(EVAL_TAG,                       "Eval")                             \
    122   V(FUNCTION_TAG,                   "Function")                         \
    123   V(HANDLER_TAG,                    "Handler")                          \
    124   V(KEYED_LOAD_IC_TAG,              "KeyedLoadIC")                      \
    125   V(KEYED_LOAD_POLYMORPHIC_IC_TAG,  "KeyedLoadPolymorphicIC")           \
    126   V(KEYED_EXTERNAL_ARRAY_LOAD_IC_TAG, "KeyedExternalArrayLoadIC")       \
    127   V(KEYED_STORE_IC_TAG,             "KeyedStoreIC")                     \
    128   V(KEYED_STORE_POLYMORPHIC_IC_TAG, "KeyedStorePolymorphicIC")          \
    129   V(KEYED_EXTERNAL_ARRAY_STORE_IC_TAG, "KeyedExternalArrayStoreIC")     \
    130   V(LAZY_COMPILE_TAG,               "LazyCompile")                      \
    131   V(CALL_IC_TAG,                    "CallIC")                           \
    132   V(LOAD_IC_TAG,                    "LoadIC")                           \
    133   V(LOAD_POLYMORPHIC_IC_TAG,        "LoadPolymorphicIC")                \
    134   V(REG_EXP_TAG,                    "RegExp")                           \
    135   V(SCRIPT_TAG,                     "Script")                           \
    136   V(STORE_IC_TAG,                   "StoreIC")                          \
    137   V(STORE_POLYMORPHIC_IC_TAG,       "StorePolymorphicIC")               \
    138   V(STUB_TAG,                       "Stub")                             \
    139   V(NATIVE_FUNCTION_TAG,            "Function")                         \
    140   V(NATIVE_LAZY_COMPILE_TAG,        "LazyCompile")                      \
    141   V(NATIVE_SCRIPT_TAG,              "Script")
    142 // Note that 'NATIVE_' cases for functions and scripts are mapped onto
    143 // original tags when writing to the log.
    144 
    145 
    146 class JitLogger;
    147 class PerfBasicLogger;
    148 class LowLevelLogger;
    149 class Sampler;
    150 
    151 class Logger {
    152  public:
    153   enum StartEnd { START = 0, END = 1 };
    154 
    155 #define DECLARE_ENUM(enum_item, ignore) enum_item,
    156   enum LogEventsAndTags {
    157     LOG_EVENTS_AND_TAGS_LIST(DECLARE_ENUM)
    158     NUMBER_OF_LOG_EVENTS
    159   };
    160 #undef DECLARE_ENUM
    161 
    162   // Acquires resources for logging if the right flags are set.
    163   bool SetUp(Isolate* isolate);
    164 
    165   // Sets the current code event handler.
    166   void SetCodeEventHandler(uint32_t options,
    167                            JitCodeEventHandler event_handler);
    168 
    169   Sampler* sampler();
    170 
    171   // Frees resources acquired in SetUp.
    172   // When a temporary file is used for the log, returns its stream descriptor,
    173   // leaving the file open.
    174   FILE* TearDown();
    175 
    176   // Emits an event with a string value -> (name, value).
    177   void StringEvent(const char* name, const char* value);
    178 
    179   // Emits an event with an int value -> (name, value).
    180   void IntEvent(const char* name, int value);
    181   void IntPtrTEvent(const char* name, intptr_t value);
    182 
    183   // Emits an event with an handle value -> (name, location).
    184   void HandleEvent(const char* name, Object** location);
    185 
    186   // Emits memory management events for C allocated structures.
    187   void NewEvent(const char* name, void* object, size_t size);
    188   void DeleteEvent(const char* name, void* object);
    189 
    190   // Emits an event with a tag, and some resource usage information.
    191   // -> (name, tag, <rusage information>).
    192   // Currently, the resource usage information is a process time stamp
    193   // and a real time timestamp.
    194   void ResourceEvent(const char* name, const char* tag);
    195 
    196   // Emits an event that an undefined property was read from an
    197   // object.
    198   void SuspectReadEvent(Name* name, Object* obj);
    199 
    200   // Emits an event when a message is put on or read from a debugging queue.
    201   // DebugTag lets us put a call-site specific label on the event.
    202   void DebugTag(const char* call_site_tag);
    203   void DebugEvent(const char* event_type, Vector<uint16_t> parameter);
    204 
    205 
    206   // ==== Events logged by --log-api. ====
    207   void ApiSecurityCheck();
    208   void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
    209   void ApiIndexedPropertyAccess(const char* tag,
    210                                 JSObject* holder,
    211                                 uint32_t index);
    212   void ApiObjectAccess(const char* tag, JSObject* obj);
    213   void ApiEntryCall(const char* name);
    214 
    215 
    216   // ==== Events logged by --log-code. ====
    217   void addCodeEventListener(CodeEventListener* listener);
    218   void removeCodeEventListener(CodeEventListener* listener);
    219   bool hasCodeEventListener(CodeEventListener* listener);
    220 
    221 
    222   // Emits a code event for a callback function.
    223   void CallbackEvent(Name* name, Address entry_point);
    224   void GetterCallbackEvent(Name* name, Address entry_point);
    225   void SetterCallbackEvent(Name* name, Address entry_point);
    226   // Emits a code create event.
    227   void CodeCreateEvent(LogEventsAndTags tag,
    228                        Code* code, const char* source);
    229   void CodeCreateEvent(LogEventsAndTags tag,
    230                        Code* code, Name* name);
    231   void CodeCreateEvent(LogEventsAndTags tag,
    232                        Code* code,
    233                        SharedFunctionInfo* shared,
    234                        CompilationInfo* info,
    235                        Name* name);
    236   void CodeCreateEvent(LogEventsAndTags tag,
    237                        Code* code,
    238                        SharedFunctionInfo* shared,
    239                        CompilationInfo* info,
    240                        Name* source, int line, int column);
    241   void CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count);
    242   // Emits a code deoptimization event.
    243   void CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared);
    244   void CodeMovingGCEvent();
    245   // Emits a code create event for a RegExp.
    246   void RegExpCodeCreateEvent(Code* code, String* source);
    247   // Emits a code move event.
    248   void CodeMoveEvent(Address from, Address to);
    249   // Emits a code delete event.
    250   void CodeDeleteEvent(Address from);
    251   // Emits a code line info add event with Postion type.
    252   void CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
    253                                        int pc_offset,
    254                                        int position);
    255   // Emits a code line info add event with StatementPostion type.
    256   void CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
    257                                                 int pc_offset,
    258                                                 int position);
    259   // Emits a code line info start to record event
    260   void CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder);
    261   // Emits a code line info finish record event.
    262   // It's the callee's responsibility to dispose the parameter jit_handler_data.
    263   void CodeEndLinePosInfoRecordEvent(Code* code, void* jit_handler_data);
    264 
    265   void SharedFunctionInfoMoveEvent(Address from, Address to);
    266 
    267   void CodeNameEvent(Address addr, int pos, const char* code_name);
    268   void SnapshotPositionEvent(Address addr, int pos);
    269 
    270   // ==== Events logged by --log-gc. ====
    271   // Heap sampling events: start, end, and individual types.
    272   void HeapSampleBeginEvent(const char* space, const char* kind);
    273   void HeapSampleEndEvent(const char* space, const char* kind);
    274   void HeapSampleItemEvent(const char* type, int number, int bytes);
    275   void HeapSampleJSConstructorEvent(const char* constructor,
    276                                     int number, int bytes);
    277   void HeapSampleJSRetainersEvent(const char* constructor,
    278                                          const char* event);
    279   void HeapSampleJSProducerEvent(const char* constructor,
    280                                  Address* stack);
    281   void HeapSampleStats(const char* space, const char* kind,
    282                        intptr_t capacity, intptr_t used);
    283 
    284   void SharedLibraryEvent(const std::string& library_path,
    285                           uintptr_t start,
    286                           uintptr_t end);
    287 
    288   void CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta);
    289   void CurrentTimeEvent();
    290 
    291   void TimerEvent(StartEnd se, const char* name);
    292 
    293   static void EnterExternal(Isolate* isolate);
    294   static void LeaveExternal(Isolate* isolate);
    295 
    296   static void DefaultEventLoggerSentinel(const char* name, int event) {}
    297 
    298   INLINE(static void CallEventLogger(Isolate* isolate, const char* name,
    299                                      StartEnd se, bool expose_to_api));
    300 
    301   // ==== Events logged by --log-regexp ====
    302   // Regexp compilation and execution events.
    303 
    304   void RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache);
    305 
    306   bool is_logging() {
    307     return is_logging_;
    308   }
    309 
    310   bool is_logging_code_events() {
    311     return is_logging() || jit_logger_ != NULL;
    312   }
    313 
    314   // Stop collection of profiling data.
    315   // When data collection is paused, CPU Tick events are discarded.
    316   void StopProfiler();
    317 
    318   void LogExistingFunction(Handle<SharedFunctionInfo> shared,
    319                            Handle<Code> code);
    320   // Logs all compiled functions found in the heap.
    321   void LogCompiledFunctions();
    322   // Logs all accessor callbacks found in the heap.
    323   void LogAccessorCallbacks();
    324   // Used for logging stubs found in the snapshot.
    325   void LogCodeObjects();
    326 
    327   // Converts tag to a corresponding NATIVE_... if the script is native.
    328   INLINE(static LogEventsAndTags ToNativeByScript(LogEventsAndTags, Script*));
    329 
    330   // Profiler's sampling interval (in milliseconds).
    331 #if defined(ANDROID)
    332   // Phones and tablets have processors that are much slower than desktop
    333   // and laptop computers for which current heuristics are tuned.
    334   static const int kSamplingIntervalMs = 5;
    335 #else
    336   static const int kSamplingIntervalMs = 1;
    337 #endif
    338 
    339   // Callback from Log, stops profiling in case of insufficient resources.
    340   void LogFailure();
    341 
    342  private:
    343   explicit Logger(Isolate* isolate);
    344   ~Logger();
    345 
    346   // Emits the profiler's first message.
    347   void ProfilerBeginEvent();
    348 
    349   // Emits callback event messages.
    350   void CallbackEventInternal(const char* prefix,
    351                              Name* name,
    352                              Address entry_point);
    353 
    354   // Internal configurable move event.
    355   void MoveEventInternal(LogEventsAndTags event, Address from, Address to);
    356 
    357   // Used for logging stubs found in the snapshot.
    358   void LogCodeObject(Object* code_object);
    359 
    360   // Helper method. It resets name_buffer_ and add tag name into it.
    361   void InitNameBuffer(LogEventsAndTags tag);
    362 
    363   // Emits a profiler tick event. Used by the profiler thread.
    364   void TickEvent(TickSample* sample, bool overflow);
    365 
    366   void ApiEvent(const char* name, ...);
    367 
    368   // Logs a StringEvent regardless of whether FLAG_log is true.
    369   void UncheckedStringEvent(const char* name, const char* value);
    370 
    371   // Logs an IntEvent regardless of whether FLAG_log is true.
    372   void UncheckedIntEvent(const char* name, int value);
    373   void UncheckedIntPtrTEvent(const char* name, intptr_t value);
    374 
    375   Isolate* isolate_;
    376 
    377   // The sampler used by the profiler and the sliding state window.
    378   Ticker* ticker_;
    379 
    380   // When the statistical profile is active, profiler_
    381   // points to a Profiler, that handles collection
    382   // of samples.
    383   Profiler* profiler_;
    384 
    385   // An array of log events names.
    386   const char* const* log_events_;
    387 
    388   // Internal implementation classes with access to
    389   // private members.
    390   friend class EventLog;
    391   friend class Isolate;
    392   friend class TimeLog;
    393   friend class Profiler;
    394   template <StateTag Tag> friend class VMState;
    395   friend class LoggerTestHelper;
    396 
    397   bool is_logging_;
    398   Log* log_;
    399   PerfBasicLogger* perf_basic_logger_;
    400   LowLevelLogger* ll_logger_;
    401   JitLogger* jit_logger_;
    402   List<CodeEventListener*> listeners_;
    403 
    404   // Guards against multiple calls to TearDown() that can happen in some tests.
    405   // 'true' between SetUp() and TearDown().
    406   bool is_initialized_;
    407 
    408   base::ElapsedTimer timer_;
    409 
    410   friend class CpuProfiler;
    411 };
    412 
    413 
    414 #define TIMER_EVENTS_LIST(V)    \
    415   V(RecompileSynchronous, true) \
    416   V(RecompileConcurrent, true)  \
    417   V(CompileFullCode, true)      \
    418   V(Execute, true)              \
    419   V(External, true)             \
    420   V(IcMiss, false)
    421 
    422 #define V(TimerName, expose)                                                  \
    423   class TimerEvent##TimerName : public AllStatic {                            \
    424    public:                                                                    \
    425     static const char* name(void* unused = NULL) { return "V8." #TimerName; } \
    426     static bool expose_to_api() { return expose; }                            \
    427   };
    428 TIMER_EVENTS_LIST(V)
    429 #undef V
    430 
    431 
    432 template <class TimerEvent>
    433 class TimerEventScope {
    434  public:
    435   explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
    436     LogTimerEvent(Logger::START);
    437   }
    438 
    439   ~TimerEventScope() { LogTimerEvent(Logger::END); }
    440 
    441   void LogTimerEvent(Logger::StartEnd se);
    442 
    443  private:
    444   Isolate* isolate_;
    445 };
    446 
    447 
    448 class CodeEventListener {
    449  public:
    450   virtual ~CodeEventListener() {}
    451 
    452   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    453                                Code* code,
    454                                const char* comment) = 0;
    455   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    456                                Code* code,
    457                                Name* name) = 0;
    458   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    459                                Code* code,
    460                                SharedFunctionInfo* shared,
    461                                CompilationInfo* info,
    462                                Name* name) = 0;
    463   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    464                                Code* code,
    465                                SharedFunctionInfo* shared,
    466                                CompilationInfo* info,
    467                                Name* source,
    468                                int line, int column) = 0;
    469   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    470                                Code* code,
    471                                int args_count) = 0;
    472   virtual void CallbackEvent(Name* name, Address entry_point) = 0;
    473   virtual void GetterCallbackEvent(Name* name, Address entry_point) = 0;
    474   virtual void SetterCallbackEvent(Name* name, Address entry_point) = 0;
    475   virtual void RegExpCodeCreateEvent(Code* code, String* source) = 0;
    476   virtual void CodeMoveEvent(Address from, Address to) = 0;
    477   virtual void CodeDeleteEvent(Address from) = 0;
    478   virtual void SharedFunctionInfoMoveEvent(Address from, Address to) = 0;
    479   virtual void CodeMovingGCEvent() = 0;
    480   virtual void CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared) = 0;
    481 };
    482 
    483 
    484 class CodeEventLogger : public CodeEventListener {
    485  public:
    486   CodeEventLogger();
    487   virtual ~CodeEventLogger();
    488 
    489   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    490                                Code* code,
    491                                const char* comment);
    492   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    493                                Code* code,
    494                                Name* name);
    495   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    496                                Code* code,
    497                                int args_count);
    498   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    499                                Code* code,
    500                                SharedFunctionInfo* shared,
    501                                CompilationInfo* info,
    502                                Name* name);
    503   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
    504                                Code* code,
    505                                SharedFunctionInfo* shared,
    506                                CompilationInfo* info,
    507                                Name* source,
    508                                int line, int column);
    509   virtual void RegExpCodeCreateEvent(Code* code, String* source);
    510 
    511   virtual void CallbackEvent(Name* name, Address entry_point) { }
    512   virtual void GetterCallbackEvent(Name* name, Address entry_point) { }
    513   virtual void SetterCallbackEvent(Name* name, Address entry_point) { }
    514   virtual void SharedFunctionInfoMoveEvent(Address from, Address to) { }
    515   virtual void CodeMovingGCEvent() { }
    516 
    517  private:
    518   class NameBuffer;
    519 
    520   virtual void LogRecordedBuffer(Code* code,
    521                                  SharedFunctionInfo* shared,
    522                                  const char* name,
    523                                  int length) = 0;
    524 
    525   NameBuffer* name_buffer_;
    526 };
    527 
    528 
    529 }  // namespace internal
    530 }  // namespace v8
    531 
    532 
    533 #endif  // V8_LOG_H_
    534