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