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