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 <set>
9 #include <string>
10
11 #include "include/v8-profiler.h"
12 #include "src/allocation.h"
13 #include "src/base/compiler-specific.h"
14 #include "src/base/platform/elapsed-timer.h"
15 #include "src/base/platform/platform.h"
16 #include "src/code-events.h"
17 #include "src/isolate.h"
18 #include "src/log-utils.h"
19 #include "src/objects.h"
20
21 namespace v8 {
22
23 struct TickSample;
24
25 namespace sampler {
26 class Sampler;
27 }
28
29 namespace internal {
30
31 // Logger is used for collecting logging information from V8 during
32 // execution. The result is dumped to a file.
33 //
34 // Available command line flags:
35 //
36 // --log
37 // Minimal logging (no API, code, or GC sample events), default is off.
38 //
39 // --log-all
40 // Log all events to the file, default is off. This is the same as combining
41 // --log-api, --log-code, and --log-regexp.
42 //
43 // --log-api
44 // Log API events to the logfile, default is off. --log-api implies --log.
45 //
46 // --log-code
47 // Log code (create, move, and delete) events to the logfile, default is off.
48 // --log-code implies --log.
49 //
50 // --log-regexp
51 // Log creation and use of regular expressions, Default is off.
52 // --log-regexp implies --log.
53 //
54 // --logfile <filename>
55 // Specify the name of the logfile, default is "v8.log".
56 //
57 // --prof
58 // Collect statistical profiling information (ticks), default is off. The
59 // tick profiler requires code events, so --prof implies --log-code.
60 //
61 // --prof-sampling-interval <microseconds>
62 // The interval between --prof samples, default is 1000 microseconds (5000 on
63 // Android).
64
65 // Forward declarations.
66 class CodeEventListener;
67 class CpuProfiler;
68 class Isolate;
69 class JitLogger;
70 class Log;
71 class LowLevelLogger;
72 class PerfBasicLogger;
73 class PerfJitLogger;
74 class Profiler;
75 class RuntimeCallTimer;
76 class Ticker;
77
78 namespace interpreter {
79 enum class Bytecode : uint8_t;
80 enum class OperandScale : uint8_t;
81 } // namespace interpreter
82
83 namespace wasm {
84 class WasmCode;
85 }
86
87 #undef LOG
88 #define LOG(isolate, Call) \
89 do { \
90 v8::internal::Logger* logger = (isolate)->logger(); \
91 if (logger->is_logging()) logger->Call; \
92 } while (false)
93
94 #define LOG_CODE_EVENT(isolate, Call) \
95 do { \
96 v8::internal::Logger* logger = (isolate)->logger(); \
97 if (logger->is_listening_to_code_events()) logger->Call; \
98 } while (false)
99
100 class ExistingCodeLogger {
101 public:
102 explicit ExistingCodeLogger(Isolate* isolate,
103 CodeEventListener* listener = nullptr)
isolate_(isolate)104 : isolate_(isolate), listener_(listener) {}
105
106 void LogCodeObjects();
107 void LogBytecodeHandlers();
108
109 void LogCompiledFunctions();
110 void LogExistingFunction(Handle<SharedFunctionInfo> shared,
111 Handle<AbstractCode> code,
112 CodeEventListener::LogEventsAndTags tag =
113 CodeEventListener::LAZY_COMPILE_TAG);
114 void LogCodeObject(Object* object);
115 void LogBytecodeHandler(interpreter::Bytecode bytecode,
116 interpreter::OperandScale operand_scale, Code* code);
117
118 private:
119 Isolate* isolate_;
120 CodeEventListener* listener_;
121 };
122
123 class Logger : public CodeEventListener {
124 public:
125 enum StartEnd { START = 0, END = 1, STAMP = 2 };
126
127 enum class ScriptEventType {
128 kReserveId,
129 kCreate,
130 kDeserialize,
131 kBackgroundCompile,
132 kStreamingCompile
133 };
134
135 // The separator is used to write an unescaped "," into the log.
136 static const LogSeparator kNext = LogSeparator::kSeparator;
137
138 // Acquires resources for logging if the right flags are set.
139 bool SetUp(Isolate* isolate);
140
141 // Sets the current code event handler.
142 void SetCodeEventHandler(uint32_t options,
143 JitCodeEventHandler event_handler);
144
145 sampler::Sampler* sampler();
146
147 void StopProfilerThread();
148
149 // Frees resources acquired in SetUp.
150 // When a temporary file is used for the log, returns its stream descriptor,
151 // leaving the file open.
152 FILE* TearDown();
153
154 // Emits an event with a string value -> (name, value).
155 void StringEvent(const char* name, const char* value);
156
157 // Emits an event with an int value -> (name, value).
158 void IntPtrTEvent(const char* name, intptr_t value);
159
160 // Emits an event with an handle value -> (name, location).
161 void HandleEvent(const char* name, Object** location);
162
163 // Emits memory management events for C allocated structures.
164 void NewEvent(const char* name, void* object, size_t size);
165 void DeleteEvent(const char* name, void* object);
166
167 // Emits an event with a tag, and some resource usage information.
168 // -> (name, tag, <rusage information>).
169 // Currently, the resource usage information is a process time stamp
170 // and a real time timestamp.
171 void ResourceEvent(const char* name, const char* tag);
172
173 // Emits an event that an undefined property was read from an
174 // object.
175 void SuspectReadEvent(Name* name, Object* obj);
176
177 // ==== Events logged by --log-function-events ====
178 void FunctionEvent(const char* reason, int script_id, double time_delta_ms,
179 int start_position = -1, int end_position = -1,
180 String* function_name = nullptr);
181 void FunctionEvent(const char* reason, int script_id, double time_delta_ms,
182 int start_position, int end_position,
183 const char* function_name = nullptr,
184 size_t function_name_length = 0);
185
186 void CompilationCacheEvent(const char* action, const char* cache_type,
187 SharedFunctionInfo* sfi);
188 void ScriptEvent(ScriptEventType type, int script_id);
189 void ScriptDetails(Script* script);
190
191 // ==== Events logged by --log-api. ====
192 void ApiSecurityCheck();
193 void ApiNamedPropertyAccess(const char* tag, JSObject* holder, Object* name);
194 void ApiIndexedPropertyAccess(const char* tag,
195 JSObject* holder,
196 uint32_t index);
197 void ApiObjectAccess(const char* tag, JSObject* obj);
198 void ApiEntryCall(const char* name);
199
200 // ==== Events logged by --log-code. ====
201 void AddCodeEventListener(CodeEventListener* listener);
202 void RemoveCodeEventListener(CodeEventListener* listener);
203
204 // Emits a code event for a callback function.
205 void CallbackEvent(Name* name, Address entry_point);
206 void GetterCallbackEvent(Name* name, Address entry_point);
207 void SetterCallbackEvent(Name* name, Address entry_point);
208 // Emits a code create event.
209 void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
210 AbstractCode* code, const char* source);
211 void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
212 AbstractCode* code, Name* name);
213 void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
214 AbstractCode* code, SharedFunctionInfo* shared,
215 Name* name);
216 void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
217 AbstractCode* code, SharedFunctionInfo* shared,
218 Name* source, int line, int column);
219 void CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
220 const wasm::WasmCode* code, wasm::WasmName name);
221 // Emits a code deoptimization event.
222 void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared);
223 void CodeMovingGCEvent();
224 // Emits a code create event for a RegExp.
225 void RegExpCodeCreateEvent(AbstractCode* code, String* source);
226 // Emits a code move event.
227 void CodeMoveEvent(AbstractCode* from, AbstractCode* to);
228 // Emits a code line info record event.
229 void CodeLinePosInfoRecordEvent(Address code_start,
230 ByteArray* source_position_table);
231 void CodeLinePosInfoRecordEvent(Address code_start,
232 Vector<const byte> source_position_table);
233
234 void SharedFunctionInfoMoveEvent(Address from, Address to);
235
236 void CodeNameEvent(Address addr, int pos, const char* code_name);
237
238 void CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
239 int fp_to_sp_delta);
240
241 void ICEvent(const char* type, bool keyed, Map* map, Object* key,
242 char old_state, char new_state, const char* modifier,
243 const char* slow_stub_reason);
244
245 void MapEvent(const char* type, Map* from, Map* to,
246 const char* reason = nullptr,
247 HeapObject* name_or_sfi = nullptr);
248 void MapCreate(Map* map);
249 void MapDetails(Map* map);
250
251
252 void SharedLibraryEvent(const std::string& library_path, uintptr_t start,
253 uintptr_t end, intptr_t aslr_slide);
254
255 void CurrentTimeEvent();
256
257 V8_EXPORT_PRIVATE void TimerEvent(StartEnd se, const char* name);
258
259 static void EnterExternal(Isolate* isolate);
260 static void LeaveExternal(Isolate* isolate);
261
DefaultEventLoggerSentinel(const char * name,int event)262 static void DefaultEventLoggerSentinel(const char* name, int event) {}
263
264 V8_INLINE static void CallEventLogger(Isolate* isolate, const char* name,
265 StartEnd se, bool expose_to_api);
266
is_logging()267 bool is_logging() {
268 return is_logging_;
269 }
270
is_listening_to_code_events()271 bool is_listening_to_code_events() {
272 return is_logging() || jit_logger_ != nullptr;
273 }
274
275 // Stop collection of profiling data.
276 // When data collection is paused, CPU Tick events are discarded.
277 void StopProfiler();
278
279 void LogExistingFunction(Handle<SharedFunctionInfo> shared,
280 Handle<AbstractCode> code);
281 // Logs all compiled functions found in the heap.
282 void LogCompiledFunctions();
283 // Logs all accessor callbacks found in the heap.
284 void LogAccessorCallbacks();
285 // Used for logging stubs found in the snapshot.
286 void LogCodeObjects();
287 // Used for logging bytecode handlers found in the snapshot.
288 void LogBytecodeHandlers();
289 void LogBytecodeHandler(interpreter::Bytecode bytecode,
290 interpreter::OperandScale operand_scale, Code* code);
291 // Logs all Mpas foind in the heap.
292 void LogMaps();
293
294 // Converts tag to a corresponding NATIVE_... if the script is native.
295 V8_INLINE static CodeEventListener::LogEventsAndTags ToNativeByScript(
296 CodeEventListener::LogEventsAndTags, Script*);
297
298 // Callback from Log, stops profiling in case of insufficient resources.
299 void LogFailure();
300
301 // Used for logging stubs found in the snapshot.
302 void LogCodeObject(Object* code_object);
303
304 private:
305 explicit Logger(Isolate* isolate);
306 ~Logger();
307
308 // Emits the profiler's first message.
309 void ProfilerBeginEvent();
310
311 // Emits callback event messages.
312 void CallbackEventInternal(const char* prefix,
313 Name* name,
314 Address entry_point);
315
316 // Internal configurable move event.
317 void MoveEventInternal(CodeEventListener::LogEventsAndTags event,
318 Address from, Address to);
319
320 // Helper method. It resets name_buffer_ and add tag name into it.
321 void InitNameBuffer(CodeEventListener::LogEventsAndTags tag);
322
323 // Emits a profiler tick event. Used by the profiler thread.
324 void TickEvent(TickSample* sample, bool overflow);
325 void RuntimeCallTimerEvent();
326
327 // Logs a StringEvent regardless of whether FLAG_log is true.
328 void UncheckedStringEvent(const char* name, const char* value);
329
330 // Logs an IntPtrTEvent regardless of whether FLAG_log is true.
331 void UncheckedIntPtrTEvent(const char* name, intptr_t value);
332
333 // Logs a scripts sources. Keeps track of all logged scripts to ensure that
334 // each script is logged only once.
335 bool EnsureLogScriptSource(Script* script);
336
337 Isolate* isolate_;
338
339 // The sampler used by the profiler and the sliding state window.
340 Ticker* ticker_;
341
342 // When the statistical profile is active, profiler_
343 // points to a Profiler, that handles collection
344 // of samples.
345 Profiler* profiler_;
346
347 // An array of log events names.
348 const char* const* log_events_;
349
350 // Internal implementation classes with access to
351 // private members.
352 friend class EventLog;
353 friend class Isolate;
354 friend class TimeLog;
355 friend class Profiler;
356 template <StateTag Tag> friend class VMState;
357 friend class LoggerTestHelper;
358
359 bool is_logging_;
360 Log* log_;
361 PerfBasicLogger* perf_basic_logger_;
362 PerfJitLogger* perf_jit_logger_;
363 LowLevelLogger* ll_logger_;
364 JitLogger* jit_logger_;
365 std::set<int> logged_source_code_;
366 uint32_t next_source_info_id_ = 0;
367
368 // Guards against multiple calls to TearDown() that can happen in some tests.
369 // 'true' between SetUp() and TearDown().
370 bool is_initialized_;
371
372 ExistingCodeLogger existing_code_logger_;
373
374 base::ElapsedTimer timer_;
375
376 friend class CpuProfiler;
377 };
378
379 #define TIMER_EVENTS_LIST(V) \
380 V(RecompileSynchronous, true) \
381 V(RecompileConcurrent, true) \
382 V(CompileIgnition, true) \
383 V(CompileFullCode, true) \
384 V(OptimizeCode, true) \
385 V(CompileCode, true) \
386 V(CompileCodeBackground, true) \
387 V(DeoptimizeCode, true) \
388 V(Execute, true) \
389 V(External, true)
390
391 #define V(TimerName, expose) \
392 class TimerEvent##TimerName : public AllStatic { \
393 public: \
394 static const char* name(void* unused = nullptr) { \
395 return "V8." #TimerName; \
396 } \
397 static bool expose_to_api() { return expose; } \
398 };
TIMER_EVENTS_LIST(V)399 TIMER_EVENTS_LIST(V)
400 #undef V
401
402
403 template <class TimerEvent>
404 class TimerEventScope {
405 public:
406 explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
407 LogTimerEvent(Logger::START);
408 }
409
410 ~TimerEventScope() { LogTimerEvent(Logger::END); }
411
412 private:
413 void LogTimerEvent(Logger::StartEnd se);
414 Isolate* isolate_;
415 };
416
417 class CodeEventLogger : public CodeEventListener {
418 public:
419 explicit CodeEventLogger(Isolate* isolate);
420 ~CodeEventLogger() override;
421
422 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
423 const char* comment) override;
424 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
425 Name* name) override;
426 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
427 SharedFunctionInfo* shared, Name* name) override;
428 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
429 SharedFunctionInfo* shared, Name* source, int line,
430 int column) override;
431 void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
432 wasm::WasmName name) override;
433
434 void RegExpCodeCreateEvent(AbstractCode* code, String* source) override;
CallbackEvent(Name * name,Address entry_point)435 void CallbackEvent(Name* name, Address entry_point) override {}
GetterCallbackEvent(Name * name,Address entry_point)436 void GetterCallbackEvent(Name* name, Address entry_point) override {}
SetterCallbackEvent(Name * name,Address entry_point)437 void SetterCallbackEvent(Name* name, Address entry_point) override {}
SharedFunctionInfoMoveEvent(Address from,Address to)438 void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
CodeMovingGCEvent()439 void CodeMovingGCEvent() override {}
CodeDeoptEvent(Code * code,DeoptimizeKind kind,Address pc,int fp_to_sp_delta)440 void CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
441 int fp_to_sp_delta) override {}
442
443 protected:
444 Isolate* isolate_;
445
446 private:
447 class NameBuffer;
448
449 virtual void LogRecordedBuffer(AbstractCode* code, SharedFunctionInfo* shared,
450 const char* name, int length) = 0;
451 virtual void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
452 int length) = 0;
453
454 NameBuffer* name_buffer_;
455 };
456
457 struct CodeEvent {
458 Isolate* isolate_;
459 uintptr_t code_start_address;
460 size_t code_size;
461 Handle<String> function_name;
462 Handle<String> script_name;
463 int script_line;
464 int script_column;
465 CodeEventType code_type;
466 const char* comment;
467 };
468
469 class ExternalCodeEventListener : public CodeEventListener {
470 public:
471 explicit ExternalCodeEventListener(Isolate* isolate);
472 ~ExternalCodeEventListener() override;
473
474 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
475 const char* comment) override;
476 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
477 Name* name) override;
478 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
479 SharedFunctionInfo* shared, Name* name) override;
480 void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
481 SharedFunctionInfo* shared, Name* source, int line,
482 int column) override;
483 void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
484 wasm::WasmName name) override;
485
486 void RegExpCodeCreateEvent(AbstractCode* code, String* source) override;
CallbackEvent(Name * name,Address entry_point)487 void CallbackEvent(Name* name, Address entry_point) override {}
GetterCallbackEvent(Name * name,Address entry_point)488 void GetterCallbackEvent(Name* name, Address entry_point) override {}
SetterCallbackEvent(Name * name,Address entry_point)489 void SetterCallbackEvent(Name* name, Address entry_point) override {}
SharedFunctionInfoMoveEvent(Address from,Address to)490 void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
CodeMoveEvent(AbstractCode * from,AbstractCode * to)491 void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override {}
CodeDisableOptEvent(AbstractCode * code,SharedFunctionInfo * shared)492 void CodeDisableOptEvent(AbstractCode* code,
493 SharedFunctionInfo* shared) override {}
CodeMovingGCEvent()494 void CodeMovingGCEvent() override {}
CodeDeoptEvent(Code * code,DeoptimizeKind kind,Address pc,int fp_to_sp_delta)495 void CodeDeoptEvent(Code* code, DeoptimizeKind kind, Address pc,
496 int fp_to_sp_delta) override {}
497
498 void StartListening(CodeEventHandler* code_event_handler);
499 void StopListening();
500
is_listening_to_code_events()501 bool is_listening_to_code_events() override { return true; }
502
503 private:
504 void LogExistingCode();
505
506 bool is_listening_;
507 Isolate* isolate_;
508 v8::CodeEventHandler* code_event_handler_;
509 };
510
511 } // namespace internal
512 } // namespace v8
513
514
515 #endif // V8_LOG_H_
516