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