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 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_