1 // Copyright 2011 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 #include "src/logging/log.h"
6
7 #include <atomic>
8 #include <cstdarg>
9 #include <memory>
10 #include <sstream>
11
12 #include "include/v8-locker.h"
13 #include "src/api/api-inl.h"
14 #include "src/base/platform/mutex.h"
15 #include "src/base/platform/platform.h"
16 #include "src/base/platform/wrappers.h"
17 #include "src/builtins/profile-data-reader.h"
18 #include "src/codegen/bailout-reason.h"
19 #include "src/codegen/macro-assembler.h"
20 #include "src/codegen/source-position-table.h"
21 #include "src/deoptimizer/deoptimizer.h"
22 #include "src/diagnostics/perf-jit.h"
23 #include "src/execution/isolate.h"
24 #include "src/execution/v8threads.h"
25 #include "src/execution/vm-state-inl.h"
26 #include "src/handles/global-handles.h"
27 #include "src/heap/combined-heap.h"
28 #include "src/heap/heap-inl.h"
29 #include "src/init/bootstrapper.h"
30 #include "src/interpreter/bytecodes.h"
31 #include "src/interpreter/interpreter.h"
32 #include "src/libsampler/sampler.h"
33 #include "src/logging/counters.h"
34 #include "src/logging/log-inl.h"
35 #include "src/logging/log-utils.h"
36 #include "src/objects/api-callbacks.h"
37 #include "src/objects/code-kind.h"
38 #include "src/objects/code.h"
39 #include "src/profiler/tick-sample.h"
40 #include "src/snapshot/embedded/embedded-data.h"
41 #include "src/strings/string-stream.h"
42 #include "src/strings/unicode-inl.h"
43 #include "src/tracing/tracing-category-observer.h"
44 #include "src/utils/memcopy.h"
45 #include "src/utils/version.h"
46
47 #ifdef ENABLE_GDB_JIT_INTERFACE
48 #include "src/diagnostics/gdb-jit.h"
49 #endif // ENABLE_GDB_JIT_INTERFACE
50
51 #if V8_ENABLE_WEBASSEMBLY
52 #include "src/wasm/wasm-code-manager.h"
53 #include "src/wasm/wasm-engine.h"
54 #include "src/wasm/wasm-objects-inl.h"
55 #endif // V8_ENABLE_WEBASSEMBLY
56
57 #if V8_OS_WIN
58 #if defined(V8_ENABLE_SYSTEM_INSTRUMENTATION)
59 #include "src/diagnostics/system-jit-win.h"
60 #endif
61 #endif // V8_OS_WIN
62
63 namespace v8 {
64 namespace internal {
65
66 #define DECLARE_EVENT(ignore1, name) #name,
67 static const char* kLogEventsNames[CodeEventListener::NUMBER_OF_LOG_EVENTS] = {
68 LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)};
69 #undef DECLARE_EVENT
70
GetCodeEventTypeForTag(CodeEventListener::LogEventsAndTags tag)71 static v8::CodeEventType GetCodeEventTypeForTag(
72 CodeEventListener::LogEventsAndTags tag) {
73 switch (tag) {
74 case CodeEventListener::NUMBER_OF_LOG_EVENTS:
75 #define V(Event, _) case CodeEventListener::Event:
76 LOG_EVENTS_LIST(V)
77 #undef V
78 return v8::CodeEventType::kUnknownType;
79 #define V(From, To) \
80 case CodeEventListener::From: \
81 return v8::CodeEventType::k##To##Type;
82 TAGS_LIST(V)
83 #undef V
84 }
85 // The execution should never pass here
86 UNREACHABLE();
87 }
88 #define CALL_CODE_EVENT_HANDLER(Call) \
89 if (listener_) { \
90 listener_->Call; \
91 } else { \
92 PROFILE(isolate_, Call); \
93 }
94
ComputeMarker(SharedFunctionInfo shared,AbstractCode code)95 static const char* ComputeMarker(SharedFunctionInfo shared, AbstractCode code) {
96 CodeKind kind = code.kind();
97 // We record interpreter trampoline builtin copies as having the
98 // "interpreted" marker.
99 if (FLAG_interpreted_frames_native_stack && kind == CodeKind::BUILTIN &&
100 code.GetCode().is_interpreter_trampoline_builtin() &&
101 ToCodeT(code.GetCode()) !=
102 *BUILTIN_CODE(shared.GetIsolate(), InterpreterEntryTrampoline)) {
103 kind = CodeKind::INTERPRETED_FUNCTION;
104 }
105 if (shared.optimization_disabled() &&
106 kind == CodeKind::INTERPRETED_FUNCTION) {
107 return "";
108 }
109 return CodeKindToMarker(kind);
110 }
111
112 #if V8_ENABLE_WEBASSEMBLY
ComputeMarker(const wasm::WasmCode * code)113 static const char* ComputeMarker(const wasm::WasmCode* code) {
114 switch (code->kind()) {
115 case wasm::WasmCode::kWasmFunction:
116 return code->is_liftoff() ? "" : "*";
117 default:
118 return "";
119 }
120 }
121 #endif // V8_ENABLE_WEBASSEMBLY
122
123 class CodeEventLogger::NameBuffer {
124 public:
NameBuffer()125 NameBuffer() { Reset(); }
126
Reset()127 void Reset() { utf8_pos_ = 0; }
128
Init(LogEventsAndTags tag)129 void Init(LogEventsAndTags tag) {
130 Reset();
131 AppendBytes(kLogEventsNames[tag]);
132 AppendByte(':');
133 }
134
AppendName(Name name)135 void AppendName(Name name) {
136 if (name.IsString()) {
137 AppendString(String::cast(name));
138 } else {
139 Symbol symbol = Symbol::cast(name);
140 AppendBytes("symbol(");
141 if (!symbol.description().IsUndefined()) {
142 AppendBytes("\"");
143 AppendString(String::cast(symbol.description()));
144 AppendBytes("\" ");
145 }
146 AppendBytes("hash ");
147 AppendHex(symbol.hash());
148 AppendByte(')');
149 }
150 }
151
AppendString(String str)152 void AppendString(String str) {
153 if (str.is_null()) return;
154 int length = 0;
155 std::unique_ptr<char[]> c_str =
156 str.ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL, &length);
157 AppendBytes(c_str.get(), length);
158 }
159
AppendBytes(const char * bytes,int size)160 void AppendBytes(const char* bytes, int size) {
161 size = std::min(size, kUtf8BufferSize - utf8_pos_);
162 MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);
163 utf8_pos_ += size;
164 }
165
AppendBytes(const char * bytes)166 void AppendBytes(const char* bytes) {
167 size_t len = strlen(bytes);
168 DCHECK_GE(kMaxInt, len);
169 AppendBytes(bytes, static_cast<int>(len));
170 }
171
AppendByte(char c)172 void AppendByte(char c) {
173 if (utf8_pos_ >= kUtf8BufferSize) return;
174 utf8_buffer_[utf8_pos_++] = c;
175 }
176
AppendInt(int n)177 void AppendInt(int n) {
178 int space = kUtf8BufferSize - utf8_pos_;
179 if (space <= 0) return;
180 base::Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
181 int size = SNPrintF(buffer, "%d", n);
182 if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
183 utf8_pos_ += size;
184 }
185 }
186
AppendHex(uint32_t n)187 void AppendHex(uint32_t n) {
188 int space = kUtf8BufferSize - utf8_pos_;
189 if (space <= 0) return;
190 base::Vector<char> buffer(utf8_buffer_ + utf8_pos_, space);
191 int size = SNPrintF(buffer, "%x", n);
192 if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
193 utf8_pos_ += size;
194 }
195 }
196
get()197 const char* get() { return utf8_buffer_; }
size() const198 int size() const { return utf8_pos_; }
199
200 private:
201 static const int kUtf8BufferSize = 512;
202 static const int kUtf16BufferSize = kUtf8BufferSize;
203
204 int utf8_pos_;
205 char utf8_buffer_[kUtf8BufferSize];
206 };
207
CodeEventLogger(Isolate * isolate)208 CodeEventLogger::CodeEventLogger(Isolate* isolate)
209 : isolate_(isolate), name_buffer_(std::make_unique<NameBuffer>()) {}
210
211 CodeEventLogger::~CodeEventLogger() = default;
212
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,const char * comment)213 void CodeEventLogger::CodeCreateEvent(LogEventsAndTags tag,
214 Handle<AbstractCode> code,
215 const char* comment) {
216 DCHECK(is_listening_to_code_events());
217 name_buffer_->Init(tag);
218 name_buffer_->AppendBytes(comment);
219 LogRecordedBuffer(code, MaybeHandle<SharedFunctionInfo>(),
220 name_buffer_->get(), name_buffer_->size());
221 }
222
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<Name> name)223 void CodeEventLogger::CodeCreateEvent(LogEventsAndTags tag,
224 Handle<AbstractCode> code,
225 Handle<Name> name) {
226 DCHECK(is_listening_to_code_events());
227 name_buffer_->Init(tag);
228 name_buffer_->AppendName(*name);
229 LogRecordedBuffer(code, MaybeHandle<SharedFunctionInfo>(),
230 name_buffer_->get(), name_buffer_->size());
231 }
232
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared,Handle<Name> script_name)233 void CodeEventLogger::CodeCreateEvent(LogEventsAndTags tag,
234 Handle<AbstractCode> code,
235 Handle<SharedFunctionInfo> shared,
236 Handle<Name> script_name) {
237 DCHECK(is_listening_to_code_events());
238 name_buffer_->Init(tag);
239 name_buffer_->AppendBytes(ComputeMarker(*shared, *code));
240 name_buffer_->AppendByte(' ');
241 name_buffer_->AppendName(*script_name);
242 LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
243 }
244
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared,Handle<Name> script_name,int line,int column)245 void CodeEventLogger::CodeCreateEvent(LogEventsAndTags tag,
246 Handle<AbstractCode> code,
247 Handle<SharedFunctionInfo> shared,
248 Handle<Name> script_name, int line,
249 int column) {
250 DCHECK(is_listening_to_code_events());
251 name_buffer_->Init(tag);
252 name_buffer_->AppendBytes(ComputeMarker(*shared, *code));
253 name_buffer_->AppendBytes(shared->DebugNameCStr().get());
254 name_buffer_->AppendByte(' ');
255 if (script_name->IsString()) {
256 name_buffer_->AppendString(String::cast(*script_name));
257 } else {
258 name_buffer_->AppendBytes("symbol(hash ");
259 name_buffer_->AppendHex(Name::cast(*script_name).hash());
260 name_buffer_->AppendByte(')');
261 }
262 name_buffer_->AppendByte(':');
263 name_buffer_->AppendInt(line);
264 LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
265 }
266
267 #if V8_ENABLE_WEBASSEMBLY
CodeCreateEvent(LogEventsAndTags tag,const wasm::WasmCode * code,wasm::WasmName name,const char * source_url,int,int)268 void CodeEventLogger::CodeCreateEvent(LogEventsAndTags tag,
269 const wasm::WasmCode* code,
270 wasm::WasmName name,
271 const char* source_url,
272 int /*code_offset*/, int /*script_id*/) {
273 DCHECK(is_listening_to_code_events());
274 name_buffer_->Init(tag);
275 DCHECK(!name.empty());
276 name_buffer_->AppendBytes(name.begin(), name.length());
277 name_buffer_->AppendByte('-');
278 if (code->IsAnonymous()) {
279 name_buffer_->AppendBytes("<anonymous>");
280 } else {
281 name_buffer_->AppendInt(code->index());
282 }
283 name_buffer_->AppendByte('-');
284 name_buffer_->AppendBytes(ExecutionTierToString(code->tier()));
285 LogRecordedBuffer(code, name_buffer_->get(), name_buffer_->size());
286 }
287 #endif // V8_ENABLE_WEBASSEMBLY
288
RegExpCodeCreateEvent(Handle<AbstractCode> code,Handle<String> source)289 void CodeEventLogger::RegExpCodeCreateEvent(Handle<AbstractCode> code,
290 Handle<String> source) {
291 DCHECK(is_listening_to_code_events());
292 name_buffer_->Init(CodeEventListener::REG_EXP_TAG);
293 name_buffer_->AppendString(*source);
294 LogRecordedBuffer(code, MaybeHandle<SharedFunctionInfo>(),
295 name_buffer_->get(), name_buffer_->size());
296 }
297
298 // Linux perf tool logging support.
299 #if V8_OS_LINUX
300 class PerfBasicLogger : public CodeEventLogger {
301 public:
302 explicit PerfBasicLogger(Isolate* isolate);
303 ~PerfBasicLogger() override;
304
CodeMoveEvent(AbstractCode from,AbstractCode to)305 void CodeMoveEvent(AbstractCode from, AbstractCode to) override {}
CodeDisableOptEvent(Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared)306 void CodeDisableOptEvent(Handle<AbstractCode> code,
307 Handle<SharedFunctionInfo> shared) override {}
308
309 private:
310 void LogRecordedBuffer(Handle<AbstractCode> code,
311 MaybeHandle<SharedFunctionInfo> maybe_shared,
312 const char* name, int length) override;
313 #if V8_ENABLE_WEBASSEMBLY
314 void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
315 int length) override;
316 #endif // V8_ENABLE_WEBASSEMBLY
317 void WriteLogRecordedBuffer(uintptr_t address, int size, const char* name,
318 int name_length);
319
320 // Extension added to V8 log file name to get the low-level log name.
321 static const char kFilenameFormatString[];
322 static const int kFilenameBufferPadding;
323
324 FILE* perf_output_handle_;
325 };
326
327 const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
328 // Extra space for the PID in the filename
329 const int PerfBasicLogger::kFilenameBufferPadding = 16;
330
PerfBasicLogger(Isolate * isolate)331 PerfBasicLogger::PerfBasicLogger(Isolate* isolate)
332 : CodeEventLogger(isolate), perf_output_handle_(nullptr) {
333 // Open the perf JIT dump file.
334 int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
335 base::ScopedVector<char> perf_dump_name(bufferSize);
336 int size = SNPrintF(perf_dump_name, kFilenameFormatString,
337 base::OS::GetCurrentProcessId());
338 CHECK_NE(size, -1);
339 perf_output_handle_ =
340 base::OS::FOpen(perf_dump_name.begin(), base::OS::LogFileOpenMode);
341 CHECK_NOT_NULL(perf_output_handle_);
342 setvbuf(perf_output_handle_, nullptr, _IOLBF, 0);
343 }
344
~PerfBasicLogger()345 PerfBasicLogger::~PerfBasicLogger() {
346 base::Fclose(perf_output_handle_);
347 perf_output_handle_ = nullptr;
348 }
349
WriteLogRecordedBuffer(uintptr_t address,int size,const char * name,int name_length)350 void PerfBasicLogger::WriteLogRecordedBuffer(uintptr_t address, int size,
351 const char* name,
352 int name_length) {
353 // Linux perf expects hex literals without a leading 0x, while some
354 // implementations of printf might prepend one when using the %p format
355 // for pointers, leading to wrongly formatted JIT symbols maps.
356 //
357 // Instead, we use V8PRIxPTR format string and cast pointer to uintpr_t,
358 // so that we have control over the exact output format.
359 base::OS::FPrint(perf_output_handle_, "%" V8PRIxPTR " %x %.*s\n", address,
360 size, name_length, name);
361 }
362
LogRecordedBuffer(Handle<AbstractCode> code,MaybeHandle<SharedFunctionInfo>,const char * name,int length)363 void PerfBasicLogger::LogRecordedBuffer(Handle<AbstractCode> code,
364 MaybeHandle<SharedFunctionInfo>,
365 const char* name, int length) {
366 if (FLAG_perf_basic_prof_only_functions &&
367 !CodeKindIsBuiltinOrJSFunction(code->kind())) {
368 return;
369 }
370
371 WriteLogRecordedBuffer(static_cast<uintptr_t>(code->InstructionStart()),
372 code->InstructionSize(), name, length);
373 }
374
375 #if V8_ENABLE_WEBASSEMBLY
LogRecordedBuffer(const wasm::WasmCode * code,const char * name,int length)376 void PerfBasicLogger::LogRecordedBuffer(const wasm::WasmCode* code,
377 const char* name, int length) {
378 WriteLogRecordedBuffer(static_cast<uintptr_t>(code->instruction_start()),
379 code->instructions().length(), name, length);
380 }
381 #endif // V8_ENABLE_WEBASSEMBLY
382 #endif // V8_OS_LINUX
383
384 // External CodeEventListener
ExternalCodeEventListener(Isolate * isolate)385 ExternalCodeEventListener::ExternalCodeEventListener(Isolate* isolate)
386 : is_listening_(false), isolate_(isolate), code_event_handler_(nullptr) {}
387
~ExternalCodeEventListener()388 ExternalCodeEventListener::~ExternalCodeEventListener() {
389 if (is_listening_) {
390 StopListening();
391 }
392 }
393
LogExistingCode()394 void ExternalCodeEventListener::LogExistingCode() {
395 HandleScope scope(isolate_);
396 ExistingCodeLogger logger(isolate_, this);
397 logger.LogCodeObjects();
398 logger.LogCompiledFunctions();
399 }
400
StartListening(CodeEventHandler * code_event_handler)401 void ExternalCodeEventListener::StartListening(
402 CodeEventHandler* code_event_handler) {
403 if (is_listening_ || code_event_handler == nullptr) {
404 return;
405 }
406 code_event_handler_ = code_event_handler;
407 is_listening_ = isolate_->code_event_dispatcher()->AddListener(this);
408 if (is_listening_) {
409 LogExistingCode();
410 }
411 }
412
StopListening()413 void ExternalCodeEventListener::StopListening() {
414 if (!is_listening_) {
415 return;
416 }
417
418 isolate_->code_event_dispatcher()->RemoveListener(this);
419 is_listening_ = false;
420 }
421
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,const char * comment)422 void ExternalCodeEventListener::CodeCreateEvent(LogEventsAndTags tag,
423 Handle<AbstractCode> code,
424 const char* comment) {
425 CodeEvent code_event;
426 code_event.code_start_address =
427 static_cast<uintptr_t>(code->InstructionStart());
428 code_event.code_size = static_cast<size_t>(code->InstructionSize());
429 code_event.function_name = isolate_->factory()->empty_string();
430 code_event.script_name = isolate_->factory()->empty_string();
431 code_event.script_line = 0;
432 code_event.script_column = 0;
433 code_event.code_type = GetCodeEventTypeForTag(tag);
434 code_event.comment = comment;
435
436 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
437 }
438
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<Name> name)439 void ExternalCodeEventListener::CodeCreateEvent(LogEventsAndTags tag,
440 Handle<AbstractCode> code,
441 Handle<Name> name) {
442 Handle<String> name_string =
443 Name::ToFunctionName(isolate_, name).ToHandleChecked();
444
445 CodeEvent code_event;
446 code_event.code_start_address =
447 static_cast<uintptr_t>(code->InstructionStart());
448 code_event.code_size = static_cast<size_t>(code->InstructionSize());
449 code_event.function_name = name_string;
450 code_event.script_name = isolate_->factory()->empty_string();
451 code_event.script_line = 0;
452 code_event.script_column = 0;
453 code_event.code_type = GetCodeEventTypeForTag(tag);
454 code_event.comment = "";
455
456 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
457 }
458
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared,Handle<Name> name)459 void ExternalCodeEventListener::CodeCreateEvent(
460 LogEventsAndTags tag, Handle<AbstractCode> code,
461 Handle<SharedFunctionInfo> shared, Handle<Name> name) {
462 Handle<String> name_string =
463 Name::ToFunctionName(isolate_, name).ToHandleChecked();
464
465 CodeEvent code_event;
466 code_event.code_start_address =
467 static_cast<uintptr_t>(code->InstructionStart());
468 code_event.code_size = static_cast<size_t>(code->InstructionSize());
469 code_event.function_name = name_string;
470 code_event.script_name = isolate_->factory()->empty_string();
471 code_event.script_line = 0;
472 code_event.script_column = 0;
473 code_event.code_type = GetCodeEventTypeForTag(tag);
474 code_event.comment = "";
475
476 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
477 }
478
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared,Handle<Name> source,int line,int column)479 void ExternalCodeEventListener::CodeCreateEvent(
480 LogEventsAndTags tag, Handle<AbstractCode> code,
481 Handle<SharedFunctionInfo> shared, Handle<Name> source, int line,
482 int column) {
483 Handle<String> name_string =
484 Name::ToFunctionName(isolate_, handle(shared->Name(), isolate_))
485 .ToHandleChecked();
486 Handle<String> source_string =
487 Name::ToFunctionName(isolate_, source).ToHandleChecked();
488
489 CodeEvent code_event;
490 code_event.code_start_address =
491 static_cast<uintptr_t>(code->InstructionStart());
492 code_event.code_size = static_cast<size_t>(code->InstructionSize());
493 code_event.function_name = name_string;
494 code_event.script_name = source_string;
495 code_event.script_line = line;
496 code_event.script_column = column;
497 code_event.code_type = GetCodeEventTypeForTag(tag);
498 code_event.comment = "";
499
500 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
501 }
502
503 #if V8_ENABLE_WEBASSEMBLY
CodeCreateEvent(LogEventsAndTags tag,const wasm::WasmCode * code,wasm::WasmName name,const char * source_url,int code_offset,int script_id)504 void ExternalCodeEventListener::CodeCreateEvent(
505 LogEventsAndTags tag, const wasm::WasmCode* code, wasm::WasmName name,
506 const char* source_url, int code_offset, int script_id) {
507 // TODO(mmarchini): handle later
508 }
509 #endif // V8_ENABLE_WEBASSEMBLY
510
RegExpCodeCreateEvent(Handle<AbstractCode> code,Handle<String> source)511 void ExternalCodeEventListener::RegExpCodeCreateEvent(Handle<AbstractCode> code,
512 Handle<String> source) {
513 CodeEvent code_event;
514 code_event.code_start_address =
515 static_cast<uintptr_t>(code->InstructionStart());
516 code_event.code_size = static_cast<size_t>(code->InstructionSize());
517 code_event.function_name = source;
518 code_event.script_name = isolate_->factory()->empty_string();
519 code_event.script_line = 0;
520 code_event.script_column = 0;
521 code_event.code_type = GetCodeEventTypeForTag(CodeEventListener::REG_EXP_TAG);
522 code_event.comment = "";
523
524 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
525 }
526
CodeMoveEvent(AbstractCode from,AbstractCode to)527 void ExternalCodeEventListener::CodeMoveEvent(AbstractCode from,
528 AbstractCode to) {
529 CodeEvent code_event;
530 code_event.previous_code_start_address =
531 static_cast<uintptr_t>(from.InstructionStart());
532 code_event.code_start_address = static_cast<uintptr_t>(to.InstructionStart());
533 code_event.code_size = static_cast<size_t>(to.InstructionSize());
534 code_event.function_name = isolate_->factory()->empty_string();
535 code_event.script_name = isolate_->factory()->empty_string();
536 code_event.script_line = 0;
537 code_event.script_column = 0;
538 code_event.code_type = v8::CodeEventType::kRelocationType;
539 code_event.comment = "";
540
541 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
542 }
543
544 // Low-level logging support.
545 class LowLevelLogger : public CodeEventLogger {
546 public:
547 LowLevelLogger(Isolate* isolate, const char* file_name);
548 ~LowLevelLogger() override;
549
550 void CodeMoveEvent(AbstractCode from, AbstractCode to) override;
CodeDisableOptEvent(Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared)551 void CodeDisableOptEvent(Handle<AbstractCode> code,
552 Handle<SharedFunctionInfo> shared) override {}
553 void SnapshotPositionEvent(HeapObject obj, int pos);
554 void CodeMovingGCEvent() override;
555
556 private:
557 void LogRecordedBuffer(Handle<AbstractCode> code,
558 MaybeHandle<SharedFunctionInfo> maybe_shared,
559 const char* name, int length) override;
560 #if V8_ENABLE_WEBASSEMBLY
561 void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
562 int length) override;
563 #endif // V8_ENABLE_WEBASSEMBLY
564
565 // Low-level profiling event structures.
566 struct CodeCreateStruct {
567 static const char kTag = 'C';
568
569 int32_t name_size;
570 Address code_address;
571 int32_t code_size;
572 };
573
574 struct CodeMoveStruct {
575 static const char kTag = 'M';
576
577 Address from_address;
578 Address to_address;
579 };
580
581 static const char kCodeMovingGCTag = 'G';
582
583 // Extension added to V8 log file name to get the low-level log name.
584 static const char kLogExt[];
585
586 void LogCodeInfo();
587 void LogWriteBytes(const char* bytes, int size);
588
589 template <typename T>
LogWriteStruct(const T & s)590 void LogWriteStruct(const T& s) {
591 char tag = T::kTag;
592 LogWriteBytes(reinterpret_cast<const char*>(&tag), sizeof(tag));
593 LogWriteBytes(reinterpret_cast<const char*>(&s), sizeof(s));
594 }
595
596 FILE* ll_output_handle_;
597 };
598
599 const char LowLevelLogger::kLogExt[] = ".ll";
600
LowLevelLogger(Isolate * isolate,const char * name)601 LowLevelLogger::LowLevelLogger(Isolate* isolate, const char* name)
602 : CodeEventLogger(isolate), ll_output_handle_(nullptr) {
603 // Open the low-level log file.
604 size_t len = strlen(name);
605 base::ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLogExt)));
606 MemCopy(ll_name.begin(), name, len);
607 MemCopy(ll_name.begin() + len, kLogExt, sizeof(kLogExt));
608 ll_output_handle_ =
609 base::OS::FOpen(ll_name.begin(), base::OS::LogFileOpenMode);
610 setvbuf(ll_output_handle_, nullptr, _IOLBF, 0);
611
612 LogCodeInfo();
613 }
614
~LowLevelLogger()615 LowLevelLogger::~LowLevelLogger() {
616 base::Fclose(ll_output_handle_);
617 ll_output_handle_ = nullptr;
618 }
619
LogCodeInfo()620 void LowLevelLogger::LogCodeInfo() {
621 #if V8_TARGET_ARCH_IA32
622 const char arch[] = "ia32";
623 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_64_BIT
624 const char arch[] = "x64";
625 #elif V8_TARGET_ARCH_ARM
626 const char arch[] = "arm";
627 #elif V8_TARGET_ARCH_PPC
628 const char arch[] = "ppc";
629 #elif V8_TARGET_ARCH_PPC64
630 const char arch[] = "ppc64";
631 #elif V8_TARGET_ARCH_MIPS
632 const char arch[] = "mips";
633 #elif V8_TARGET_ARCH_LOONG64
634 const char arch[] = "loong64";
635 #elif V8_TARGET_ARCH_ARM64
636 const char arch[] = "arm64";
637 #elif V8_TARGET_ARCH_S390
638 const char arch[] = "s390";
639 #elif V8_TARGET_ARCH_RISCV64
640 const char arch[] = "riscv64";
641 #else
642 const char arch[] = "unknown";
643 #endif
644 LogWriteBytes(arch, sizeof(arch));
645 }
646
LogRecordedBuffer(Handle<AbstractCode> code,MaybeHandle<SharedFunctionInfo>,const char * name,int length)647 void LowLevelLogger::LogRecordedBuffer(Handle<AbstractCode> code,
648 MaybeHandle<SharedFunctionInfo>,
649 const char* name, int length) {
650 CodeCreateStruct event;
651 event.name_size = length;
652 event.code_address = code->InstructionStart();
653 event.code_size = code->InstructionSize();
654 LogWriteStruct(event);
655 LogWriteBytes(name, length);
656 LogWriteBytes(reinterpret_cast<const char*>(code->InstructionStart()),
657 code->InstructionSize());
658 }
659
660 #if V8_ENABLE_WEBASSEMBLY
LogRecordedBuffer(const wasm::WasmCode * code,const char * name,int length)661 void LowLevelLogger::LogRecordedBuffer(const wasm::WasmCode* code,
662 const char* name, int length) {
663 CodeCreateStruct event;
664 event.name_size = length;
665 event.code_address = code->instruction_start();
666 event.code_size = code->instructions().length();
667 LogWriteStruct(event);
668 LogWriteBytes(name, length);
669 LogWriteBytes(reinterpret_cast<const char*>(code->instruction_start()),
670 code->instructions().length());
671 }
672 #endif // V8_ENABLE_WEBASSEMBLY
673
CodeMoveEvent(AbstractCode from,AbstractCode to)674 void LowLevelLogger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
675 CodeMoveStruct event;
676 event.from_address = from.InstructionStart();
677 event.to_address = to.InstructionStart();
678 LogWriteStruct(event);
679 }
680
LogWriteBytes(const char * bytes,int size)681 void LowLevelLogger::LogWriteBytes(const char* bytes, int size) {
682 size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
683 DCHECK(static_cast<size_t>(size) == rv);
684 USE(rv);
685 }
686
CodeMovingGCEvent()687 void LowLevelLogger::CodeMovingGCEvent() {
688 const char tag = kCodeMovingGCTag;
689
690 LogWriteBytes(&tag, sizeof(tag));
691 }
692
693 class JitLogger : public CodeEventLogger {
694 public:
695 JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler);
696
697 void CodeMoveEvent(AbstractCode from, AbstractCode to) override;
CodeDisableOptEvent(Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared)698 void CodeDisableOptEvent(Handle<AbstractCode> code,
699 Handle<SharedFunctionInfo> shared) override {}
700 void AddCodeLinePosInfoEvent(void* jit_handler_data, int pc_offset,
701 int position,
702 JitCodeEvent::PositionType position_type,
703 JitCodeEvent::CodeType code_type);
704
705 void* StartCodePosInfoEvent(JitCodeEvent::CodeType code_type);
706 void EndCodePosInfoEvent(Address start_address, void* jit_handler_data,
707 JitCodeEvent::CodeType code_type);
708
709 private:
710 void LogRecordedBuffer(Handle<AbstractCode> code,
711 MaybeHandle<SharedFunctionInfo> maybe_shared,
712 const char* name, int length) override;
713 #if V8_ENABLE_WEBASSEMBLY
714 void LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
715 int length) override;
716 #endif // V8_ENABLE_WEBASSEMBLY
717
718 JitCodeEventHandler code_event_handler_;
719 base::Mutex logger_mutex_;
720 };
721
JitLogger(Isolate * isolate,JitCodeEventHandler code_event_handler)722 JitLogger::JitLogger(Isolate* isolate, JitCodeEventHandler code_event_handler)
723 : CodeEventLogger(isolate), code_event_handler_(code_event_handler) {}
724
LogRecordedBuffer(Handle<AbstractCode> code,MaybeHandle<SharedFunctionInfo> maybe_shared,const char * name,int length)725 void JitLogger::LogRecordedBuffer(Handle<AbstractCode> code,
726 MaybeHandle<SharedFunctionInfo> maybe_shared,
727 const char* name, int length) {
728 JitCodeEvent event = {};
729 event.type = JitCodeEvent::CODE_ADDED;
730 event.code_start = reinterpret_cast<void*>(code->InstructionStart());
731 event.code_type =
732 code->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
733 event.code_len = code->InstructionSize();
734 Handle<SharedFunctionInfo> shared;
735 if (maybe_shared.ToHandle(&shared) && shared->script().IsScript()) {
736 event.script = ToApiHandle<v8::UnboundScript>(shared);
737 } else {
738 event.script = Local<v8::UnboundScript>();
739 }
740 event.name.str = name;
741 event.name.len = length;
742 event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
743 code_event_handler_(&event);
744 }
745
746 #if V8_ENABLE_WEBASSEMBLY
LogRecordedBuffer(const wasm::WasmCode * code,const char * name,int length)747 void JitLogger::LogRecordedBuffer(const wasm::WasmCode* code, const char* name,
748 int length) {
749 JitCodeEvent event = {};
750 event.type = JitCodeEvent::CODE_ADDED;
751 event.code_type = JitCodeEvent::WASM_CODE;
752 event.code_start = code->instructions().begin();
753 event.code_len = code->instructions().length();
754 event.name.str = name;
755 event.name.len = length;
756 event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
757
758 wasm::WasmModuleSourceMap* source_map =
759 code->native_module()->GetWasmSourceMap();
760 wasm::WireBytesRef code_ref =
761 code->native_module()->module()->functions[code->index()].code;
762 uint32_t code_offset = code_ref.offset();
763 uint32_t code_end_offset = code_ref.end_offset();
764
765 std::vector<v8::JitCodeEvent::line_info_t> mapping_info;
766 std::string filename;
767 std::unique_ptr<JitCodeEvent::wasm_source_info_t> wasm_source_info;
768
769 if (source_map && source_map->IsValid() &&
770 source_map->HasSource(code_offset, code_end_offset)) {
771 size_t last_line_number = 0;
772
773 for (SourcePositionTableIterator iterator(code->source_positions());
774 !iterator.done(); iterator.Advance()) {
775 uint32_t offset = iterator.source_position().ScriptOffset() + code_offset;
776 if (!source_map->HasValidEntry(code_offset, offset)) continue;
777 if (filename.empty()) {
778 filename = source_map->GetFilename(offset);
779 }
780 mapping_info.push_back({static_cast<size_t>(iterator.code_offset()),
781 last_line_number, JitCodeEvent::POSITION});
782 last_line_number = source_map->GetSourceLine(offset) + 1;
783 }
784
785 wasm_source_info = std::make_unique<JitCodeEvent::wasm_source_info_t>();
786 wasm_source_info->filename = filename.c_str();
787 wasm_source_info->filename_size = filename.size();
788 wasm_source_info->line_number_table_size = mapping_info.size();
789 wasm_source_info->line_number_table = mapping_info.data();
790
791 event.wasm_source_info = wasm_source_info.get();
792 }
793 code_event_handler_(&event);
794 }
795 #endif // V8_ENABLE_WEBASSEMBLY
796
CodeMoveEvent(AbstractCode from,AbstractCode to)797 void JitLogger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
798 base::MutexGuard guard(&logger_mutex_);
799
800 JitCodeEvent event;
801 event.type = JitCodeEvent::CODE_MOVED;
802 event.code_type =
803 from.IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
804 event.code_start = reinterpret_cast<void*>(from.InstructionStart());
805 event.code_len = from.InstructionSize();
806 event.new_code_start = reinterpret_cast<void*>(to.InstructionStart());
807 event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
808
809 code_event_handler_(&event);
810 }
811
AddCodeLinePosInfoEvent(void * jit_handler_data,int pc_offset,int position,JitCodeEvent::PositionType position_type,JitCodeEvent::CodeType code_type)812 void JitLogger::AddCodeLinePosInfoEvent(
813 void* jit_handler_data, int pc_offset, int position,
814 JitCodeEvent::PositionType position_type,
815 JitCodeEvent::CodeType code_type) {
816 JitCodeEvent event = {};
817 event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
818 event.code_type = code_type;
819 event.user_data = jit_handler_data;
820 event.line_info.offset = pc_offset;
821 event.line_info.pos = position;
822 event.line_info.position_type = position_type;
823 event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
824
825 code_event_handler_(&event);
826 }
827
StartCodePosInfoEvent(JitCodeEvent::CodeType code_type)828 void* JitLogger::StartCodePosInfoEvent(JitCodeEvent::CodeType code_type) {
829 JitCodeEvent event = {};
830 event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
831 event.code_type = code_type;
832 event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
833
834 code_event_handler_(&event);
835 return event.user_data;
836 }
837
EndCodePosInfoEvent(Address start_address,void * jit_handler_data,JitCodeEvent::CodeType code_type)838 void JitLogger::EndCodePosInfoEvent(Address start_address,
839 void* jit_handler_data,
840 JitCodeEvent::CodeType code_type) {
841 JitCodeEvent event = {};
842 event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
843 event.code_type = code_type;
844 event.code_start = reinterpret_cast<void*>(start_address);
845 event.user_data = jit_handler_data;
846 event.isolate = reinterpret_cast<v8::Isolate*>(isolate_);
847
848 code_event_handler_(&event);
849 }
850
851 // TODO(lpy): Keeping sampling thread inside V8 is a workaround currently,
852 // the reason is to reduce code duplication during migration to sampler library,
853 // sampling thread, as well as the sampler, will be moved to D8 eventually.
854 class SamplingThread : public base::Thread {
855 public:
856 static const int kSamplingThreadStackSize = 64 * KB;
857
SamplingThread(sampler::Sampler * sampler,int interval_microseconds)858 SamplingThread(sampler::Sampler* sampler, int interval_microseconds)
859 : base::Thread(
860 base::Thread::Options("SamplingThread", kSamplingThreadStackSize)),
861 sampler_(sampler),
862 interval_microseconds_(interval_microseconds) {}
Run()863 void Run() override {
864 while (sampler_->IsActive()) {
865 sampler_->DoSample();
866 base::OS::Sleep(
867 base::TimeDelta::FromMicroseconds(interval_microseconds_));
868 }
869 }
870
871 private:
872 sampler::Sampler* sampler_;
873 const int interval_microseconds_;
874 };
875
876 // The Profiler samples pc and sp values for the main thread.
877 // Each sample is appended to a circular buffer.
878 // An independent thread removes data and writes it to the log.
879 // This design minimizes the time spent in the sampler.
880 //
881 class Profiler : public base::Thread {
882 public:
883 explicit Profiler(Isolate* isolate);
884 void Engage();
885 void Disengage();
886
887 // Inserts collected profiling data into buffer.
Insert(TickSample * sample)888 void Insert(TickSample* sample) {
889 if (Succ(head_) == static_cast<int>(base::Relaxed_Load(&tail_))) {
890 overflow_ = true;
891 } else {
892 buffer_[head_] = *sample;
893 head_ = Succ(head_);
894 buffer_semaphore_.Signal(); // Tell we have an element.
895 }
896 }
897
898 void Run() override;
899
900 private:
901 // Waits for a signal and removes profiling data.
Remove(TickSample * sample)902 bool Remove(TickSample* sample) {
903 buffer_semaphore_.Wait(); // Wait for an element.
904 *sample = buffer_[base::Relaxed_Load(&tail_)];
905 bool result = overflow_;
906 base::Relaxed_Store(
907 &tail_, static_cast<base::Atomic32>(Succ(base::Relaxed_Load(&tail_))));
908 overflow_ = false;
909 return result;
910 }
911
912 // Returns the next index in the cyclic buffer.
Succ(int index)913 int Succ(int index) { return (index + 1) % kBufferSize; }
914
915 Isolate* isolate_;
916 // Cyclic buffer for communicating profiling samples
917 // between the signal handler and the worker thread.
918 static const int kBufferSize = 128;
919 TickSample buffer_[kBufferSize]; // Buffer storage.
920 int head_; // Index to the buffer head.
921 base::Atomic32 tail_; // Index to the buffer tail.
922 bool overflow_; // Tell whether a buffer overflow has occurred.
923 // Semaphore used for buffer synchronization.
924 base::Semaphore buffer_semaphore_;
925
926 // Tells whether worker thread should continue running.
927 base::Atomic32 running_;
928 };
929
930 //
931 // Ticker used to provide ticks to the profiler and the sliding state
932 // window.
933 //
934 class Ticker : public sampler::Sampler {
935 public:
Ticker(Isolate * isolate,int interval_microseconds)936 Ticker(Isolate* isolate, int interval_microseconds)
937 : sampler::Sampler(reinterpret_cast<v8::Isolate*>(isolate)),
938 sampling_thread_(
939 std::make_unique<SamplingThread>(this, interval_microseconds)),
940 perThreadData_(isolate->FindPerThreadDataForThisThread()) {}
941
~Ticker()942 ~Ticker() override {
943 if (IsActive()) Stop();
944 }
945
SetProfiler(Profiler * profiler)946 void SetProfiler(Profiler* profiler) {
947 DCHECK_NULL(profiler_);
948 profiler_ = profiler;
949 if (!IsActive()) Start();
950 sampling_thread_->StartSynchronously();
951 }
952
ClearProfiler()953 void ClearProfiler() {
954 profiler_ = nullptr;
955 if (IsActive()) Stop();
956 sampling_thread_->Join();
957 }
958
SampleStack(const v8::RegisterState & state)959 void SampleStack(const v8::RegisterState& state) override {
960 if (!profiler_) return;
961 Isolate* isolate = reinterpret_cast<Isolate*>(this->isolate());
962 if (isolate->was_locker_ever_used() &&
963 (!isolate->thread_manager()->IsLockedByThread(
964 perThreadData_->thread_id()) ||
965 perThreadData_->thread_state() != nullptr))
966 return;
967 TickSample sample;
968 sample.Init(isolate, state, TickSample::kIncludeCEntryFrame, true);
969 profiler_->Insert(&sample);
970 }
971
972 private:
973 Profiler* profiler_ = nullptr;
974 std::unique_ptr<SamplingThread> sampling_thread_;
975 Isolate::PerIsolateThreadData* perThreadData_;
976 };
977
978 //
979 // Profiler implementation when invoking with --prof.
980 //
Profiler(Isolate * isolate)981 Profiler::Profiler(Isolate* isolate)
982 : base::Thread(Options("v8:Profiler")),
983 isolate_(isolate),
984 head_(0),
985 overflow_(false),
986 buffer_semaphore_(0) {
987 base::Relaxed_Store(&tail_, 0);
988 base::Relaxed_Store(&running_, 0);
989 }
990
Engage()991 void Profiler::Engage() {
992 std::vector<base::OS::SharedLibraryAddress> addresses =
993 base::OS::GetSharedLibraryAddresses();
994 for (const auto& address : addresses) {
995 LOG(isolate_, SharedLibraryEvent(address.library_path, address.start,
996 address.end, address.aslr_slide));
997 }
998 LOG(isolate_, SharedLibraryEnd());
999
1000 // Start thread processing the profiler buffer.
1001 base::Relaxed_Store(&running_, 1);
1002 CHECK(Start());
1003
1004 // Register to get ticks.
1005 Logger* logger = isolate_->logger();
1006 logger->ticker_->SetProfiler(this);
1007
1008 LOG(isolate_, ProfilerBeginEvent());
1009 }
1010
Disengage()1011 void Profiler::Disengage() {
1012 // Stop receiving ticks.
1013 isolate_->logger()->ticker_->ClearProfiler();
1014
1015 // Terminate the worker thread by setting running_ to false,
1016 // inserting a fake element in the queue and then wait for
1017 // the thread to terminate.
1018 base::Relaxed_Store(&running_, 0);
1019 TickSample sample;
1020 Insert(&sample);
1021 Join();
1022
1023 LOG(isolate_, UncheckedStringEvent("profiler", "end"));
1024 }
1025
Run()1026 void Profiler::Run() {
1027 TickSample sample;
1028 bool overflow = Remove(&sample);
1029 while (base::Relaxed_Load(&running_)) {
1030 LOG(isolate_, TickEvent(&sample, overflow));
1031 overflow = Remove(&sample);
1032 }
1033 }
1034
1035 //
1036 // Logger class implementation.
1037 //
1038 #define MSG_BUILDER() \
1039 std::unique_ptr<Log::MessageBuilder> msg_ptr = log_->NewMessageBuilder(); \
1040 if (!msg_ptr) return; \
1041 Log::MessageBuilder& msg = *msg_ptr.get();
1042
Logger(Isolate * isolate)1043 Logger::Logger(Isolate* isolate)
1044 : isolate_(isolate),
1045 is_logging_(false),
1046 is_initialized_(false),
1047 existing_code_logger_(isolate) {}
1048
1049 Logger::~Logger() = default;
1050
1051 const LogSeparator Logger::kNext = LogSeparator::kSeparator;
1052
Time()1053 int64_t Logger::Time() {
1054 if (FLAG_verify_predictable) {
1055 return isolate_->heap()->MonotonicallyIncreasingTimeInMs() * 1000;
1056 }
1057 return timer_.Elapsed().InMicroseconds();
1058 }
1059
AddCodeEventListener(CodeEventListener * listener)1060 void Logger::AddCodeEventListener(CodeEventListener* listener) {
1061 bool result = isolate_->code_event_dispatcher()->AddListener(listener);
1062 CHECK(result);
1063 }
1064
RemoveCodeEventListener(CodeEventListener * listener)1065 void Logger::RemoveCodeEventListener(CodeEventListener* listener) {
1066 isolate_->code_event_dispatcher()->RemoveListener(listener);
1067 }
1068
ProfilerBeginEvent()1069 void Logger::ProfilerBeginEvent() {
1070 MSG_BUILDER();
1071 msg << "profiler" << kNext << "begin" << kNext << FLAG_prof_sampling_interval;
1072 msg.WriteToLogFile();
1073 }
1074
StringEvent(const char * name,const char * value)1075 void Logger::StringEvent(const char* name, const char* value) {
1076 if (FLAG_log) UncheckedStringEvent(name, value);
1077 }
1078
UncheckedStringEvent(const char * name,const char * value)1079 void Logger::UncheckedStringEvent(const char* name, const char* value) {
1080 MSG_BUILDER();
1081 msg << name << kNext << value;
1082 msg.WriteToLogFile();
1083 }
1084
IntPtrTEvent(const char * name,intptr_t value)1085 void Logger::IntPtrTEvent(const char* name, intptr_t value) {
1086 if (!FLAG_log) return;
1087 MSG_BUILDER();
1088 msg << name << kNext;
1089 msg.AppendFormatString("%" V8PRIdPTR, value);
1090 msg.WriteToLogFile();
1091 }
1092
SharedLibraryEvent(const std::string & library_path,uintptr_t start,uintptr_t end,intptr_t aslr_slide)1093 void Logger::SharedLibraryEvent(const std::string& library_path,
1094 uintptr_t start, uintptr_t end,
1095 intptr_t aslr_slide) {
1096 if (!FLAG_prof_cpp) return;
1097 MSG_BUILDER();
1098 msg << "shared-library" << kNext << library_path.c_str() << kNext
1099 << reinterpret_cast<void*>(start) << kNext << reinterpret_cast<void*>(end)
1100 << kNext << aslr_slide;
1101 msg.WriteToLogFile();
1102 }
1103
SharedLibraryEnd()1104 void Logger::SharedLibraryEnd() {
1105 if (!FLAG_prof_cpp) return;
1106 MSG_BUILDER();
1107 msg << "shared-library-end";
1108 msg.WriteToLogFile();
1109 }
1110
CurrentTimeEvent()1111 void Logger::CurrentTimeEvent() {
1112 DCHECK(FLAG_log_internal_timer_events);
1113 MSG_BUILDER();
1114 msg << "current-time" << kNext << Time();
1115 msg.WriteToLogFile();
1116 }
1117
TimerEvent(v8::LogEventStatus se,const char * name)1118 void Logger::TimerEvent(v8::LogEventStatus se, const char* name) {
1119 MSG_BUILDER();
1120 switch (se) {
1121 case kStart:
1122 msg << "timer-event-start";
1123 break;
1124 case kEnd:
1125 msg << "timer-event-end";
1126 break;
1127 case kStamp:
1128 msg << "timer-event";
1129 }
1130 msg << kNext << name << kNext << Time();
1131 msg.WriteToLogFile();
1132 }
1133
BasicBlockCounterEvent(const char * name,int block_id,uint32_t count)1134 void Logger::BasicBlockCounterEvent(const char* name, int block_id,
1135 uint32_t count) {
1136 if (!FLAG_turbo_profiling_log_builtins) return;
1137 MSG_BUILDER();
1138 msg << ProfileDataFromFileConstants::kBlockCounterMarker << kNext << name
1139 << kNext << block_id << kNext << count;
1140 msg.WriteToLogFile();
1141 }
1142
BuiltinHashEvent(const char * name,int hash)1143 void Logger::BuiltinHashEvent(const char* name, int hash) {
1144 if (!FLAG_turbo_profiling_log_builtins) return;
1145 MSG_BUILDER();
1146 msg << ProfileDataFromFileConstants::kBuiltinHashMarker << kNext << name
1147 << kNext << hash;
1148 msg.WriteToLogFile();
1149 }
1150
is_logging()1151 bool Logger::is_logging() {
1152 // Disable logging while the CPU profiler is running.
1153 if (isolate_->is_profiling()) return false;
1154 return is_logging_.load(std::memory_order_relaxed);
1155 }
1156
1157 // Instantiate template methods.
1158 #define V(TimerName, expose) \
1159 template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \
1160 v8::LogEventStatus se);
TIMER_EVENTS_LIST(V)1161 TIMER_EVENTS_LIST(V)
1162 #undef V
1163
1164 void Logger::NewEvent(const char* name, void* object, size_t size) {
1165 if (!FLAG_log) return;
1166 MSG_BUILDER();
1167 msg << "new" << kNext << name << kNext << object << kNext
1168 << static_cast<unsigned int>(size);
1169 msg.WriteToLogFile();
1170 }
1171
DeleteEvent(const char * name,void * object)1172 void Logger::DeleteEvent(const char* name, void* object) {
1173 if (!FLAG_log) return;
1174 MSG_BUILDER();
1175 msg << "delete" << kNext << name << kNext << object;
1176 msg.WriteToLogFile();
1177 }
1178
1179 namespace {
1180
AppendCodeCreateHeader(Log::MessageBuilder & msg,CodeEventListener::LogEventsAndTags tag,CodeKind kind,uint8_t * address,int size,uint64_t time)1181 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
1182 CodeEventListener::LogEventsAndTags tag,
1183 CodeKind kind, uint8_t* address, int size,
1184 uint64_t time) {
1185 msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT]
1186 << Logger::kNext << kLogEventsNames[tag] << Logger::kNext
1187 << static_cast<int>(kind) << Logger::kNext << time << Logger::kNext
1188 << reinterpret_cast<void*>(address) << Logger::kNext << size
1189 << Logger::kNext;
1190 }
1191
AppendCodeCreateHeader(Log::MessageBuilder & msg,CodeEventListener::LogEventsAndTags tag,AbstractCode code,uint64_t time)1192 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
1193 CodeEventListener::LogEventsAndTags tag,
1194 AbstractCode code, uint64_t time) {
1195 AppendCodeCreateHeader(msg, tag, code.kind(),
1196 reinterpret_cast<uint8_t*>(code.InstructionStart()),
1197 code.InstructionSize(), time);
1198 }
1199
1200 } // namespace
1201 // We log source code information in the form:
1202 //
1203 // code-source-info <addr>,<script>,<start>,<end>,<pos>,<inline-pos>,<fns>
1204 //
1205 // where
1206 // <addr> is code object address
1207 // <script> is script id
1208 // <start> is the starting position inside the script
1209 // <end> is the end position inside the script
1210 // <pos> is source position table encoded in the string,
1211 // it is a sequence of C<code-offset>O<script-offset>[I<inlining-id>]
1212 // where
1213 // <code-offset> is the offset within the code object
1214 // <script-offset> is the position within the script
1215 // <inlining-id> is the offset in the <inlining> table
1216 // <inlining> table is a sequence of strings of the form
1217 // F<function-id>O<script-offset>[I<inlining-id>]
1218 // where
1219 // <function-id> is an index into the <fns> function table
1220 // <fns> is the function table encoded as a sequence of strings
1221 // S<shared-function-info-address>
1222
LogSourceCodeInformation(Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared)1223 void Logger::LogSourceCodeInformation(Handle<AbstractCode> code,
1224 Handle<SharedFunctionInfo> shared) {
1225 Object script_object = shared->script();
1226 if (!script_object.IsScript()) return;
1227 Script script = Script::cast(script_object);
1228 EnsureLogScriptSource(script);
1229
1230 MSG_BUILDER();
1231 msg << "code-source-info" << Logger::kNext
1232 << reinterpret_cast<void*>(code->InstructionStart()) << Logger::kNext
1233 << script.id() << Logger::kNext << shared->StartPosition()
1234 << Logger::kNext << shared->EndPosition() << Logger::kNext;
1235 // TODO(v8:11429): Clean-up baseline-replated code in source position
1236 // iteration.
1237 bool hasInlined = false;
1238 if (code->kind() != CodeKind::BASELINE) {
1239 SourcePositionTableIterator iterator(code->SourcePositionTable(*shared));
1240 for (; !iterator.done(); iterator.Advance()) {
1241 SourcePosition pos = iterator.source_position();
1242 msg << "C" << iterator.code_offset() << "O" << pos.ScriptOffset();
1243 if (pos.isInlined()) {
1244 msg << "I" << pos.InliningId();
1245 hasInlined = true;
1246 }
1247 }
1248 }
1249 msg << Logger::kNext;
1250 int maxInlinedId = -1;
1251 if (hasInlined) {
1252 PodArray<InliningPosition> inlining_positions =
1253 DeoptimizationData::cast(
1254 Handle<Code>::cast(code)->deoptimization_data())
1255 .InliningPositions();
1256 for (int i = 0; i < inlining_positions.length(); i++) {
1257 InliningPosition inlining_pos = inlining_positions.get(i);
1258 msg << "F";
1259 if (inlining_pos.inlined_function_id != -1) {
1260 msg << inlining_pos.inlined_function_id;
1261 if (inlining_pos.inlined_function_id > maxInlinedId) {
1262 maxInlinedId = inlining_pos.inlined_function_id;
1263 }
1264 }
1265 SourcePosition pos = inlining_pos.position;
1266 msg << "O" << pos.ScriptOffset();
1267 if (pos.isInlined()) {
1268 msg << "I" << pos.InliningId();
1269 }
1270 }
1271 }
1272 msg << Logger::kNext;
1273 if (hasInlined) {
1274 DeoptimizationData deopt_data = DeoptimizationData::cast(
1275 Handle<Code>::cast(code)->deoptimization_data());
1276 msg << std::hex;
1277 for (int i = 0; i <= maxInlinedId; i++) {
1278 msg << "S"
1279 << reinterpret_cast<void*>(
1280 deopt_data.GetInlinedFunction(i).address());
1281 }
1282 msg << std::dec;
1283 }
1284 msg.WriteToLogFile();
1285 }
1286
LogCodeDisassemble(Handle<AbstractCode> code)1287 void Logger::LogCodeDisassemble(Handle<AbstractCode> code) {
1288 if (!FLAG_log_code_disassemble) return;
1289 MSG_BUILDER();
1290 msg << "code-disassemble" << Logger::kNext
1291 << reinterpret_cast<void*>(code->InstructionStart()) << Logger::kNext
1292 << CodeKindToString(code->kind()) << Logger::kNext;
1293 {
1294 std::ostringstream stream;
1295 if (code->IsCode()) {
1296 #ifdef ENABLE_DISASSEMBLER
1297 Code::cast(*code).Disassemble(nullptr, stream, isolate_);
1298 #endif
1299 } else {
1300 BytecodeArray::cast(*code).Disassemble(stream);
1301 }
1302 std::string string = stream.str();
1303 msg.AppendString(string.c_str(), string.length());
1304 }
1305 msg.WriteToLogFile();
1306 }
1307
1308 // Builtins and Bytecode handlers
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,const char * name)1309 void Logger::CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
1310 const char* name) {
1311 if (!is_listening_to_code_events()) return;
1312 if (!FLAG_log_code) return;
1313 {
1314 MSG_BUILDER();
1315 AppendCodeCreateHeader(msg, tag, *code, Time());
1316 msg << name;
1317 msg.WriteToLogFile();
1318 }
1319 LogCodeDisassemble(code);
1320 }
1321
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<Name> name)1322 void Logger::CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
1323 Handle<Name> name) {
1324 if (!is_listening_to_code_events()) return;
1325 if (!FLAG_log_code) return;
1326 {
1327 MSG_BUILDER();
1328 AppendCodeCreateHeader(msg, tag, *code, Time());
1329 msg << *name;
1330 msg.WriteToLogFile();
1331 }
1332 LogCodeDisassemble(code);
1333 }
1334
1335 // Scripts
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared,Handle<Name> script_name)1336 void Logger::CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
1337 Handle<SharedFunctionInfo> shared,
1338 Handle<Name> script_name) {
1339 if (!is_listening_to_code_events()) return;
1340 if (!FLAG_log_code) return;
1341 if (*code ==
1342 AbstractCode::cast(isolate_->builtins()->code(Builtin::kCompileLazy))) {
1343 return;
1344 }
1345 {
1346 MSG_BUILDER();
1347 AppendCodeCreateHeader(msg, tag, *code, Time());
1348 msg << *script_name << kNext << reinterpret_cast<void*>(shared->address())
1349 << kNext << ComputeMarker(*shared, *code);
1350 msg.WriteToLogFile();
1351 }
1352 LogSourceCodeInformation(code, shared);
1353 LogCodeDisassemble(code);
1354 }
1355
FeedbackVectorEvent(FeedbackVector vector,AbstractCode code)1356 void Logger::FeedbackVectorEvent(FeedbackVector vector, AbstractCode code) {
1357 DisallowGarbageCollection no_gc;
1358 if (!FLAG_log_code) return;
1359 MSG_BUILDER();
1360 msg << "feedback-vector" << kNext << Time();
1361 msg << kNext << reinterpret_cast<void*>(vector.address()) << kNext
1362 << vector.length();
1363 msg << kNext << reinterpret_cast<void*>(code.InstructionStart());
1364 msg << kNext << vector.tiering_state();
1365 msg << kNext << vector.maybe_has_optimized_code();
1366 msg << kNext << vector.invocation_count();
1367 msg << kNext << vector.profiler_ticks() << kNext;
1368
1369 #ifdef OBJECT_PRINT
1370 std::ostringstream buffer;
1371 vector.FeedbackVectorPrint(buffer);
1372 std::string contents = buffer.str();
1373 msg.AppendString(contents.c_str(), contents.length());
1374 #else
1375 msg << "object-printing-disabled";
1376 #endif
1377 msg.WriteToLogFile();
1378 }
1379
1380 // Functions
1381 // Although, it is possible to extract source and line from
1382 // the SharedFunctionInfo object, we left it to caller
1383 // to leave logging functions free from heap allocations.
CodeCreateEvent(LogEventsAndTags tag,Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared,Handle<Name> script_name,int line,int column)1384 void Logger::CodeCreateEvent(LogEventsAndTags tag, Handle<AbstractCode> code,
1385 Handle<SharedFunctionInfo> shared,
1386 Handle<Name> script_name, int line, int column) {
1387 if (!is_listening_to_code_events()) return;
1388 if (!FLAG_log_code) return;
1389 {
1390 MSG_BUILDER();
1391 AppendCodeCreateHeader(msg, tag, *code, Time());
1392 msg << shared->DebugNameCStr().get() << " " << *script_name << ":" << line
1393 << ":" << column << kNext << reinterpret_cast<void*>(shared->address())
1394 << kNext << ComputeMarker(*shared, *code);
1395
1396 msg.WriteToLogFile();
1397 }
1398 LogSourceCodeInformation(code, shared);
1399 LogCodeDisassemble(code);
1400 }
1401
1402 #if V8_ENABLE_WEBASSEMBLY
CodeCreateEvent(LogEventsAndTags tag,const wasm::WasmCode * code,wasm::WasmName name,const char *,int,int)1403 void Logger::CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
1404 wasm::WasmName name, const char* /*source_url*/,
1405 int /*code_offset*/, int /*script_id*/) {
1406 if (!is_listening_to_code_events()) return;
1407 if (!FLAG_log_code) return;
1408 MSG_BUILDER();
1409 AppendCodeCreateHeader(msg, tag, CodeKind::WASM_FUNCTION,
1410 code->instructions().begin(),
1411 code->instructions().length(), Time());
1412 DCHECK(!name.empty());
1413 msg.AppendString(name);
1414
1415 // We have to add two extra fields that allow the tick processor to group
1416 // events for the same wasm function, even if it gets compiled again. For
1417 // normal JS functions, we use the shared function info. For wasm, the pointer
1418 // to the native module + function index works well enough.
1419 // TODO(herhut) Clean up the tick processor code instead.
1420 void* tag_ptr =
1421 reinterpret_cast<byte*>(code->native_module()) + code->index();
1422 msg << kNext << tag_ptr << kNext << ComputeMarker(code);
1423 msg.WriteToLogFile();
1424 }
1425 #endif // V8_ENABLE_WEBASSEMBLY
1426
CallbackEventInternal(const char * prefix,Handle<Name> name,Address entry_point)1427 void Logger::CallbackEventInternal(const char* prefix, Handle<Name> name,
1428 Address entry_point) {
1429 if (!FLAG_log_code) return;
1430 MSG_BUILDER();
1431 msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT] << kNext
1432 << kLogEventsNames[CodeEventListener::CALLBACK_TAG] << kNext << -2
1433 << kNext << Time() << kNext << reinterpret_cast<void*>(entry_point)
1434 << kNext << 1 << kNext << prefix << *name;
1435 msg.WriteToLogFile();
1436 }
1437
CallbackEvent(Handle<Name> name,Address entry_point)1438 void Logger::CallbackEvent(Handle<Name> name, Address entry_point) {
1439 CallbackEventInternal("", name, entry_point);
1440 }
1441
GetterCallbackEvent(Handle<Name> name,Address entry_point)1442 void Logger::GetterCallbackEvent(Handle<Name> name, Address entry_point) {
1443 CallbackEventInternal("get ", name, entry_point);
1444 }
1445
SetterCallbackEvent(Handle<Name> name,Address entry_point)1446 void Logger::SetterCallbackEvent(Handle<Name> name, Address entry_point) {
1447 CallbackEventInternal("set ", name, entry_point);
1448 }
1449
RegExpCodeCreateEvent(Handle<AbstractCode> code,Handle<String> source)1450 void Logger::RegExpCodeCreateEvent(Handle<AbstractCode> code,
1451 Handle<String> source) {
1452 if (!is_listening_to_code_events()) return;
1453 if (!FLAG_log_code) return;
1454 MSG_BUILDER();
1455 AppendCodeCreateHeader(msg, CodeEventListener::REG_EXP_TAG, *code, Time());
1456 msg << *source;
1457 msg.WriteToLogFile();
1458 }
1459
CodeMoveEvent(AbstractCode from,AbstractCode to)1460 void Logger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
1461 if (!is_listening_to_code_events()) return;
1462 MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from.InstructionStart(),
1463 to.InstructionStart());
1464 }
1465
SharedFunctionInfoMoveEvent(Address from,Address to)1466 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
1467 if (!is_listening_to_code_events()) return;
1468 MoveEventInternal(CodeEventListener::SHARED_FUNC_MOVE_EVENT, from, to);
1469 }
1470
CodeMovingGCEvent()1471 void Logger::CodeMovingGCEvent() {
1472 if (!is_listening_to_code_events()) return;
1473 if (!FLAG_ll_prof) return;
1474 base::OS::SignalCodeMovingGC();
1475 }
1476
CodeDisableOptEvent(Handle<AbstractCode> code,Handle<SharedFunctionInfo> shared)1477 void Logger::CodeDisableOptEvent(Handle<AbstractCode> code,
1478 Handle<SharedFunctionInfo> shared) {
1479 if (!is_listening_to_code_events()) return;
1480 if (!FLAG_log_code) return;
1481 MSG_BUILDER();
1482 msg << kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT] << kNext
1483 << shared->DebugNameCStr().get() << kNext
1484 << GetBailoutReason(shared->disabled_optimization_reason());
1485 msg.WriteToLogFile();
1486 }
1487
ProcessDeoptEvent(Handle<Code> code,SourcePosition position,const char * kind,const char * reason)1488 void Logger::ProcessDeoptEvent(Handle<Code> code, SourcePosition position,
1489 const char* kind, const char* reason) {
1490 MSG_BUILDER();
1491 msg << "code-deopt" << kNext << Time() << kNext << code->CodeSize() << kNext
1492 << reinterpret_cast<void*>(code->InstructionStart());
1493
1494 std::ostringstream deopt_location;
1495 int inlining_id = -1;
1496 int script_offset = -1;
1497 if (position.IsKnown()) {
1498 position.Print(deopt_location, *code);
1499 inlining_id = position.InliningId();
1500 script_offset = position.ScriptOffset();
1501 } else {
1502 deopt_location << "<unknown>";
1503 }
1504 msg << kNext << inlining_id << kNext << script_offset << kNext;
1505 msg << kind << kNext;
1506 msg << deopt_location.str().c_str() << kNext << reason;
1507 msg.WriteToLogFile();
1508 }
1509
CodeDeoptEvent(Handle<Code> code,DeoptimizeKind kind,Address pc,int fp_to_sp_delta)1510 void Logger::CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
1511 int fp_to_sp_delta) {
1512 if (!is_logging() || !FLAG_log_deopt) return;
1513 Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(*code, pc);
1514 ProcessDeoptEvent(code, info.position, Deoptimizer::MessageFor(kind),
1515 DeoptimizeReasonToString(info.deopt_reason));
1516 }
1517
CodeDependencyChangeEvent(Handle<Code> code,Handle<SharedFunctionInfo> sfi,const char * reason)1518 void Logger::CodeDependencyChangeEvent(Handle<Code> code,
1519 Handle<SharedFunctionInfo> sfi,
1520 const char* reason) {
1521 if (!is_logging() || !FLAG_log_deopt) return;
1522 SourcePosition position(sfi->StartPosition(), -1);
1523 ProcessDeoptEvent(code, position, "dependency-change", reason);
1524 }
1525
1526 namespace {
1527
CodeLinePosEvent(JitLogger & jit_logger,Address code_start,SourcePositionTableIterator & iter,JitCodeEvent::CodeType code_type)1528 void CodeLinePosEvent(JitLogger& jit_logger, Address code_start,
1529 SourcePositionTableIterator& iter,
1530 JitCodeEvent::CodeType code_type) {
1531 void* jit_handler_data = jit_logger.StartCodePosInfoEvent(code_type);
1532 for (; !iter.done(); iter.Advance()) {
1533 if (iter.is_statement()) {
1534 jit_logger.AddCodeLinePosInfoEvent(jit_handler_data, iter.code_offset(),
1535 iter.source_position().ScriptOffset(),
1536 JitCodeEvent::STATEMENT_POSITION,
1537 code_type);
1538 }
1539 jit_logger.AddCodeLinePosInfoEvent(jit_handler_data, iter.code_offset(),
1540 iter.source_position().ScriptOffset(),
1541 JitCodeEvent::POSITION, code_type);
1542 }
1543 jit_logger.EndCodePosInfoEvent(code_start, jit_handler_data, code_type);
1544 }
1545
1546 } // namespace
1547
CodeLinePosInfoRecordEvent(Address code_start,ByteArray source_position_table,JitCodeEvent::CodeType code_type)1548 void Logger::CodeLinePosInfoRecordEvent(Address code_start,
1549 ByteArray source_position_table,
1550 JitCodeEvent::CodeType code_type) {
1551 if (!jit_logger_) return;
1552 SourcePositionTableIterator iter(source_position_table);
1553 CodeLinePosEvent(*jit_logger_, code_start, iter, code_type);
1554 }
1555
1556 #if V8_ENABLE_WEBASSEMBLY
WasmCodeLinePosInfoRecordEvent(Address code_start,base::Vector<const byte> source_position_table)1557 void Logger::WasmCodeLinePosInfoRecordEvent(
1558 Address code_start, base::Vector<const byte> source_position_table) {
1559 if (!jit_logger_) return;
1560 SourcePositionTableIterator iter(source_position_table);
1561 CodeLinePosEvent(*jit_logger_, code_start, iter, JitCodeEvent::WASM_CODE);
1562 }
1563 #endif // V8_ENABLE_WEBASSEMBLY
1564
CodeNameEvent(Address addr,int pos,const char * code_name)1565 void Logger::CodeNameEvent(Address addr, int pos, const char* code_name) {
1566 if (code_name == nullptr) return; // Not a code object.
1567 if (!is_listening_to_code_events()) return;
1568 MSG_BUILDER();
1569 msg << kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT] << kNext
1570 << pos << kNext << code_name;
1571 msg.WriteToLogFile();
1572 }
1573
MoveEventInternal(LogEventsAndTags event,Address from,Address to)1574 void Logger::MoveEventInternal(LogEventsAndTags event, Address from,
1575 Address to) {
1576 if (!FLAG_log_code) return;
1577 MSG_BUILDER();
1578 msg << kLogEventsNames[event] << kNext << reinterpret_cast<void*>(from)
1579 << kNext << reinterpret_cast<void*>(to);
1580 msg.WriteToLogFile();
1581 }
1582
1583 namespace {
AppendFunctionMessage(Log::MessageBuilder & msg,const char * reason,int script_id,double time_delta,int start_position,int end_position,uint64_t time)1584 void AppendFunctionMessage(Log::MessageBuilder& msg, const char* reason,
1585 int script_id, double time_delta, int start_position,
1586 int end_position, uint64_t time) {
1587 msg << "function" << Logger::kNext << reason << Logger::kNext << script_id
1588 << Logger::kNext << start_position << Logger::kNext << end_position
1589 << Logger::kNext;
1590 if (V8_UNLIKELY(FLAG_predictable)) {
1591 msg << 0.1;
1592 } else {
1593 msg << time_delta;
1594 }
1595 msg << Logger::kNext << time << Logger::kNext;
1596 }
1597 } // namespace
1598
FunctionEvent(const char * reason,int script_id,double time_delta,int start_position,int end_position,String function_name)1599 void Logger::FunctionEvent(const char* reason, int script_id, double time_delta,
1600 int start_position, int end_position,
1601 String function_name) {
1602 if (!FLAG_log_function_events) return;
1603 MSG_BUILDER();
1604 AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
1605 end_position, Time());
1606 if (!function_name.is_null()) msg << function_name;
1607 msg.WriteToLogFile();
1608 }
1609
FunctionEvent(const char * reason,int script_id,double time_delta,int start_position,int end_position,const char * function_name,size_t function_name_length,bool is_one_byte)1610 void Logger::FunctionEvent(const char* reason, int script_id, double time_delta,
1611 int start_position, int end_position,
1612 const char* function_name,
1613 size_t function_name_length, bool is_one_byte) {
1614 if (!FLAG_log_function_events) return;
1615 MSG_BUILDER();
1616 AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
1617 end_position, Time());
1618 if (function_name_length > 0) {
1619 msg.AppendString(function_name, function_name_length, is_one_byte);
1620 }
1621 msg.WriteToLogFile();
1622 }
1623
CompilationCacheEvent(const char * action,const char * cache_type,SharedFunctionInfo sfi)1624 void Logger::CompilationCacheEvent(const char* action, const char* cache_type,
1625 SharedFunctionInfo sfi) {
1626 if (!FLAG_log_function_events) return;
1627 MSG_BUILDER();
1628 int script_id = -1;
1629 if (sfi.script().IsScript()) {
1630 script_id = Script::cast(sfi.script()).id();
1631 }
1632 msg << "compilation-cache" << Logger::kNext << action << Logger::kNext
1633 << cache_type << Logger::kNext << script_id << Logger::kNext
1634 << sfi.StartPosition() << Logger::kNext << sfi.EndPosition()
1635 << Logger::kNext << Time();
1636 msg.WriteToLogFile();
1637 }
1638
ScriptEvent(ScriptEventType type,int script_id)1639 void Logger::ScriptEvent(ScriptEventType type, int script_id) {
1640 if (!FLAG_log_function_events) return;
1641 MSG_BUILDER();
1642 msg << "script" << Logger::kNext;
1643 switch (type) {
1644 case ScriptEventType::kReserveId:
1645 msg << "reserve-id";
1646 break;
1647 case ScriptEventType::kCreate:
1648 msg << "create";
1649 break;
1650 case ScriptEventType::kDeserialize:
1651 msg << "deserialize";
1652 break;
1653 case ScriptEventType::kBackgroundCompile:
1654 msg << "background-compile";
1655 break;
1656 case ScriptEventType::kStreamingCompile:
1657 msg << "streaming-compile";
1658 break;
1659 }
1660 msg << Logger::kNext << script_id << Logger::kNext << Time();
1661 msg.WriteToLogFile();
1662 }
1663
ScriptDetails(Script script)1664 void Logger::ScriptDetails(Script script) {
1665 if (!FLAG_log_function_events) return;
1666 {
1667 MSG_BUILDER();
1668 msg << "script-details" << Logger::kNext << script.id() << Logger::kNext;
1669 if (script.name().IsString()) {
1670 msg << String::cast(script.name());
1671 }
1672 msg << Logger::kNext << script.line_offset() << Logger::kNext
1673 << script.column_offset() << Logger::kNext;
1674 if (script.source_mapping_url().IsString()) {
1675 msg << String::cast(script.source_mapping_url());
1676 }
1677 msg.WriteToLogFile();
1678 }
1679 EnsureLogScriptSource(script);
1680 }
1681
EnsureLogScriptSource(Script script)1682 bool Logger::EnsureLogScriptSource(Script script) {
1683 // Make sure the script is written to the log file.
1684 int script_id = script.id();
1685 if (logged_source_code_.find(script_id) != logged_source_code_.end()) {
1686 return true;
1687 }
1688 // This script has not been logged yet.
1689 logged_source_code_.insert(script_id);
1690 Object source_object = script.source();
1691 if (!source_object.IsString()) return false;
1692
1693 std::unique_ptr<Log::MessageBuilder> msg_ptr = log_->NewMessageBuilder();
1694 if (!msg_ptr) return false;
1695 Log::MessageBuilder& msg = *msg_ptr.get();
1696
1697 String source_code = String::cast(source_object);
1698 msg << "script-source" << kNext << script_id << kNext;
1699
1700 // Log the script name.
1701 if (script.name().IsString()) {
1702 msg << String::cast(script.name()) << kNext;
1703 } else {
1704 msg << "<unknown>" << kNext;
1705 }
1706
1707 // Log the source code.
1708 msg << source_code;
1709 msg.WriteToLogFile();
1710 return true;
1711 }
1712
RuntimeCallTimerEvent()1713 void Logger::RuntimeCallTimerEvent() {
1714 #ifdef V8_RUNTIME_CALL_STATS
1715 RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
1716 RuntimeCallCounter* counter = stats->current_counter();
1717 if (counter == nullptr) return;
1718 MSG_BUILDER();
1719 msg << "active-runtime-timer" << kNext << counter->name();
1720 msg.WriteToLogFile();
1721 #endif // V8_RUNTIME_CALL_STATS
1722 }
1723
TickEvent(TickSample * sample,bool overflow)1724 void Logger::TickEvent(TickSample* sample, bool overflow) {
1725 if (!FLAG_prof_cpp) return;
1726 if (V8_UNLIKELY(TracingFlags::runtime_stats.load(std::memory_order_relaxed) ==
1727 v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE)) {
1728 RuntimeCallTimerEvent();
1729 }
1730 MSG_BUILDER();
1731 msg << kLogEventsNames[CodeEventListener::TICK_EVENT] << kNext
1732 << reinterpret_cast<void*>(sample->pc) << kNext << Time();
1733 if (sample->has_external_callback) {
1734 msg << kNext << 1 << kNext
1735 << reinterpret_cast<void*>(sample->external_callback_entry);
1736 } else {
1737 msg << kNext << 0 << kNext << reinterpret_cast<void*>(sample->tos);
1738 }
1739 msg << kNext << static_cast<int>(sample->state);
1740 if (overflow) msg << kNext << "overflow";
1741 for (unsigned i = 0; i < sample->frames_count; ++i) {
1742 msg << kNext << reinterpret_cast<void*>(sample->stack[i]);
1743 }
1744 msg.WriteToLogFile();
1745 }
1746
ICEvent(const char * type,bool keyed,Handle<Map> map,Handle<Object> key,char old_state,char new_state,const char * modifier,const char * slow_stub_reason)1747 void Logger::ICEvent(const char* type, bool keyed, Handle<Map> map,
1748 Handle<Object> key, char old_state, char new_state,
1749 const char* modifier, const char* slow_stub_reason) {
1750 if (!FLAG_log_ic) return;
1751 int line;
1752 int column;
1753 // GetAbstractPC must come before MSG_BUILDER(), as it can GC, which might
1754 // attempt to get the log lock again and result in a deadlock.
1755 Address pc = isolate_->GetAbstractPC(&line, &column);
1756 MSG_BUILDER();
1757 if (keyed) msg << "Keyed";
1758 msg << type << kNext << reinterpret_cast<void*>(pc) << kNext << Time()
1759 << kNext << line << kNext << column << kNext << old_state << kNext
1760 << new_state << kNext
1761 << AsHex::Address(map.is_null() ? kNullAddress : map->ptr()) << kNext;
1762 if (key->IsSmi()) {
1763 msg << Smi::ToInt(*key);
1764 } else if (key->IsNumber()) {
1765 msg << key->Number();
1766 } else if (key->IsName()) {
1767 msg << Name::cast(*key);
1768 }
1769 msg << kNext << modifier << kNext;
1770 if (slow_stub_reason != nullptr) {
1771 msg << slow_stub_reason;
1772 }
1773 msg.WriteToLogFile();
1774 }
1775
MapEvent(const char * type,Handle<Map> from,Handle<Map> to,const char * reason,Handle<HeapObject> name_or_sfi)1776 void Logger::MapEvent(const char* type, Handle<Map> from, Handle<Map> to,
1777 const char* reason, Handle<HeapObject> name_or_sfi) {
1778 if (!FLAG_log_maps) return;
1779 if (!to.is_null()) MapDetails(*to);
1780 int line = -1;
1781 int column = -1;
1782 Address pc = 0;
1783
1784 if (!isolate_->bootstrapper()->IsActive()) {
1785 pc = isolate_->GetAbstractPC(&line, &column);
1786 }
1787 MSG_BUILDER();
1788 msg << "map" << kNext << type << kNext << Time() << kNext
1789 << AsHex::Address(from.is_null() ? kNullAddress : from->ptr()) << kNext
1790 << AsHex::Address(to.is_null() ? kNullAddress : to->ptr()) << kNext
1791 << AsHex::Address(pc) << kNext << line << kNext << column << kNext
1792 << reason << kNext;
1793
1794 if (!name_or_sfi.is_null()) {
1795 if (name_or_sfi->IsName()) {
1796 msg << Name::cast(*name_or_sfi);
1797 } else if (name_or_sfi->IsSharedFunctionInfo()) {
1798 SharedFunctionInfo sfi = SharedFunctionInfo::cast(*name_or_sfi);
1799 msg << sfi.DebugNameCStr().get();
1800 #if V8_SFI_HAS_UNIQUE_ID
1801 msg << " " << sfi.unique_id();
1802 #endif // V8_SFI_HAS_UNIQUE_ID
1803 }
1804 }
1805 msg.WriteToLogFile();
1806 }
1807
MapCreate(Map map)1808 void Logger::MapCreate(Map map) {
1809 if (!FLAG_log_maps) return;
1810 DisallowGarbageCollection no_gc;
1811 MSG_BUILDER();
1812 msg << "map-create" << kNext << Time() << kNext << AsHex::Address(map.ptr());
1813 msg.WriteToLogFile();
1814 }
1815
MapDetails(Map map)1816 void Logger::MapDetails(Map map) {
1817 if (!FLAG_log_maps) return;
1818 DisallowGarbageCollection no_gc;
1819 MSG_BUILDER();
1820 msg << "map-details" << kNext << Time() << kNext << AsHex::Address(map.ptr())
1821 << kNext;
1822 if (FLAG_log_maps_details) {
1823 std::ostringstream buffer;
1824 map.PrintMapDetails(buffer);
1825 msg << buffer.str().c_str();
1826 }
1827 msg.WriteToLogFile();
1828 }
1829
1830 static std::vector<std::pair<Handle<SharedFunctionInfo>, Handle<AbstractCode>>>
EnumerateCompiledFunctions(Heap * heap)1831 EnumerateCompiledFunctions(Heap* heap) {
1832 HeapObjectIterator iterator(heap);
1833 DisallowGarbageCollection no_gc;
1834 std::vector<std::pair<Handle<SharedFunctionInfo>, Handle<AbstractCode>>>
1835 compiled_funcs;
1836 Isolate* isolate = heap->isolate();
1837
1838 // Iterate the heap to find JSFunctions and record their optimized code.
1839 for (HeapObject obj = iterator.Next(); !obj.is_null();
1840 obj = iterator.Next()) {
1841 if (obj.IsSharedFunctionInfo()) {
1842 SharedFunctionInfo sfi = SharedFunctionInfo::cast(obj);
1843 if (sfi.is_compiled() && !sfi.HasBytecodeArray()) {
1844 compiled_funcs.emplace_back(
1845 handle(sfi, isolate),
1846 handle(AbstractCode::cast(sfi.abstract_code(isolate)), isolate));
1847 }
1848 } else if (obj.IsJSFunction()) {
1849 // Given that we no longer iterate over all optimized JSFunctions, we need
1850 // to take care of this here.
1851 JSFunction function = JSFunction::cast(obj);
1852 // TODO(jarin) This leaves out deoptimized code that might still be on the
1853 // stack. Also note that we will not log optimized code objects that are
1854 // only on a type feedback vector. We should make this mroe precise.
1855 if (function.HasAttachedOptimizedCode() &&
1856 Script::cast(function.shared().script()).HasValidSource()) {
1857 compiled_funcs.emplace_back(
1858 handle(function.shared(), isolate),
1859 handle(AbstractCode::cast(FromCodeT(function.code())), isolate));
1860 }
1861 }
1862 }
1863
1864 Script::Iterator script_iterator(heap->isolate());
1865 for (Script script = script_iterator.Next(); !script.is_null();
1866 script = script_iterator.Next()) {
1867 if (!script.HasValidSource()) continue;
1868
1869 SharedFunctionInfo::ScriptIterator sfi_iterator(heap->isolate(), script);
1870 for (SharedFunctionInfo sfi = sfi_iterator.Next(); !sfi.is_null();
1871 sfi = sfi_iterator.Next()) {
1872 if (sfi.is_compiled()) {
1873 compiled_funcs.emplace_back(
1874 handle(sfi, isolate),
1875 handle(AbstractCode::cast(sfi.abstract_code(isolate)), isolate));
1876 }
1877 }
1878 }
1879
1880 return compiled_funcs;
1881 }
1882
LogCodeObjects()1883 void Logger::LogCodeObjects() { existing_code_logger_.LogCodeObjects(); }
1884
LogExistingFunction(Handle<SharedFunctionInfo> shared,Handle<AbstractCode> code)1885 void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
1886 Handle<AbstractCode> code) {
1887 existing_code_logger_.LogExistingFunction(shared, code);
1888 }
1889
LogCompiledFunctions()1890 void Logger::LogCompiledFunctions() {
1891 existing_code_logger_.LogCompiledFunctions();
1892 }
1893
LogBuiltins()1894 void Logger::LogBuiltins() { existing_code_logger_.LogBuiltins(); }
1895
LogAccessorCallbacks()1896 void Logger::LogAccessorCallbacks() {
1897 Heap* heap = isolate_->heap();
1898 HeapObjectIterator iterator(heap);
1899 DisallowGarbageCollection no_gc;
1900 for (HeapObject obj = iterator.Next(); !obj.is_null();
1901 obj = iterator.Next()) {
1902 if (!obj.IsAccessorInfo()) continue;
1903 AccessorInfo ai = AccessorInfo::cast(obj);
1904 if (!ai.name().IsName()) continue;
1905 Address getter_entry = v8::ToCData<Address>(ai.getter());
1906 HandleScope scope(isolate_);
1907 Handle<Name> name(Name::cast(ai.name()), isolate_);
1908 if (getter_entry != 0) {
1909 #if USES_FUNCTION_DESCRIPTORS
1910 getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(getter_entry);
1911 #endif
1912 PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
1913 }
1914 Address setter_entry = v8::ToCData<Address>(ai.setter());
1915 if (setter_entry != 0) {
1916 #if USES_FUNCTION_DESCRIPTORS
1917 setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(setter_entry);
1918 #endif
1919 PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
1920 }
1921 }
1922 }
1923
LogAllMaps()1924 void Logger::LogAllMaps() {
1925 Heap* heap = isolate_->heap();
1926 CombinedHeapObjectIterator iterator(heap);
1927 for (HeapObject obj = iterator.Next(); !obj.is_null();
1928 obj = iterator.Next()) {
1929 if (!obj.IsMap()) continue;
1930 Map map = Map::cast(obj);
1931 MapCreate(map);
1932 MapDetails(map);
1933 }
1934 }
1935
AddIsolateIdIfNeeded(std::ostream & os,Isolate * isolate)1936 static void AddIsolateIdIfNeeded(std::ostream& os, Isolate* isolate) {
1937 if (!FLAG_logfile_per_isolate) return;
1938 os << "isolate-" << isolate << "-" << base::OS::GetCurrentProcessId() << "-";
1939 }
1940
PrepareLogFileName(std::ostream & os,Isolate * isolate,const char * file_name)1941 static void PrepareLogFileName(std::ostream& os, Isolate* isolate,
1942 const char* file_name) {
1943 int dir_separator_count = 0;
1944 for (const char* p = file_name; *p; p++) {
1945 if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
1946 }
1947
1948 for (const char* p = file_name; *p; p++) {
1949 if (dir_separator_count == 0) {
1950 AddIsolateIdIfNeeded(os, isolate);
1951 dir_separator_count--;
1952 }
1953 if (*p == '%') {
1954 p++;
1955 switch (*p) {
1956 case '\0':
1957 // If there's a % at the end of the string we back up
1958 // one character so we can escape the loop properly.
1959 p--;
1960 break;
1961 case 'p':
1962 os << base::OS::GetCurrentProcessId();
1963 break;
1964 case 't':
1965 // %t expands to the current time in milliseconds.
1966 os << static_cast<int64_t>(
1967 V8::GetCurrentPlatform()->CurrentClockTimeMillis());
1968 break;
1969 case '%':
1970 // %% expands (contracts really) to %.
1971 os << '%';
1972 break;
1973 default:
1974 // All other %'s expand to themselves.
1975 os << '%' << *p;
1976 break;
1977 }
1978 } else {
1979 if (base::OS::isDirectorySeparator(*p)) dir_separator_count--;
1980 os << *p;
1981 }
1982 }
1983 }
1984
SetUp(Isolate * isolate)1985 bool Logger::SetUp(Isolate* isolate) {
1986 // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
1987 if (is_initialized_) return true;
1988 is_initialized_ = true;
1989
1990 std::ostringstream log_file_name;
1991 PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
1992 log_ = std::make_unique<Log>(this, log_file_name.str());
1993
1994 #if V8_OS_LINUX
1995 if (FLAG_perf_basic_prof) {
1996 perf_basic_logger_ = std::make_unique<PerfBasicLogger>(isolate);
1997 AddCodeEventListener(perf_basic_logger_.get());
1998 }
1999
2000 if (FLAG_perf_prof) {
2001 perf_jit_logger_ = std::make_unique<PerfJitLogger>(isolate);
2002 AddCodeEventListener(perf_jit_logger_.get());
2003 }
2004 #else
2005 static_assert(
2006 !FLAG_perf_prof,
2007 "--perf-prof should be statically disabled on non-Linux platforms");
2008 static_assert(
2009 !FLAG_perf_basic_prof,
2010 "--perf-basic-prof should be statically disabled on non-Linux platforms");
2011 #endif
2012
2013 #ifdef ENABLE_GDB_JIT_INTERFACE
2014 if (i::FLAG_gdbjit) {
2015 auto code_event_handler = i::GDBJITInterface::EventHandler;
2016 DCHECK_NOT_NULL(code_event_handler);
2017 gdb_jit_logger_ = std::make_unique<JitLogger>(isolate, code_event_handler);
2018 AddCodeEventListener(gdb_jit_logger_.get());
2019 CHECK(isolate->code_event_dispatcher()->IsListeningToCodeEvents());
2020 }
2021 #endif // ENABLE_GDB_JIT_INTERFACE
2022
2023 #if defined(V8_OS_WIN) && defined(V8_ENABLE_SYSTEM_INSTRUMENTATION)
2024 if (i::FLAG_enable_system_instrumentation) {
2025 auto code_event_handler = i::ETWJITInterface::EventHandler;
2026 DCHECK_NOT_NULL(code_event_handler);
2027 etw_jit_logger_ = std::make_unique<JitLogger>(isolate, code_event_handler);
2028 AddCodeEventListener(etw_jit_logger_.get());
2029 CHECK(isolate->code_event_dispatcher()->IsListeningToCodeEvents());
2030 }
2031 #endif // defined(V8_OS_WIN)
2032
2033 if (FLAG_ll_prof) {
2034 ll_logger_ =
2035 std::make_unique<LowLevelLogger>(isolate, log_file_name.str().c_str());
2036 AddCodeEventListener(ll_logger_.get());
2037 }
2038 ticker_ = std::make_unique<Ticker>(isolate, FLAG_prof_sampling_interval);
2039 if (FLAG_log) UpdateIsLogging(true);
2040 timer_.Start();
2041 if (FLAG_prof_cpp) {
2042 CHECK(FLAG_log);
2043 CHECK(is_logging());
2044 profiler_ = std::make_unique<Profiler>(isolate);
2045 profiler_->Engage();
2046 }
2047 if (is_logging_) AddCodeEventListener(this);
2048 return true;
2049 }
2050
LateSetup(Isolate * isolate)2051 void Logger::LateSetup(Isolate* isolate) {
2052 if (!isolate->code_event_dispatcher()->IsListeningToCodeEvents()) return;
2053 Builtins::EmitCodeCreateEvents(isolate);
2054 #if V8_ENABLE_WEBASSEMBLY
2055 wasm::GetWasmEngine()->EnableCodeLogging(isolate);
2056 #endif
2057 }
2058
SetCodeEventHandler(uint32_t options,JitCodeEventHandler event_handler)2059 void Logger::SetCodeEventHandler(uint32_t options,
2060 JitCodeEventHandler event_handler) {
2061 if (jit_logger_) {
2062 RemoveCodeEventListener(jit_logger_.get());
2063 jit_logger_.reset();
2064 }
2065
2066 if (event_handler) {
2067 #if V8_ENABLE_WEBASSEMBLY
2068 wasm::GetWasmEngine()->EnableCodeLogging(isolate_);
2069 #endif // V8_ENABLE_WEBASSEMBLY
2070 jit_logger_ = std::make_unique<JitLogger>(isolate_, event_handler);
2071 AddCodeEventListener(jit_logger_.get());
2072 if (options & kJitCodeEventEnumExisting) {
2073 HandleScope scope(isolate_);
2074 LogCodeObjects();
2075 LogBuiltins();
2076 LogCompiledFunctions();
2077 }
2078 }
2079 }
2080
sampler()2081 sampler::Sampler* Logger::sampler() { return ticker_.get(); }
file_name() const2082 std::string Logger::file_name() const { return log_.get()->file_name(); }
2083
StopProfilerThread()2084 void Logger::StopProfilerThread() {
2085 if (profiler_ != nullptr) {
2086 profiler_->Disengage();
2087 profiler_.reset();
2088 }
2089 }
2090
TearDownAndGetLogFile()2091 FILE* Logger::TearDownAndGetLogFile() {
2092 if (!is_initialized_) return nullptr;
2093 is_initialized_ = false;
2094 UpdateIsLogging(false);
2095
2096 // Stop the profiler thread before closing the file.
2097 StopProfilerThread();
2098
2099 ticker_.reset();
2100 timer_.Stop();
2101
2102 #if V8_OS_LINUX
2103 if (perf_basic_logger_) {
2104 RemoveCodeEventListener(perf_basic_logger_.get());
2105 perf_basic_logger_.reset();
2106 }
2107
2108 if (perf_jit_logger_) {
2109 RemoveCodeEventListener(perf_jit_logger_.get());
2110 perf_jit_logger_.reset();
2111 }
2112 #endif
2113
2114 if (ll_logger_) {
2115 RemoveCodeEventListener(ll_logger_.get());
2116 ll_logger_.reset();
2117 }
2118
2119 if (jit_logger_) {
2120 RemoveCodeEventListener(jit_logger_.get());
2121 jit_logger_.reset();
2122 }
2123
2124 return log_->Close();
2125 }
2126
UpdateIsLogging(bool value)2127 void Logger::UpdateIsLogging(bool value) {
2128 base::MutexGuard guard(log_->mutex());
2129 if (value) {
2130 isolate_->CollectSourcePositionsForAllBytecodeArrays();
2131 }
2132 // Relaxed atomic to avoid locking the mutex for the most common case: when
2133 // logging is disabled.
2134 is_logging_.store(value, std::memory_order_relaxed);
2135 }
2136
LogCodeObject(Object object)2137 void ExistingCodeLogger::LogCodeObject(Object object) {
2138 HandleScope scope(isolate_);
2139 Handle<AbstractCode> abstract_code(AbstractCode::cast(object), isolate_);
2140 CodeEventListener::LogEventsAndTags tag = CodeEventListener::STUB_TAG;
2141 const char* description = "Unknown code from before profiling";
2142 switch (abstract_code->kind()) {
2143 case CodeKind::INTERPRETED_FUNCTION:
2144 case CodeKind::TURBOFAN:
2145 case CodeKind::BASELINE:
2146 case CodeKind::MAGLEV:
2147 return; // We log this later using LogCompiledFunctions.
2148 case CodeKind::FOR_TESTING:
2149 description = "STUB code";
2150 tag = CodeEventListener::STUB_TAG;
2151 break;
2152 case CodeKind::REGEXP:
2153 description = "Regular expression code";
2154 tag = CodeEventListener::REG_EXP_TAG;
2155 break;
2156 case CodeKind::BYTECODE_HANDLER:
2157 description =
2158 isolate_->builtins()->name(abstract_code->GetCode().builtin_id());
2159 tag = CodeEventListener::BYTECODE_HANDLER_TAG;
2160 break;
2161 case CodeKind::BUILTIN:
2162 if (Code::cast(object).is_interpreter_trampoline_builtin() &&
2163 ToCodeT(Code::cast(object)) !=
2164 *BUILTIN_CODE(isolate_, InterpreterEntryTrampoline)) {
2165 return;
2166 }
2167 description =
2168 isolate_->builtins()->name(abstract_code->GetCode().builtin_id());
2169 tag = CodeEventListener::BUILTIN_TAG;
2170 break;
2171 case CodeKind::WASM_FUNCTION:
2172 description = "A Wasm function";
2173 tag = CodeEventListener::FUNCTION_TAG;
2174 break;
2175 case CodeKind::JS_TO_WASM_FUNCTION:
2176 description = "A JavaScript to Wasm adapter";
2177 tag = CodeEventListener::STUB_TAG;
2178 break;
2179 case CodeKind::JS_TO_JS_FUNCTION:
2180 description = "A WebAssembly.Function adapter";
2181 tag = CodeEventListener::STUB_TAG;
2182 break;
2183 case CodeKind::WASM_TO_CAPI_FUNCTION:
2184 description = "A Wasm to C-API adapter";
2185 tag = CodeEventListener::STUB_TAG;
2186 break;
2187 case CodeKind::WASM_TO_JS_FUNCTION:
2188 description = "A Wasm to JavaScript adapter";
2189 tag = CodeEventListener::STUB_TAG;
2190 break;
2191 case CodeKind::C_WASM_ENTRY:
2192 description = "A C to Wasm entry stub";
2193 tag = CodeEventListener::STUB_TAG;
2194 break;
2195 }
2196 CALL_CODE_EVENT_HANDLER(CodeCreateEvent(tag, abstract_code, description))
2197 }
2198
LogCodeObjects()2199 void ExistingCodeLogger::LogCodeObjects() {
2200 Heap* heap = isolate_->heap();
2201 HeapObjectIterator iterator(heap);
2202 DisallowGarbageCollection no_gc;
2203 for (HeapObject obj = iterator.Next(); !obj.is_null();
2204 obj = iterator.Next()) {
2205 if (obj.IsCode()) LogCodeObject(obj);
2206 if (obj.IsBytecodeArray()) LogCodeObject(obj);
2207 }
2208 }
2209
LogBuiltins()2210 void ExistingCodeLogger::LogBuiltins() {
2211 Builtins* builtins = isolate_->builtins();
2212 DCHECK(builtins->is_initialized());
2213 for (Builtin builtin = Builtins::kFirst; builtin <= Builtins::kLast;
2214 ++builtin) {
2215 Code code = FromCodeT(builtins->code(builtin));
2216 LogCodeObject(code);
2217 }
2218 }
2219
LogCompiledFunctions()2220 void ExistingCodeLogger::LogCompiledFunctions() {
2221 Heap* heap = isolate_->heap();
2222 HandleScope scope(isolate_);
2223 std::vector<std::pair<Handle<SharedFunctionInfo>, Handle<AbstractCode>>>
2224 compiled_funcs = EnumerateCompiledFunctions(heap);
2225
2226 // During iteration, there can be heap allocation due to
2227 // GetScriptLineNumber call.
2228 for (auto& pair : compiled_funcs) {
2229 Handle<SharedFunctionInfo> shared = pair.first;
2230 SharedFunctionInfo::EnsureSourcePositionsAvailable(isolate_, shared);
2231 if (shared->HasInterpreterData()) {
2232 LogExistingFunction(
2233 shared,
2234 Handle<AbstractCode>(
2235 AbstractCode::cast(FromCodeT(shared->InterpreterTrampoline())),
2236 isolate_));
2237 }
2238 if (shared->HasBaselineCode()) {
2239 LogExistingFunction(shared, Handle<AbstractCode>(
2240 AbstractCode::cast(FromCodeT(
2241 shared->baseline_code(kAcquireLoad))),
2242 isolate_));
2243 }
2244 if (pair.second.is_identical_to(BUILTIN_CODE(isolate_, CompileLazy)))
2245 continue;
2246 LogExistingFunction(pair.first, pair.second);
2247 }
2248
2249 #if V8_ENABLE_WEBASSEMBLY
2250 HeapObjectIterator iterator(heap);
2251 DisallowGarbageCollection no_gc;
2252
2253 for (HeapObject obj = iterator.Next(); !obj.is_null();
2254 obj = iterator.Next()) {
2255 if (!obj.IsWasmModuleObject()) continue;
2256 auto module_object = WasmModuleObject::cast(obj);
2257 module_object.native_module()->LogWasmCodes(isolate_,
2258 module_object.script());
2259 }
2260 #endif // V8_ENABLE_WEBASSEMBLY
2261 }
2262
LogExistingFunction(Handle<SharedFunctionInfo> shared,Handle<AbstractCode> code,CodeEventListener::LogEventsAndTags tag)2263 void ExistingCodeLogger::LogExistingFunction(
2264 Handle<SharedFunctionInfo> shared, Handle<AbstractCode> code,
2265 CodeEventListener::LogEventsAndTags tag) {
2266 if (shared->script().IsScript()) {
2267 Handle<Script> script(Script::cast(shared->script()), isolate_);
2268 int line_num = Script::GetLineNumber(script, shared->StartPosition()) + 1;
2269 int column_num =
2270 Script::GetColumnNumber(script, shared->StartPosition()) + 1;
2271 if (script->name().IsString()) {
2272 Handle<String> script_name(String::cast(script->name()), isolate_);
2273 if (!shared->is_toplevel()) {
2274 CALL_CODE_EVENT_HANDLER(
2275 CodeCreateEvent(Logger::ToNativeByScript(tag, *script), code,
2276 shared, script_name, line_num, column_num))
2277 } else {
2278 // Can't distinguish eval and script here, so always use Script.
2279 CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
2280 Logger::ToNativeByScript(CodeEventListener::SCRIPT_TAG, *script),
2281 code, shared, script_name))
2282 }
2283 } else {
2284 CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
2285 Logger::ToNativeByScript(tag, *script), code, shared,
2286 ReadOnlyRoots(isolate_).empty_string_handle(), line_num, column_num))
2287 }
2288 } else if (shared->IsApiFunction()) {
2289 // API function.
2290 Handle<FunctionTemplateInfo> fun_data =
2291 handle(shared->get_api_func_data(), isolate_);
2292 Object raw_call_data = fun_data->call_code(kAcquireLoad);
2293 if (!raw_call_data.IsUndefined(isolate_)) {
2294 CallHandlerInfo call_data = CallHandlerInfo::cast(raw_call_data);
2295 Object callback_obj = call_data.callback();
2296 Address entry_point = v8::ToCData<Address>(callback_obj);
2297 #if USES_FUNCTION_DESCRIPTORS
2298 entry_point = *FUNCTION_ENTRYPOINT_ADDRESS(entry_point);
2299 #endif
2300 Handle<String> fun_name = SharedFunctionInfo::DebugName(shared);
2301 CALL_CODE_EVENT_HANDLER(CallbackEvent(fun_name, entry_point))
2302
2303 // Fast API function.
2304 int c_functions_count = fun_data->GetCFunctionsCount();
2305 for (int i = 0; i < c_functions_count; i++) {
2306 CALL_CODE_EVENT_HANDLER(
2307 CallbackEvent(fun_name, fun_data->GetCFunction(i)))
2308 }
2309 }
2310 }
2311 }
2312
2313 #undef CALL_CODE_EVENT_HANDLER
2314 #undef MSG_BUILDER
2315
2316 } // namespace internal
2317 } // namespace v8
2318