src/v8/src/log.h

   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 PerfJitLogger;
 150 class Sampler;
 151
 152 class Logger {
 153  public:
 154   enum StartEnd { START = 0, END = 1 };
 155
 156 #define DECLARE_ENUM(enum_item, ignore) enum_item,
 157   enum LogEventsAndTags {
 158     LOG_EVENTS_AND_TAGS_LIST(DECLARE_ENUM)
 159     NUMBER_OF_LOG_EVENTS
 160   };
 161 #undef DECLARE_ENUM
 162
 163   // Acquires resources for logging if the right flags are set.
 164   bool SetUp(Isolate* isolate);
 165
 166   // Sets the current code event handler.
 167   void SetCodeEventHandler(uint32_t options,
 168                            JitCodeEventHandler event_handler);
 169
 170   Sampler* sampler();
 171
 172   // Frees resources acquired in SetUp.
 173   // When a temporary file is used for the log, returns its stream descriptor,
 174   // leaving the file open.
 175   FILE* TearDown();
 176
 177   // Emits an event with a string value -> (name, value).
 178   void StringEvent(const char* name, const char* value);
 179
 180   // Emits an event with an int value -> (name, value).
 181   void IntEvent(const char* name, int value);
 182   void IntPtrTEvent(const char* name, intptr_t value);
 183
 184   // Emits an event with an handle value -> (name, location).
 185   void HandleEvent(const char* name, Object** location);
 186
 187   // Emits memory management events for C allocated structures.
 188   void NewEvent(const char* name, void* object, size_t size);
 189   void DeleteEvent(const char* name, void* object);
 190
 191   // Static versions of the above, operate on current isolate's logger.
 192   // Used in TRACK_MEMORY(TypeName) defined in globals.h
 193   static void NewEventStatic(const char* name, void* object, size_t size);
 194   static void DeleteEventStatic(const char* name, void* object);
 195
 196   // Emits an event with a tag, and some resource usage information.
 197   // -> (name, tag, <rusage information>).
 198   // Currently, the resource usage information is a process time stamp
 199   // and a real time timestamp.
 200   void ResourceEvent(const char* name, const char* tag);
 201
 202   // Emits an event that an undefined property was read from an
 203   // object.
 204   void SuspectReadEvent(Name* name, Object* obj);
 205
 206   // Emits an event when a message is put on or read from a debugging queue.
 207   // DebugTag lets us put a call-site specific label on the event.
 208   void DebugTag(const char* call_site_tag);
 209   void DebugEvent(const char* event_type, Vector<uint16_t> parameter);
 210
 211
 212   // ==== Events logged by --log-api. ====
 213   void ApiNamedSecurityCheck(Object* key);
 214   void ApiIndexedSecurityCheck(uint32_t index);
 215   void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
 216   void ApiIndexedPropertyAccess(const char* tag,
 217                                 JSObject* holder,
 218                                 uint32_t index);
 219   void ApiObjectAccess(const char* tag, JSObject* obj);
 220   void ApiEntryCall(const char* name);
 221
 222
 223   // ==== Events logged by --log-code. ====
 224   void addCodeEventListener(CodeEventListener* listener);
 225   void removeCodeEventListener(CodeEventListener* listener);
 226   bool hasCodeEventListener(CodeEventListener* listener);
 227
 228
 229   // Emits a code event for a callback function.
 230   void CallbackEvent(Name* name, Address entry_point);
 231   void GetterCallbackEvent(Name* name, Address entry_point);
 232   void SetterCallbackEvent(Name* name, Address entry_point);
 233   // Emits a code create event.
 234   void CodeCreateEvent(LogEventsAndTags tag,
 235                        Code* code, const char* source);
 236   void CodeCreateEvent(LogEventsAndTags tag,
 237                        Code* code, Name* name);
 238   void CodeCreateEvent(LogEventsAndTags tag,
 239                        Code* code,
 240                        SharedFunctionInfo* shared,
 241                        CompilationInfo* info,
 242                        Name* name);
 243   void CodeCreateEvent(LogEventsAndTags tag,
 244                        Code* code,
 245                        SharedFunctionInfo* shared,
 246                        CompilationInfo* info,
 247                        Name* source, int line, int column);
 248   void CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count);
 249   // Emits a code deoptimization event.
 250   void CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared);
 251   void CodeMovingGCEvent();
 252   // Emits a code create event for a RegExp.
 253   void RegExpCodeCreateEvent(Code* code, String* source);
 254   // Emits a code move event.
 255   void CodeMoveEvent(Address from, Address to);
 256   // Emits a code delete event.
 257   void CodeDeleteEvent(Address from);
 258   // Emits a code line info add event with Postion type.
 259   void CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
 260                                        int pc_offset,
 261                                        int position);
 262   // Emits a code line info add event with StatementPostion type.
 263   void CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
 264                                                 int pc_offset,
 265                                                 int position);
 266   // Emits a code line info start to record event
 267   void CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder);
 268   // Emits a code line info finish record event.
 269   // It's the callee's responsibility to dispose the parameter jit_handler_data.
 270   void CodeEndLinePosInfoRecordEvent(Code* code, void* jit_handler_data);
 271
 272   void SharedFunctionInfoMoveEvent(Address from, Address to);
 273
 274   void CodeNameEvent(Address addr, int pos, const char* code_name);
 275   void SnapshotPositionEvent(Address addr, int pos);
 276
 277   // ==== Events logged by --log-gc. ====
 278   // Heap sampling events: start, end, and individual types.
 279   void HeapSampleBeginEvent(const char* space, const char* kind);
 280   void HeapSampleEndEvent(const char* space, const char* kind);
 281   void HeapSampleItemEvent(const char* type, int number, int bytes);
 282   void HeapSampleJSConstructorEvent(const char* constructor,
 283                                     int number, int bytes);
 284   void HeapSampleJSRetainersEvent(const char* constructor,
 285                                          const char* event);
 286   void HeapSampleJSProducerEvent(const char* constructor,
 287                                  Address* stack);
 288   void HeapSampleStats(const char* space, const char* kind,
 289                        intptr_t capacity, intptr_t used);
 290
 291   void SharedLibraryEvent(const std::string& library_path,
 292                           uintptr_t start,
 293                           uintptr_t end);
 294
 295   void CodeDeoptEvent(Code* code);
 296   void CurrentTimeEvent();
 297
 298   void TimerEvent(StartEnd se, const char* name);
 299
 300   static void EnterExternal(Isolate* isolate);
 301   static void LeaveExternal(Isolate* isolate);
 302
 303   static void DefaultEventLoggerSentinel(const char* name, int event) {}
 304
 305   INLINE(static void CallEventLogger(Isolate* isolate, const char* name,
 306                                      StartEnd se, bool expose_to_api));
 307
 308   // ==== Events logged by --log-regexp ====
 309   // Regexp compilation and execution events.
 310
 311   void RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache);
 312
 313   bool is_logging() {
 314     return is_logging_;
 315   }
 316
 317   bool is_logging_code_events() {
 318     return is_logging() || jit_logger_ != NULL;
 319   }
 320
 321   // Stop collection of profiling data.
 322   // When data collection is paused, CPU Tick events are discarded.
 323   void StopProfiler();
 324
 325   void LogExistingFunction(Handle<SharedFunctionInfo> shared,
 326                            Handle<Code> code);
 327   // Logs all compiled functions found in the heap.
 328   void LogCompiledFunctions();
 329   // Logs all accessor callbacks found in the heap.
 330   void LogAccessorCallbacks();
 331   // Used for logging stubs found in the snapshot.
 332   void LogCodeObjects();
 333
 334   // Converts tag to a corresponding NATIVE_... if the script is native.
 335   INLINE(static LogEventsAndTags ToNativeByScript(LogEventsAndTags, Script*));
 336
 337   // Profiler's sampling interval (in milliseconds).
 338 #if defined(ANDROID)
 339   // Phones and tablets have processors that are much slower than desktop
 340   // and laptop computers for which current heuristics are tuned.
 341   static const int kSamplingIntervalMs = 5;
 342 #else
 343   static const int kSamplingIntervalMs = 1;
 344 #endif
 345
 346   // Callback from Log, stops profiling in case of insufficient resources.
 347   void LogFailure();
 348
 349  private:
 350   explicit Logger(Isolate* isolate);
 351   ~Logger();
 352
 353   // Emits the profiler's first message.
 354   void ProfilerBeginEvent();
 355
 356   // Emits callback event messages.
 357   void CallbackEventInternal(const char* prefix,
 358                              Name* name,
 359                              Address entry_point);
 360
 361   // Internal configurable move event.
 362   void MoveEventInternal(LogEventsAndTags event, Address from, Address to);
 363
 364   // Emits the source code of a regexp. Used by regexp events.
 365   void LogRegExpSource(Handle<JSRegExp> regexp);
 366
 367   // Used for logging stubs found in the snapshot.
 368   void LogCodeObject(Object* code_object);
 369
 370   // Helper method. It resets name_buffer_ and add tag name into it.
 371   void InitNameBuffer(LogEventsAndTags tag);
 372
 373   // Emits a profiler tick event. Used by the profiler thread.
 374   void TickEvent(TickSample* sample, bool overflow);
 375
 376   void ApiEvent(const char* name, ...);
 377
 378   // Logs a StringEvent regardless of whether FLAG_log is true.
 379   void UncheckedStringEvent(const char* name, const char* value);
 380
 381   // Logs an IntEvent regardless of whether FLAG_log is true.
 382   void UncheckedIntEvent(const char* name, int value);
 383   void UncheckedIntPtrTEvent(const char* name, intptr_t value);
 384
 385   Isolate* isolate_;
 386
 387   // The sampler used by the profiler and the sliding state window.
 388   Ticker* ticker_;
 389
 390   // When the statistical profile is active, profiler_
 391   // points to a Profiler, that handles collection
 392   // of samples.
 393   Profiler* profiler_;
 394
 395   // An array of log events names.
 396   const char* const* log_events_;
 397
 398   // Internal implementation classes with access to
 399   // private members.
 400   friend class EventLog;
 401   friend class Isolate;
 402   friend class TimeLog;
 403   friend class Profiler;
 404   template <StateTag Tag> friend class VMState;
 405   friend class LoggerTestHelper;
 406
 407   bool is_logging_;
 408   Log* log_;
 409   PerfBasicLogger* perf_basic_logger_;
 410   PerfJitLogger* perf_jit_logger_;
 411   LowLevelLogger* ll_logger_;
 412   JitLogger* jit_logger_;
 413   List<CodeEventListener*> listeners_;
 414
 415   // Guards against multiple calls to TearDown() that can happen in some tests.
 416   // 'true' between SetUp() and TearDown().
 417   bool is_initialized_;
 418
 419   base::ElapsedTimer timer_;
 420
 421   friend class CpuProfiler;
 422 };
 423
 424
 425 #define TIMER_EVENTS_LIST(V)    \
 426   V(RecompileSynchronous, true) \
 427   V(RecompileConcurrent, true)  \
 428   V(CompileFullCode, true)      \
 429   V(Execute, true)              \
 430   V(External, true)             \
 431   V(IcMiss, false)
 432
 433 #define V(TimerName, expose)                                                  \
 434   class TimerEvent##TimerName : public AllStatic {                            \
 435    public:                                                                    \
 436     static const char* name(void* unused = NULL) { return "V8." #TimerName; } \
 437     static bool expose_to_api() { return expose; }                            \
 438   };
 439 TIMER_EVENTS_LIST(V)
 440 #undef V
 441
 442
 443 template <class TimerEvent>
 444 class TimerEventScope {
 445  public:
 446   explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
 447     LogTimerEvent(Logger::START);
 448   }
 449
 450   ~TimerEventScope() { LogTimerEvent(Logger::END); }
 451
 452   void LogTimerEvent(Logger::StartEnd se);
 453
 454  private:
 455   Isolate* isolate_;
 456 };
 457
 458
 459 class CodeEventListener {
 460  public:
 461   virtual ~CodeEventListener() {}
 462
 463   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 464                                Code* code,
 465                                const char* comment) = 0;
 466   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 467                                Code* code,
 468                                Name* name) = 0;
 469   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 470                                Code* code,
 471                                SharedFunctionInfo* shared,
 472                                CompilationInfo* info,
 473                                Name* name) = 0;
 474   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 475                                Code* code,
 476                                SharedFunctionInfo* shared,
 477                                CompilationInfo* info,
 478                                Name* source,
 479                                int line, int column) = 0;
 480   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 481                                Code* code,
 482                                int args_count) = 0;
 483   virtual void CallbackEvent(Name* name, Address entry_point) = 0;
 484   virtual void GetterCallbackEvent(Name* name, Address entry_point) = 0;
 485   virtual void SetterCallbackEvent(Name* name, Address entry_point) = 0;
 486   virtual void RegExpCodeCreateEvent(Code* code, String* source) = 0;
 487   virtual void CodeMoveEvent(Address from, Address to) = 0;
 488   virtual void CodeDeleteEvent(Address from) = 0;
 489   virtual void SharedFunctionInfoMoveEvent(Address from, Address to) = 0;
 490   virtual void CodeMovingGCEvent() = 0;
 491   virtual void CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared) = 0;
 492 };
 493
 494
 495 class CodeEventLogger : public CodeEventListener {
 496  public:
 497   CodeEventLogger();
 498   virtual ~CodeEventLogger();
 499
 500   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 501                                Code* code,
 502                                const char* comment);
 503   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 504                                Code* code,
 505                                Name* name);
 506   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 507                                Code* code,
 508                                int args_count);
 509   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 510                                Code* code,
 511                                SharedFunctionInfo* shared,
 512                                CompilationInfo* info,
 513                                Name* name);
 514   virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
 515                                Code* code,
 516                                SharedFunctionInfo* shared,
 517                                CompilationInfo* info,
 518                                Name* source,
 519                                int line, int column);
 520   virtual void RegExpCodeCreateEvent(Code* code, String* source);
 521
 522   virtual void CallbackEvent(Name* name, Address entry_point) { }
 523   virtual void GetterCallbackEvent(Name* name, Address entry_point) { }
 524   virtual void SetterCallbackEvent(Name* name, Address entry_point) { }
 525   virtual void SharedFunctionInfoMoveEvent(Address from, Address to) { }
 526   virtual void CodeMovingGCEvent() { }
 527
 528  private:
 529   class NameBuffer;
 530
 531   virtual void LogRecordedBuffer(Code* code,
 532                                  SharedFunctionInfo* shared,
 533                                  const char* name,
 534                                  int length) = 0;
 535
 536   NameBuffer* name_buffer_;
 537 };
 538
 539
 540 } }  // namespace v8::internal
 541
 542
 543 #endif  // V8_LOG_H_