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