1 // Copyright 2012 the V8 project authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #ifndef V8_LOG_H_
6 #define V8_LOG_H_
7
8 #include <string>
9
10 #include "src/allocation.h"
11 #include "src/base/platform/elapsed-timer.h"
12 #include "src/base/platform/platform.h"
13 #include "src/objects.h"
14
15 namespace v8 {
16
17 namespace base {
18 class Semaphore;
19 }
20
21 namespace internal {
22
23 // Logger is used for collecting logging information from V8 during
24 // execution. The result is dumped to a file.
25 //
26 // Available command line flags:
27 //
28 // --log
29 // Minimal logging (no API, code, or GC sample events), default is off.
30 //
31 // --log-all
32 // Log all events to the file, default is off. This is the same as combining
33 // --log-api, --log-code, --log-gc, and --log-regexp.
34 //
35 // --log-api
36 // Log API events to the logfile, default is off. --log-api implies --log.
37 //
38 // --log-code
39 // Log code (create, move, and delete) events to the logfile, default is off.
40 // --log-code implies --log.
41 //
42 // --log-gc
43 // Log GC heap samples after each GC that can be processed by hp2ps, default
44 // is off. --log-gc implies --log.
45 //
46 // --log-regexp
47 // Log creation and use of regular expressions, Default is off.
48 // --log-regexp implies --log.
49 //
50 // --logfile <filename>
51 // Specify the name of the logfile, default is "v8.log".
52 //
53 // --prof
54 // Collect statistical profiling information (ticks), default is off. The
55 // tick profiler requires code events, so --prof implies --log-code.
56
57 // Forward declarations.
58 class CodeEventListener;
59 class CompilationInfo;
60 class CpuProfiler;
61 class Isolate;
62 class Log;
63 class PositionsRecorder;
64 class Profiler;
65 class Ticker;
66 struct TickSample;
67
68 #undef LOG
69 #define LOG(isolate, Call) \
70 do { \
71 v8::internal::Logger* logger = \
72 (isolate)->logger(); \
73 if (logger->is_logging()) \
74 logger->Call; \
75 } while (false)
76
77 #define LOG_CODE_EVENT(isolate, Call) \
78 do { \
79 v8::internal::Logger* logger = \
80 (isolate)->logger(); \
81 if (logger->is_logging_code_events()) \
82 logger->Call; \
83 } while (false)
84
85
86 #define LOG_EVENTS_AND_TAGS_LIST(V) \
87 V(CODE_CREATION_EVENT, "code-creation") \
88 V(CODE_DISABLE_OPT_EVENT, "code-disable-optimization") \
89 V(CODE_MOVE_EVENT, "code-move") \
90 V(CODE_DELETE_EVENT, "code-delete") \
91 V(CODE_MOVING_GC, "code-moving-gc") \
92 V(SHARED_FUNC_MOVE_EVENT, "sfi-move") \
93 V(SNAPSHOT_POSITION_EVENT, "snapshot-pos") \
94 V(SNAPSHOT_CODE_NAME_EVENT, "snapshot-code-name") \
95 V(TICK_EVENT, "tick") \
96 V(REPEAT_META_EVENT, "repeat") \
97 V(BUILTIN_TAG, "Builtin") \
98 V(CALL_DEBUG_BREAK_TAG, "CallDebugBreak") \
99 V(CALL_DEBUG_PREPARE_STEP_IN_TAG, "CallDebugPrepareStepIn") \
100 V(CALL_INITIALIZE_TAG, "CallInitialize") \
101 V(CALL_MEGAMORPHIC_TAG, "CallMegamorphic") \
102 V(CALL_MISS_TAG, "CallMiss") \
103 V(CALL_NORMAL_TAG, "CallNormal") \
104 V(CALL_PRE_MONOMORPHIC_TAG, "CallPreMonomorphic") \
105 V(LOAD_INITIALIZE_TAG, "LoadInitialize") \
106 V(LOAD_PREMONOMORPHIC_TAG, "LoadPreMonomorphic") \
107 V(LOAD_MEGAMORPHIC_TAG, "LoadMegamorphic") \
108 V(STORE_INITIALIZE_TAG, "StoreInitialize") \
109 V(STORE_PREMONOMORPHIC_TAG, "StorePreMonomorphic") \
110 V(STORE_GENERIC_TAG, "StoreGeneric") \
111 V(STORE_MEGAMORPHIC_TAG, "StoreMegamorphic") \
112 V(KEYED_CALL_DEBUG_BREAK_TAG, "KeyedCallDebugBreak") \
113 V(KEYED_CALL_DEBUG_PREPARE_STEP_IN_TAG, \
114 "KeyedCallDebugPrepareStepIn") \
115 V(KEYED_CALL_INITIALIZE_TAG, "KeyedCallInitialize") \
116 V(KEYED_CALL_MEGAMORPHIC_TAG, "KeyedCallMegamorphic") \
117 V(KEYED_CALL_MISS_TAG, "KeyedCallMiss") \
118 V(KEYED_CALL_NORMAL_TAG, "KeyedCallNormal") \
119 V(KEYED_CALL_PRE_MONOMORPHIC_TAG, "KeyedCallPreMonomorphic") \
120 V(CALLBACK_TAG, "Callback") \
121 V(EVAL_TAG, "Eval") \
122 V(FUNCTION_TAG, "Function") \
123 V(HANDLER_TAG, "Handler") \
124 V(KEYED_LOAD_IC_TAG, "KeyedLoadIC") \
125 V(KEYED_LOAD_POLYMORPHIC_IC_TAG, "KeyedLoadPolymorphicIC") \
126 V(KEYED_EXTERNAL_ARRAY_LOAD_IC_TAG, "KeyedExternalArrayLoadIC") \
127 V(KEYED_STORE_IC_TAG, "KeyedStoreIC") \
128 V(KEYED_STORE_POLYMORPHIC_IC_TAG, "KeyedStorePolymorphicIC") \
129 V(KEYED_EXTERNAL_ARRAY_STORE_IC_TAG, "KeyedExternalArrayStoreIC") \
130 V(LAZY_COMPILE_TAG, "LazyCompile") \
131 V(CALL_IC_TAG, "CallIC") \
132 V(LOAD_IC_TAG, "LoadIC") \
133 V(LOAD_POLYMORPHIC_IC_TAG, "LoadPolymorphicIC") \
134 V(REG_EXP_TAG, "RegExp") \
135 V(SCRIPT_TAG, "Script") \
136 V(STORE_IC_TAG, "StoreIC") \
137 V(STORE_POLYMORPHIC_IC_TAG, "StorePolymorphicIC") \
138 V(STUB_TAG, "Stub") \
139 V(NATIVE_FUNCTION_TAG, "Function") \
140 V(NATIVE_LAZY_COMPILE_TAG, "LazyCompile") \
141 V(NATIVE_SCRIPT_TAG, "Script")
142 // Note that 'NATIVE_' cases for functions and scripts are mapped onto
143 // original tags when writing to the log.
144
145
146 class JitLogger;
147 class PerfBasicLogger;
148 class LowLevelLogger;
149 class PerfJitLogger;
150 class Sampler;
151
152 class 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
EmptyTimerEventsLogger(const char * name,int se)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
is_logging()311 bool is_logging() {
312 return is_logging_;
313 }
314
is_logging_code_events()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 };
TIMER_EVENTS_LIST(V)437 TIMER_EVENTS_LIST(V)
438 #undef V
439
440
441 template <class TimerEvent>
442 class 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
457 class CodeEventListener {
458 public:
~CodeEventListener()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
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
CallbackEvent(Name * name,Address entry_point)520 virtual void CallbackEvent(Name* name, Address entry_point) { }
GetterCallbackEvent(Name * name,Address entry_point)521 virtual void GetterCallbackEvent(Name* name, Address entry_point) { }
SetterCallbackEvent(Name * name,Address entry_point)522 virtual void SetterCallbackEvent(Name* name, Address entry_point) { }
SharedFunctionInfoMoveEvent(Address from,Address to)523 virtual void SharedFunctionInfoMoveEvent(Address from, Address to) { }
CodeMovingGCEvent()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