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