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
15namespace v8 {
16
17namespace base {
18class Semaphore;
19}
20
21namespace 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.
58class CodeEventListener;
59class CompilationInfo;
60class CpuProfiler;
61class Isolate;
62class Log;
63class PositionsRecorder;
64class Profiler;
65class Ticker;
66struct 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
146class JitLogger;
147class PerfBasicLogger;
148class LowLevelLogger;
149class PerfJitLogger;
150class Sampler;
151
152class 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 EmptyTimerEventsLogger(const char* name, int se) {}
304  static void DefaultTimerEventsLogger(const char* name, int se);
305
306  // ==== Events logged by --log-regexp ====
307  // Regexp compilation and execution events.
308
309  void RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache);
310
311  bool is_logging() {
312    return is_logging_;
313  }
314
315  bool is_logging_code_events() {
316    return is_logging() || jit_logger_ != NULL;
317  }
318
319  // Stop collection of profiling data.
320  // When data collection is paused, CPU Tick events are discarded.
321  void StopProfiler();
322
323  void LogExistingFunction(Handle<SharedFunctionInfo> shared,
324                           Handle<Code> code);
325  // Logs all compiled functions found in the heap.
326  void LogCompiledFunctions();
327  // Logs all accessor callbacks found in the heap.
328  void LogAccessorCallbacks();
329  // Used for logging stubs found in the snapshot.
330  void LogCodeObjects();
331
332  // Converts tag to a corresponding NATIVE_... if the script is native.
333  INLINE(static LogEventsAndTags ToNativeByScript(LogEventsAndTags, Script*));
334
335  // Profiler's sampling interval (in milliseconds).
336#if defined(ANDROID)
337  // Phones and tablets have processors that are much slower than desktop
338  // and laptop computers for which current heuristics are tuned.
339  static const int kSamplingIntervalMs = 5;
340#else
341  static const int kSamplingIntervalMs = 1;
342#endif
343
344  // Callback from Log, stops profiling in case of insufficient resources.
345  void LogFailure();
346
347 private:
348  explicit Logger(Isolate* isolate);
349  ~Logger();
350
351  // Emits the profiler's first message.
352  void ProfilerBeginEvent();
353
354  // Emits callback event messages.
355  void CallbackEventInternal(const char* prefix,
356                             Name* name,
357                             Address entry_point);
358
359  // Internal configurable move event.
360  void MoveEventInternal(LogEventsAndTags event, Address from, Address to);
361
362  // Emits the source code of a regexp. Used by regexp events.
363  void LogRegExpSource(Handle<JSRegExp> regexp);
364
365  // Used for logging stubs found in the snapshot.
366  void LogCodeObject(Object* code_object);
367
368  // Helper method. It resets name_buffer_ and add tag name into it.
369  void InitNameBuffer(LogEventsAndTags tag);
370
371  // Emits a profiler tick event. Used by the profiler thread.
372  void TickEvent(TickSample* sample, bool overflow);
373
374  void ApiEvent(const char* name, ...);
375
376  // Logs a StringEvent regardless of whether FLAG_log is true.
377  void UncheckedStringEvent(const char* name, const char* value);
378
379  // Logs an IntEvent regardless of whether FLAG_log is true.
380  void UncheckedIntEvent(const char* name, int value);
381  void UncheckedIntPtrTEvent(const char* name, intptr_t value);
382
383  Isolate* isolate_;
384
385  // The sampler used by the profiler and the sliding state window.
386  Ticker* ticker_;
387
388  // When the statistical profile is active, profiler_
389  // points to a Profiler, that handles collection
390  // of samples.
391  Profiler* profiler_;
392
393  // An array of log events names.
394  const char* const* log_events_;
395
396  // Internal implementation classes with access to
397  // private members.
398  friend class EventLog;
399  friend class Isolate;
400  friend class TimeLog;
401  friend class Profiler;
402  template <StateTag Tag> friend class VMState;
403  friend class LoggerTestHelper;
404
405  bool is_logging_;
406  Log* log_;
407  PerfBasicLogger* perf_basic_logger_;
408  PerfJitLogger* perf_jit_logger_;
409  LowLevelLogger* ll_logger_;
410  JitLogger* jit_logger_;
411  List<CodeEventListener*> listeners_;
412
413  // Guards against multiple calls to TearDown() that can happen in some tests.
414  // 'true' between SetUp() and TearDown().
415  bool is_initialized_;
416
417  base::ElapsedTimer timer_;
418
419  friend class CpuProfiler;
420};
421
422
423#define TIMER_EVENTS_LIST(V)    \
424  V(RecompileSynchronous, true) \
425  V(RecompileConcurrent, true)  \
426  V(CompileFullCode, true)      \
427  V(Execute, true)              \
428  V(External, true)             \
429  V(IcMiss, false)
430
431#define V(TimerName, expose)                                                  \
432  class TimerEvent##TimerName : public AllStatic {                            \
433   public:                                                                    \
434    static const char* name(void* unused = NULL) { return "V8." #TimerName; } \
435    static bool expose_to_api() { return expose; }                            \
436  };
437TIMER_EVENTS_LIST(V)
438#undef V
439
440
441template <class TimerEvent>
442class TimerEventScope {
443 public:
444  explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
445    LogTimerEvent(Logger::START);
446  }
447
448  ~TimerEventScope() { LogTimerEvent(Logger::END); }
449
450  void LogTimerEvent(Logger::StartEnd se);
451
452 private:
453  Isolate* isolate_;
454};
455
456
457class CodeEventListener {
458 public:
459  virtual ~CodeEventListener() {}
460
461  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
462                               Code* code,
463                               const char* comment) = 0;
464  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
465                               Code* code,
466                               Name* name) = 0;
467  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
468                               Code* code,
469                               SharedFunctionInfo* shared,
470                               CompilationInfo* info,
471                               Name* name) = 0;
472  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
473                               Code* code,
474                               SharedFunctionInfo* shared,
475                               CompilationInfo* info,
476                               Name* source,
477                               int line, int column) = 0;
478  virtual void CodeCreateEvent(Logger::LogEventsAndTags tag,
479                               Code* code,
480                               int args_count) = 0;
481  virtual void CallbackEvent(Name* name, Address entry_point) = 0;
482  virtual void GetterCallbackEvent(Name* name, Address entry_point) = 0;
483  virtual void SetterCallbackEvent(Name* name, Address entry_point) = 0;
484  virtual void RegExpCodeCreateEvent(Code* code, String* source) = 0;
485  virtual void CodeMoveEvent(Address from, Address to) = 0;
486  virtual void CodeDeleteEvent(Address from) = 0;
487  virtual void SharedFunctionInfoMoveEvent(Address from, Address to) = 0;
488  virtual void CodeMovingGCEvent() = 0;
489  virtual void CodeDisableOptEvent(Code* code, SharedFunctionInfo* shared) = 0;
490};
491
492
493class 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