src/v8/src/log.h

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