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/interpreter/bytecodes.h" 20 #include "src/interpreter/interpreter.h" 21 #include "src/libsampler/sampler.h" 22 #include "src/log-inl.h" 23 #include "src/macro-assembler.h" 24 #include "src/objects/api-callbacks.h" 25 #include "src/perf-jit.h" 26 #include "src/profiler/tick-sample.h" 27 #include "src/runtime-profiler.h" 28 #include "src/snapshot/embedded-data.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" 37 #include "src/utils.h" 38 #include "src/version.h" 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)};
49 CodeEventListener::LogEventsAndTags tag) {
51 case CodeEventListener::NUMBER_OF_LOG_EVENTS:
52 #define V(Event, _) case CodeEventListener::Event: 55 return v8::CodeEventType::kUnknownType;
57 case CodeEventListener::From: \ 58 return v8::CodeEventType::k##To##Type; 65 return v8::CodeEventType::kUnknownType;
67 #define CALL_CODE_EVENT_HANDLER(Call) \ 71 PROFILE(isolate_, Call); \ 74 static const char* ComputeMarker(SharedFunctionInfo* shared,
76 switch (code->kind()) {
77 case AbstractCode::INTERPRETED_FUNCTION:
78 return shared->optimization_disabled() ?
"" :
"~";
79 case AbstractCode::OPTIMIZED_FUNCTION:
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:
105 void Init(CodeEventListener::LogEventsAndTags tag) {
107 AppendBytes(kLogEventsNames[tag]);
111 void AppendName(
Name name) {
112 if (name->IsString()) {
113 AppendString(String::cast(name));
115 Symbol symbol = Symbol::cast(name);
116 AppendBytes(
"symbol(");
117 if (!symbol->name()->IsUndefined()) {
119 AppendString(String::cast(symbol->name()));
122 AppendBytes(
"hash ");
123 AppendHex(symbol->Hash());
128 void AppendString(
String str) {
129 if (str.is_null())
return;
131 std::unique_ptr<char[]> c_str =
132 str->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL, &length);
133 AppendBytes(c_str.get(), length);
136 void AppendBytes(
const char* bytes,
int size) {
137 size = Min(size, kUtf8BufferSize - utf8_pos_);
138 MemCopy(utf8_buffer_ + utf8_pos_, bytes, size);
142 void AppendBytes(
const char* bytes) {
143 AppendBytes(bytes, StrLength(bytes));
146 void AppendByte(
char c) {
147 if (utf8_pos_ >= kUtf8BufferSize)
return;
148 utf8_buffer_[utf8_pos_++] = c;
151 void AppendInt(
int n) {
152 int space = kUtf8BufferSize - utf8_pos_;
153 if (space <= 0)
return;
155 int size = SNPrintF(buffer,
"%d", n);
156 if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
162 int space = kUtf8BufferSize - utf8_pos_;
163 if (space <= 0)
return;
165 int size = SNPrintF(buffer,
"%x", n);
166 if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
171 const char*
get() {
return utf8_buffer_; }
172 int size()
const {
return utf8_pos_; }
175 static const int kUtf8BufferSize = 512;
176 static const int kUtf16BufferSize = kUtf8BufferSize;
179 char utf8_buffer_[kUtf8BufferSize];
182 CodeEventLogger::CodeEventLogger(
Isolate* isolate)
183 : isolate_(isolate), name_buffer_(new
NameBuffer) {}
185 CodeEventLogger::~CodeEventLogger() {
delete name_buffer_; }
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());
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());
201 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
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());
210 void CodeEventLogger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
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));
221 name_buffer_->AppendBytes(
"symbol(hash ");
222 name_buffer_->AppendHex(Name::cast(source)->Hash());
223 name_buffer_->AppendByte(
')');
225 name_buffer_->AppendByte(
':');
226 name_buffer_->AppendInt(line);
227 LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
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>");
237 name_buffer_->AppendBytes(name.start(), name.length());
239 name_buffer_->AppendByte(
'-');
240 if (code->IsAnonymous()) {
241 name_buffer_->AppendBytes(
"<anonymous>");
243 name_buffer_->AppendInt(code->index());
245 LogRecordedBuffer(code, name_buffer_->get(), name_buffer_->size());
248 void CodeEventLogger::RegExpCodeCreateEvent(AbstractCode code, String source) {
249 name_buffer_->Init(CodeEventListener::REG_EXP_TAG);
250 name_buffer_->AppendString(source);
251 LogRecordedBuffer(code,
nullptr, name_buffer_->get(), name_buffer_->size());
266 const char* name,
int length)
override;
267 void LogRecordedBuffer(
const wasm::WasmCode* code,
const char* name,
268 int length)
override;
269 void WriteLogRecordedBuffer(
uintptr_t address,
int size,
const char* name,
273 static const char kFilenameFormatString[];
274 static const int kFilenameBufferPadding;
276 FILE* perf_output_handle_;
279 const char PerfBasicLogger::kFilenameFormatString[] =
"/tmp/perf-%d.map";
281 const int PerfBasicLogger::kFilenameBufferPadding = 16;
283 PerfBasicLogger::PerfBasicLogger(
Isolate* isolate)
286 int bufferSize =
sizeof(kFilenameFormatString) + kFilenameBufferPadding;
290 kFilenameFormatString,
291 base::OS::GetCurrentProcessId());
293 perf_output_handle_ =
294 base::OS::FOpen(perf_dump_name.start(), base::OS::LogFileOpenMode);
295 CHECK_NOT_NULL(perf_output_handle_);
296 setvbuf(perf_output_handle_,
nullptr, _IOLBF, 0);
300 PerfBasicLogger::~PerfBasicLogger() {
301 fclose(perf_output_handle_);
302 perf_output_handle_ =
nullptr;
305 void PerfBasicLogger::WriteLogRecordedBuffer(
uintptr_t address,
int size,
314 base::OS::FPrint(perf_output_handle_,
"%" V8PRIxPTR
" %x %.*s\n", address,
315 size, name_length, name);
318 void PerfBasicLogger::LogRecordedBuffer(AbstractCode code, SharedFunctionInfo*,
319 const char* name,
int length) {
320 if (FLAG_perf_basic_prof_only_functions &&
321 (code->kind() != AbstractCode::INTERPRETED_FUNCTION &&
322 code->kind() != AbstractCode::BUILTIN &&
323 code->kind() != AbstractCode::OPTIMIZED_FUNCTION)) {
327 WriteLogRecordedBuffer(static_cast<uintptr_t>(code->InstructionStart()),
328 code->InstructionSize(), name, length);
331 void PerfBasicLogger::LogRecordedBuffer(
const wasm::WasmCode* code,
332 const char* name,
int length) {
333 WriteLogRecordedBuffer(static_cast<uintptr_t>(code->instruction_start()),
334 code->instructions().length(), name, length);
338 ExternalCodeEventListener::ExternalCodeEventListener(Isolate* isolate)
339 : is_listening_(false), isolate_(isolate), code_event_handler_(nullptr) {}
341 ExternalCodeEventListener::~ExternalCodeEventListener() {
347 void ExternalCodeEventListener::LogExistingCode() {
348 HandleScope scope(isolate_);
349 ExistingCodeLogger logger(isolate_,
this);
350 logger.LogCodeObjects();
351 logger.LogCompiledFunctions();
354 void ExternalCodeEventListener::StartListening(
355 CodeEventHandler* code_event_handler) {
356 if (is_listening_ || code_event_handler ==
nullptr) {
359 code_event_handler_ = code_event_handler;
360 is_listening_ = isolate_->code_event_dispatcher()->AddListener(
this);
366 void ExternalCodeEventListener::StopListening() {
367 if (!is_listening_) {
371 isolate_->code_event_dispatcher()->RemoveListener(
this);
372 is_listening_ =
false;
375 void ExternalCodeEventListener::CodeCreateEvent(
376 CodeEventListener::LogEventsAndTags tag, AbstractCode code,
377 const char* comment) {
378 CodeEvent code_event;
379 code_event.code_start_address =
380 static_cast<uintptr_t>(code->InstructionStart());
381 code_event.code_size =
static_cast<size_t>(code->InstructionSize());
382 code_event.function_name = isolate_->factory()->empty_string();
383 code_event.script_name = isolate_->factory()->empty_string();
384 code_event.script_line = 0;
385 code_event.script_column = 0;
386 code_event.code_type = GetCodeEventTypeForTag(tag);
387 code_event.comment = comment;
389 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
392 void ExternalCodeEventListener::CodeCreateEvent(
393 CodeEventListener::LogEventsAndTags tag, AbstractCode code, Name name) {
394 Handle<String> name_string =
395 Name::ToFunctionName(isolate_, Handle<Name>(name, isolate_))
398 CodeEvent code_event;
399 code_event.code_start_address =
400 static_cast<uintptr_t>(code->InstructionStart());
401 code_event.code_size =
static_cast<size_t>(code->InstructionSize());
402 code_event.function_name = name_string;
403 code_event.script_name = isolate_->factory()->empty_string();
404 code_event.script_line = 0;
405 code_event.script_column = 0;
406 code_event.code_type = GetCodeEventTypeForTag(tag);
407 code_event.comment =
"";
409 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
412 void ExternalCodeEventListener::CodeCreateEvent(
413 CodeEventListener::LogEventsAndTags tag, AbstractCode code,
414 SharedFunctionInfo* shared, Name name) {
415 Handle<String> name_string =
416 Name::ToFunctionName(isolate_, Handle<Name>(name, isolate_))
419 CodeEvent code_event;
420 code_event.code_start_address =
421 static_cast<uintptr_t>(code->InstructionStart());
422 code_event.code_size =
static_cast<size_t>(code->InstructionSize());
423 code_event.function_name = name_string;
424 code_event.script_name = isolate_->factory()->empty_string();
425 code_event.script_line = 0;
426 code_event.script_column = 0;
427 code_event.code_type = GetCodeEventTypeForTag(tag);
428 code_event.comment =
"";
430 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
433 void ExternalCodeEventListener::CodeCreateEvent(
434 CodeEventListener::LogEventsAndTags tag, AbstractCode code,
435 SharedFunctionInfo* shared, Name source,
int line,
int column) {
436 Handle<String> name_string =
437 Name::ToFunctionName(isolate_, Handle<Name>(shared->Name(), isolate_))
439 Handle<String> source_string =
440 Name::ToFunctionName(isolate_, Handle<Name>(source, isolate_))
443 CodeEvent code_event;
444 code_event.code_start_address =
445 static_cast<uintptr_t>(code->InstructionStart());
446 code_event.code_size =
static_cast<size_t>(code->InstructionSize());
447 code_event.function_name = name_string;
448 code_event.script_name = source_string;
449 code_event.script_line = line;
450 code_event.script_column = column;
451 code_event.code_type = GetCodeEventTypeForTag(tag);
452 code_event.comment =
"";
454 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
457 void ExternalCodeEventListener::CodeCreateEvent(LogEventsAndTags tag,
458 const wasm::WasmCode* code,
459 wasm::WasmName name) {
463 void ExternalCodeEventListener::RegExpCodeCreateEvent(AbstractCode code,
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 = Handle<String>(source, isolate_);
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(CodeEventListener::REG_EXP_TAG);
474 code_event.comment =
"";
476 code_event_handler_->Handle(reinterpret_cast<v8::CodeEvent*>(&code_event));
488 void SnapshotPositionEvent(
HeapObject* obj,
int pos);
489 void CodeMovingGCEvent()
override;
493 const char* name,
int length)
override;
494 void LogRecordedBuffer(
const wasm::WasmCode* code,
const char* name,
495 int length)
override;
498 struct CodeCreateStruct {
499 static const char kTag =
'C';
507 struct CodeMoveStruct {
508 static const char kTag =
'M';
515 static const char kCodeMovingGCTag =
'G';
519 static const char kLogExt[];
522 void LogWriteBytes(
const char* bytes,
int size);
524 template <
typename T>
525 void LogWriteStruct(
const T& s) {
527 LogWriteBytes(reinterpret_cast<const char*>(&tag),
sizeof(tag));
528 LogWriteBytes(reinterpret_cast<const char*>(&s),
sizeof(s));
531 FILE* ll_output_handle_;
534 const char LowLevelLogger::kLogExt[] =
".ll";
536 LowLevelLogger::LowLevelLogger(
Isolate* isolate,
const char* name)
539 size_t len = strlen(name);
541 MemCopy(ll_name.start(), name, len);
542 MemCopy(ll_name.start() + len, kLogExt,
sizeof(kLogExt));
544 base::OS::FOpen(ll_name.start(), base::OS::LogFileOpenMode);
545 setvbuf(ll_output_handle_,
nullptr, _IOLBF, 0);
551 LowLevelLogger::~LowLevelLogger() {
552 fclose(ll_output_handle_);
553 ll_output_handle_ =
nullptr;
557 void LowLevelLogger::LogCodeInfo() {
558 #if V8_TARGET_ARCH_IA32 559 const char arch[] =
"ia32";
560 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_64_BIT 561 const char arch[] =
"x64";
562 #elif V8_TARGET_ARCH_X64 && V8_TARGET_ARCH_32_BIT 563 const char arch[] =
"x32";
564 #elif V8_TARGET_ARCH_ARM 565 const char arch[] =
"arm";
566 #elif V8_TARGET_ARCH_PPC 567 const char arch[] =
"ppc";
568 #elif V8_TARGET_ARCH_MIPS 569 const char arch[] =
"mips";
570 #elif V8_TARGET_ARCH_ARM64 571 const char arch[] =
"arm64";
572 #elif V8_TARGET_ARCH_S390 573 const char arch[] =
"s390";
575 const char arch[] =
"unknown";
577 LogWriteBytes(arch,
sizeof(arch));
580 void LowLevelLogger::LogRecordedBuffer(AbstractCode code, SharedFunctionInfo*,
581 const char* name,
int length) {
582 CodeCreateStruct event;
583 event.name_size = length;
584 event.code_address = code->InstructionStart();
585 event.code_size = code->InstructionSize();
586 LogWriteStruct(event);
587 LogWriteBytes(name, length);
588 LogWriteBytes(reinterpret_cast<const char*>(code->InstructionStart()),
589 code->InstructionSize());
592 void LowLevelLogger::LogRecordedBuffer(
const wasm::WasmCode* code,
593 const char* name,
int length) {
594 CodeCreateStruct event;
595 event.name_size = length;
596 event.code_address = code->instruction_start();
597 event.code_size = code->instructions().length();
598 LogWriteStruct(event);
599 LogWriteBytes(name, length);
600 LogWriteBytes(reinterpret_cast<const char*>(code->instruction_start()),
601 code->instructions().length());
604 void LowLevelLogger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
605 CodeMoveStruct event;
606 event.from_address = from->InstructionStart();
607 event.to_address = to->InstructionStart();
608 LogWriteStruct(event);
611 void LowLevelLogger::LogWriteBytes(
const char* bytes,
int size) {
612 size_t rv = fwrite(bytes, 1, size, ll_output_handle_);
613 DCHECK(static_cast<size_t>(size) == rv);
618 void LowLevelLogger::CodeMovingGCEvent() {
619 const char tag = kCodeMovingGCTag;
621 LogWriteBytes(&tag,
sizeof(tag));
631 void AddCodeLinePosInfoEvent(
void* jit_handler_data,
int pc_offset,
633 JitCodeEvent::PositionType position_type);
635 void* StartCodePosInfoEvent();
636 void EndCodePosInfoEvent(
Address start_address,
void* jit_handler_data);
640 const char* name,
int length)
override;
641 void LogRecordedBuffer(
const wasm::WasmCode* code,
const char* name,
642 int length)
override;
644 JitCodeEventHandler code_event_handler_;
648 JitLogger::JitLogger(
Isolate* isolate, JitCodeEventHandler code_event_handler)
651 void JitLogger::LogRecordedBuffer(AbstractCode code, SharedFunctionInfo* shared,
652 const char* name,
int length) {
654 memset(static_cast<void*>(&event), 0,
sizeof(event));
655 event.type = JitCodeEvent::CODE_ADDED;
656 event.code_start =
reinterpret_cast<void*
>(code->InstructionStart());
658 code->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
659 event.code_len = code->InstructionSize();
661 if (shared && shared->script()->IsScript()) {
662 shared_function_handle =
665 event.script = ToApiHandle<v8::UnboundScript>(shared_function_handle);
666 event.name.str = name;
667 event.name.len = length;
668 event.isolate =
reinterpret_cast<v8::Isolate*
>(isolate_);
669 code_event_handler_(&event);
672 void JitLogger::LogRecordedBuffer(
const wasm::WasmCode* code,
const char* name,
675 memset(static_cast<void*>(&event), 0,
sizeof(event));
676 event.type = JitCodeEvent::CODE_ADDED;
677 event.code_type = JitCodeEvent::JIT_CODE;
678 event.code_start = code->instructions().start();
679 event.code_len = code->instructions().length();
680 event.name.str = name;
681 event.name.len = length;
682 event.isolate =
reinterpret_cast<v8::Isolate*
>(isolate_);
683 code_event_handler_(&event);
686 void JitLogger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
687 base::MutexGuard guard(&logger_mutex_);
690 event.type = JitCodeEvent::CODE_MOVED;
692 from->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE;
693 event.code_start =
reinterpret_cast<void*
>(from->InstructionStart());
694 event.code_len = from->InstructionSize();
695 event.new_code_start =
reinterpret_cast<void*
>(to->InstructionStart());
696 event.isolate =
reinterpret_cast<v8::Isolate*
>(isolate_);
698 code_event_handler_(&event);
701 void JitLogger::AddCodeLinePosInfoEvent(
702 void* jit_handler_data,
705 JitCodeEvent::PositionType position_type) {
707 memset(static_cast<void*>(&event), 0,
sizeof(event));
708 event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
709 event.user_data = jit_handler_data;
710 event.line_info.offset = pc_offset;
711 event.line_info.pos = position;
712 event.line_info.position_type = position_type;
713 event.isolate =
reinterpret_cast<v8::Isolate*
>(isolate_);
715 code_event_handler_(&event);
719 void* JitLogger::StartCodePosInfoEvent() {
721 memset(static_cast<void*>(&event), 0,
sizeof(event));
722 event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
723 event.isolate =
reinterpret_cast<v8::Isolate*
>(isolate_);
725 code_event_handler_(&event);
726 return event.user_data;
729 void JitLogger::EndCodePosInfoEvent(Address start_address,
730 void* jit_handler_data) {
732 memset(static_cast<void*>(&event), 0,
sizeof(event));
733 event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
734 event.code_start =
reinterpret_cast<void*
>(start_address);
735 event.user_data = jit_handler_data;
736 event.isolate =
reinterpret_cast<v8::Isolate*
>(isolate_);
738 code_event_handler_(&event);
747 static const int kSamplingThreadStackSize = 64 * KB;
753 interval_microseconds_(interval_microseconds) {}
754 void Run()
override {
755 while (sampler_->IsProfiling()) {
756 sampler_->DoSample();
758 base::TimeDelta::FromMicroseconds(interval_microseconds_));
764 const int interval_microseconds_;
784 if (Succ(head_) == static_cast<int>(base::Relaxed_Load(&tail_))) {
787 buffer_[head_] = *sample;
789 buffer_semaphore_.Signal();
796 void Pause() { paused_ =
true; }
797 void Resume() { paused_ =
false; }
802 buffer_semaphore_.Wait();
803 *sample = buffer_[base::Relaxed_Load(&tail_)];
804 bool result = overflow_;
806 &tail_, static_cast<base::Atomic32>(Succ(base::Relaxed_Load(&tail_))));
812 int Succ(
int index) {
return (index + 1) % kBufferSize; }
817 static const int kBufferSize = 128;
820 base::Atomic32 tail_;
829 base::Atomic32 running_;
845 sampling_thread_(
new SamplingThread(
this, interval_microseconds)) {}
848 if (IsActive()) Stop();
849 delete sampling_thread_;
852 void SetProfiler(
Profiler* profiler) {
853 DCHECK_NULL(profiler_);
854 profiler_ = profiler;
855 IncreaseProfilingDepth();
856 if (!IsActive()) Start();
857 sampling_thread_->StartSynchronously();
860 void ClearProfiler() {
862 if (IsActive()) Stop();
863 DecreaseProfilingDepth();
864 sampling_thread_->Join();
868 if (!profiler_)
return;
871 sample.Init(isolate, state, TickSample::kIncludeCEntryFrame,
true);
872 profiler_->Insert(&sample);
883 Profiler::Profiler(
Isolate* isolate)
884 : base::Thread(Options(
"v8:Profiler")),
888 buffer_semaphore_(0),
891 base::Relaxed_Store(&tail_, 0);
892 base::Relaxed_Store(&running_, 0);
896 void Profiler::Engage() {
897 if (engaged_)
return;
900 std::vector<base::OS::SharedLibraryAddress> addresses =
901 base::OS::GetSharedLibraryAddresses();
902 for (
const auto& address : addresses) {
903 LOG(isolate_, SharedLibraryEvent(address.library_path, address.start,
904 address.end, address.aslr_slide));
908 base::Relaxed_Store(&running_, 1);
912 Logger* logger = isolate_->logger();
913 logger->ticker_->SetProfiler(
this);
915 logger->ProfilerBeginEvent();
919 void Profiler::Disengage() {
920 if (!engaged_)
return;
923 isolate_->logger()->ticker_->ClearProfiler();
928 base::Relaxed_Store(&running_, 0);
935 LOG(isolate_, UncheckedStringEvent(
"profiler",
"end"));
939 void Profiler::Run() {
941 bool overflow = Remove(&sample);
942 while (base::Relaxed_Load(&running_)) {
943 LOG(isolate_, TickEvent(&sample, overflow));
944 overflow = Remove(&sample);
953 Logger::Logger(Isolate* isolate)
957 log_events_(nullptr),
960 perf_basic_logger_(nullptr),
961 perf_jit_logger_(nullptr),
963 jit_logger_(nullptr),
964 is_initialized_(false),
965 existing_code_logger_(isolate) {}
971 void Logger::AddCodeEventListener(CodeEventListener* listener) {
972 bool result = isolate_->code_event_dispatcher()->AddListener(listener);
976 void Logger::RemoveCodeEventListener(CodeEventListener* listener) {
977 isolate_->code_event_dispatcher()->RemoveListener(listener);
980 void Logger::ProfilerBeginEvent() {
981 if (!log_->IsEnabled())
return;
982 Log::MessageBuilder msg(log_);
983 msg <<
"profiler" << kNext <<
"begin" << kNext << FLAG_prof_sampling_interval;
984 msg.WriteToLogFile();
988 void Logger::StringEvent(
const char* name,
const char* value) {
989 if (FLAG_log) UncheckedStringEvent(name, value);
993 void Logger::UncheckedStringEvent(
const char* name,
const char* value) {
994 if (!log_->IsEnabled())
return;
995 Log::MessageBuilder msg(log_);
996 msg << name << kNext << value;
997 msg.WriteToLogFile();
1001 void Logger::IntPtrTEvent(
const char* name, intptr_t value) {
1002 if (FLAG_log) UncheckedIntPtrTEvent(name, value);
1006 void Logger::UncheckedIntPtrTEvent(
const char* name, intptr_t value) {
1007 if (!log_->IsEnabled())
return;
1008 Log::MessageBuilder msg(log_);
1009 msg << name << kNext;
1010 msg.AppendFormatString(
"%" V8PRIdPTR, value);
1011 msg.WriteToLogFile();
1014 void Logger::HandleEvent(
const char* name, Address* location) {
1015 if (!log_->IsEnabled() || !FLAG_log_handles)
return;
1016 Log::MessageBuilder msg(log_);
1017 msg << name << kNext << reinterpret_cast<void*>(location);
1018 msg.WriteToLogFile();
1022 void Logger::ApiSecurityCheck() {
1023 if (!log_->IsEnabled() || !FLAG_log_api)
return;
1024 Log::MessageBuilder msg(log_);
1025 msg <<
"api" << kNext <<
"check-security";
1026 msg.WriteToLogFile();
1029 void Logger::SharedLibraryEvent(
const std::string& library_path,
1031 intptr_t aslr_slide) {
1032 if (!log_->IsEnabled() || !FLAG_prof_cpp)
return;
1033 Log::MessageBuilder msg(log_);
1034 msg <<
"shared-library" << kNext << library_path.c_str() << kNext
1035 <<
reinterpret_cast<void*
>(start) << kNext << reinterpret_cast<void*>(end)
1036 << kNext << aslr_slide;
1037 msg.WriteToLogFile();
1040 void Logger::CodeDeoptEvent(Code code, DeoptimizeKind kind, Address pc,
1041 int fp_to_sp_delta) {
1042 if (!log_->IsEnabled())
return;
1043 Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc);
1044 Log::MessageBuilder msg(log_);
1045 msg <<
"code-deopt" << kNext << timer_.Elapsed().InMicroseconds() << kNext
1046 << code->CodeSize() << kNext
1047 <<
reinterpret_cast<void*
>(code->InstructionStart());
1050 std::ostringstream deopt_location;
1051 int inlining_id = -1;
1052 int script_offset = -1;
1053 if (info.position.IsKnown()) {
1054 info.position.Print(deopt_location, code);
1055 inlining_id = info.position.InliningId();
1056 script_offset = info.position.ScriptOffset();
1058 deopt_location <<
"<unknown>";
1060 msg << kNext << inlining_id << kNext << script_offset << kNext;
1061 msg << Deoptimizer::MessageFor(kind) << kNext;
1062 msg << deopt_location.str().c_str() << kNext
1063 << DeoptimizeReasonToString(info.deopt_reason);
1064 msg.WriteToLogFile();
1068 void Logger::CurrentTimeEvent() {
1069 if (!log_->IsEnabled())
return;
1070 DCHECK(FLAG_log_internal_timer_events);
1071 Log::MessageBuilder msg(log_);
1072 msg <<
"current-time" << kNext << timer_.Elapsed().InMicroseconds();
1073 msg.WriteToLogFile();
1077 void Logger::TimerEvent(Logger::StartEnd se,
const char* name) {
1078 if (!log_->IsEnabled())
return;
1079 Log::MessageBuilder msg(log_);
1082 msg <<
"timer-event-start";
1085 msg <<
"timer-event-end";
1088 msg <<
"timer-event";
1090 msg << kNext << name << kNext << timer_.Elapsed().InMicroseconds();
1091 msg.WriteToLogFile();
1095 void Logger::EnterExternal(Isolate* isolate) {
1096 DCHECK(FLAG_log_internal_timer_events);
1097 LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
1098 DCHECK(isolate->current_vm_state() == JS);
1099 isolate->set_current_vm_state(EXTERNAL);
1103 void Logger::LeaveExternal(Isolate* isolate) {
1104 DCHECK(FLAG_log_internal_timer_events);
1105 LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
1106 DCHECK(isolate->current_vm_state() == EXTERNAL);
1107 isolate->set_current_vm_state(JS);
1111 #define V(TimerName, expose) \ 1112 template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \ 1113 Logger::StartEnd se); 1114 TIMER_EVENTS_LIST(
V)
1117 void Logger::ApiNamedPropertyAccess(
const char* tag, JSObject* holder,
1118 Object* property_name) {
1119 DCHECK(property_name->IsName());
1120 if (!log_->IsEnabled() || !FLAG_log_api)
return;
1121 Log::MessageBuilder msg(log_);
1122 msg <<
"api" << kNext << tag << kNext << holder->class_name() << kNext
1123 << Name::cast(property_name);
1124 msg.WriteToLogFile();
1127 void Logger::ApiIndexedPropertyAccess(
const char* tag,
1130 if (!log_->IsEnabled() || !FLAG_log_api)
return;
1131 Log::MessageBuilder msg(log_);
1132 msg <<
"api" << kNext << tag << kNext << holder->class_name() << kNext
1134 msg.WriteToLogFile();
1138 void Logger::ApiObjectAccess(
const char* tag, JSObject*
object) {
1139 if (!log_->IsEnabled() || !FLAG_log_api)
return;
1140 Log::MessageBuilder msg(log_);
1141 msg <<
"api" << kNext << tag << kNext <<
object->class_name();
1142 msg.WriteToLogFile();
1146 void Logger::ApiEntryCall(
const char* name) {
1147 if (!log_->IsEnabled() || !FLAG_log_api)
return;
1148 Log::MessageBuilder msg(log_);
1149 msg <<
"api" << kNext << name;
1150 msg.WriteToLogFile();
1154 void Logger::NewEvent(
const char* name,
void*
object,
size_t size) {
1155 if (!log_->IsEnabled() || !FLAG_log)
return;
1156 Log::MessageBuilder msg(log_);
1157 msg <<
"new" << kNext << name << kNext <<
object << kNext
1158 <<
static_cast<unsigned int>(size);
1159 msg.WriteToLogFile();
1163 void Logger::DeleteEvent(
const char* name,
void*
object) {
1164 if (!log_->IsEnabled() || !FLAG_log)
return;
1165 Log::MessageBuilder msg(log_);
1166 msg <<
"delete" << kNext << name << kNext << object;
1167 msg.WriteToLogFile();
1170 void Logger::CallbackEventInternal(
const char* prefix, Name name,
1171 Address entry_point) {
1172 if (!FLAG_log_code || !log_->IsEnabled())
return;
1173 Log::MessageBuilder msg(log_);
1174 msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT] << kNext
1175 << kLogEventsNames[CodeEventListener::CALLBACK_TAG] << kNext << -2
1176 << kNext << timer_.Elapsed().InMicroseconds() << kNext
1177 <<
reinterpret_cast<void*
>(entry_point) << kNext << 1 << kNext << prefix
1179 msg.WriteToLogFile();
1182 void Logger::CallbackEvent(Name name, Address entry_point) {
1183 CallbackEventInternal(
"", name, entry_point);
1186 void Logger::GetterCallbackEvent(Name name, Address entry_point) {
1187 CallbackEventInternal(
"get ", name, entry_point);
1190 void Logger::SetterCallbackEvent(Name name, Address entry_point) {
1191 CallbackEventInternal(
"set ", name, entry_point);
1196 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
1197 CodeEventListener::LogEventsAndTags tag,
1198 AbstractCode::Kind kind, uint8_t* address,
int size,
1199 base::ElapsedTimer* timer) {
1200 msg << kLogEventsNames[CodeEventListener::CODE_CREATION_EVENT]
1201 << Logger::kNext << kLogEventsNames[tag] << Logger::kNext << kind
1202 << Logger::kNext << timer->Elapsed().InMicroseconds() << Logger::kNext
1203 <<
reinterpret_cast<void*
>(address) << Logger::kNext << size
1207 void AppendCodeCreateHeader(Log::MessageBuilder& msg,
1208 CodeEventListener::LogEventsAndTags tag,
1209 AbstractCode code, base::ElapsedTimer* timer) {
1210 AppendCodeCreateHeader(msg, tag, code->kind(),
1211 reinterpret_cast<uint8_t*
>(code->InstructionStart()),
1212 code->InstructionSize(), timer);
1217 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1218 AbstractCode code,
const char* comment) {
1219 if (!is_listening_to_code_events())
return;
1220 if (!FLAG_log_code || !log_->IsEnabled())
return;
1221 Log::MessageBuilder msg(log_);
1222 AppendCodeCreateHeader(msg, tag, code, &timer_);
1224 msg.WriteToLogFile();
1227 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1228 AbstractCode code, Name name) {
1229 if (!is_listening_to_code_events())
return;
1230 if (!FLAG_log_code || !log_->IsEnabled())
return;
1231 Log::MessageBuilder msg(log_);
1232 AppendCodeCreateHeader(msg, tag, code, &timer_);
1234 msg.WriteToLogFile();
1237 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1238 AbstractCode code, SharedFunctionInfo* shared,
1240 if (!is_listening_to_code_events())
return;
1241 if (!FLAG_log_code || !log_->IsEnabled())
return;
1242 if (code == AbstractCode::cast(
1243 isolate_->builtins()->builtin(Builtins::kCompileLazy))) {
1247 Log::MessageBuilder msg(log_);
1248 AppendCodeCreateHeader(msg, tag, code, &timer_);
1249 msg << name << kNext << reinterpret_cast<void*>(shared->address()) << kNext
1250 << ComputeMarker(shared, code);
1251 msg.WriteToLogFile();
1254 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1255 const wasm::WasmCode* code, wasm::WasmName name) {
1256 if (!is_listening_to_code_events())
return;
1257 if (!FLAG_log_code || !log_->IsEnabled())
return;
1258 Log::MessageBuilder msg(log_);
1259 AppendCodeCreateHeader(msg, tag, AbstractCode::Kind::WASM_FUNCTION,
1260 code->instructions().start(),
1261 code->instructions().length(), &timer_);
1262 if (name.is_empty()) {
1263 msg <<
"<unknown wasm>";
1265 msg.AppendString(name);
1273 reinterpret_cast<byte*
>(code->native_module()) + code->index();
1274 msg << kNext << tag_ptr << kNext << ComputeMarker(code);
1275 msg.WriteToLogFile();
1281 void Logger::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag,
1282 AbstractCode code, SharedFunctionInfo* shared,
1283 Name source,
int line,
int column) {
1284 if (!is_listening_to_code_events())
return;
1285 if (!FLAG_log_code || !log_->IsEnabled())
return;
1287 Log::MessageBuilder msg(log_);
1288 AppendCodeCreateHeader(msg, tag, code, &timer_);
1289 msg << shared->DebugName() <<
" " << source <<
":" << line <<
":" << column
1290 << kNext << reinterpret_cast<void*>(shared->address()) << kNext
1291 << ComputeMarker(shared, code);
1292 msg.WriteToLogFile();
1295 if (!FLAG_log_source_code)
return;
1296 Object* script_object = shared->script();
1297 if (!script_object->IsScript())
return;
1298 Script* script = Script::cast(script_object);
1299 if (!EnsureLogScriptSource(script))
return;
1322 Log::MessageBuilder msg(log_);
1323 msg <<
"code-source-info" << kNext
1324 <<
reinterpret_cast<void*
>(code->InstructionStart()) << kNext
1325 << script->id() << kNext << shared->StartPosition() << kNext
1326 << shared->EndPosition() << kNext;
1328 SourcePositionTableIterator iterator(code->source_position_table());
1329 bool hasInlined =
false;
1330 for (; !iterator.done(); iterator.Advance()) {
1331 SourcePosition pos = iterator.source_position();
1332 msg <<
"C" << iterator.code_offset() <<
"O" << pos.ScriptOffset();
1333 if (pos.isInlined()) {
1334 msg <<
"I" << pos.InliningId();
1339 int maxInlinedId = -1;
1341 PodArray<InliningPosition> inlining_positions =
1342 DeoptimizationData::cast(Code::cast(code)->deoptimization_data())
1343 ->InliningPositions();
1344 for (
int i = 0;
i < inlining_positions->length();
i++) {
1345 InliningPosition inlining_pos = inlining_positions->get(
i);
1347 if (inlining_pos.inlined_function_id != -1) {
1348 msg << inlining_pos.inlined_function_id;
1349 if (inlining_pos.inlined_function_id > maxInlinedId) {
1350 maxInlinedId = inlining_pos.inlined_function_id;
1353 SourcePosition pos = inlining_pos.position;
1354 msg <<
"O" << pos.ScriptOffset();
1355 if (pos.isInlined()) {
1356 msg <<
"I" << pos.InliningId();
1362 DeoptimizationData deopt_data =
1363 DeoptimizationData::cast(Code::cast(code)->deoptimization_data());
1366 for (
int i = 0;
i <= maxInlinedId;
i++) {
1368 <<
reinterpret_cast<void*
>(
1369 deopt_data->GetInlinedFunction(
i)->address());
1373 msg.WriteToLogFile();
1376 void Logger::CodeDisableOptEvent(AbstractCode code,
1377 SharedFunctionInfo* shared) {
1378 if (!is_listening_to_code_events())
return;
1379 if (!FLAG_log_code || !log_->IsEnabled())
return;
1380 Log::MessageBuilder msg(log_);
1381 msg << kLogEventsNames[CodeEventListener::CODE_DISABLE_OPT_EVENT] << kNext
1382 << shared->DebugName() << kNext
1383 << GetBailoutReason(shared->disable_optimization_reason());
1384 msg.WriteToLogFile();
1387 void Logger::CodeMovingGCEvent() {
1388 if (!is_listening_to_code_events())
return;
1389 if (!log_->IsEnabled() || !FLAG_ll_prof)
return;
1390 base::OS::SignalCodeMovingGC();
1393 void Logger::RegExpCodeCreateEvent(AbstractCode code, String source) {
1394 if (!is_listening_to_code_events())
return;
1395 if (!FLAG_log_code || !log_->IsEnabled())
return;
1396 Log::MessageBuilder msg(log_);
1397 AppendCodeCreateHeader(msg, CodeEventListener::REG_EXP_TAG, code, &timer_);
1399 msg.WriteToLogFile();
1402 void Logger::CodeMoveEvent(AbstractCode from, AbstractCode to) {
1403 if (!is_listening_to_code_events())
return;
1404 MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(),
1410 void CodeLinePosEvent(JitLogger* jit_logger, Address code_start,
1411 SourcePositionTableIterator& iter) {
1413 void* jit_handler_data = jit_logger->StartCodePosInfoEvent();
1414 for (; !iter.done(); iter.Advance()) {
1415 if (iter.is_statement()) {
1416 jit_logger->AddCodeLinePosInfoEvent(
1417 jit_handler_data, iter.code_offset(),
1418 iter.source_position().ScriptOffset(),
1419 JitCodeEvent::STATEMENT_POSITION);
1421 jit_logger->AddCodeLinePosInfoEvent(jit_handler_data, iter.code_offset(),
1422 iter.source_position().ScriptOffset(),
1423 JitCodeEvent::POSITION);
1425 jit_logger->EndCodePosInfoEvent(code_start, jit_handler_data);
1431 void Logger::CodeLinePosInfoRecordEvent(Address code_start,
1432 ByteArray source_position_table) {
1433 SourcePositionTableIterator iter(source_position_table);
1434 CodeLinePosEvent(jit_logger_, code_start, iter);
1437 void Logger::CodeLinePosInfoRecordEvent(
1438 Address code_start, Vector<const byte> source_position_table) {
1439 SourcePositionTableIterator iter(source_position_table);
1440 CodeLinePosEvent(jit_logger_, code_start, iter);
1443 void Logger::CodeNameEvent(Address addr,
int pos,
const char* code_name) {
1444 if (code_name ==
nullptr)
return;
1445 Log::MessageBuilder msg(log_);
1446 msg << kLogEventsNames[CodeEventListener::SNAPSHOT_CODE_NAME_EVENT] << kNext
1447 << pos << kNext << code_name;
1448 msg.WriteToLogFile();
1452 void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
1453 if (!is_listening_to_code_events())
return;
1454 MoveEventInternal(CodeEventListener::SHARED_FUNC_MOVE_EVENT, from, to);
1457 void Logger::MoveEventInternal(CodeEventListener::LogEventsAndTags event,
1458 Address from, Address to) {
1459 if (!FLAG_log_code || !log_->IsEnabled())
return;
1460 Log::MessageBuilder msg(log_);
1461 msg << kLogEventsNames[event] << kNext << reinterpret_cast<void*>(from)
1462 << kNext << reinterpret_cast<void*>(to);
1463 msg.WriteToLogFile();
1467 void Logger::ResourceEvent(
const char* name,
const char* tag) {
1468 if (!log_->IsEnabled() || !FLAG_log)
return;
1469 Log::MessageBuilder msg(log_);
1470 msg << name << kNext << tag << kNext;
1473 if (base::OS::GetUserTime(&sec, &usec) != -1) {
1474 msg << sec << kNext << usec << kNext;
1476 msg.AppendFormatString(
"%.0f",
1477 V8::GetCurrentPlatform()->CurrentClockTimeMillis());
1478 msg.WriteToLogFile();
1481 void Logger::SuspectReadEvent(Name name, Object* obj) {
1482 if (!log_->IsEnabled() || !FLAG_log_suspect)
return;
1483 Log::MessageBuilder msg(log_);
1484 String class_name = obj->IsJSObject()
1485 ? JSObject::cast(obj)->class_name()
1486 : ReadOnlyRoots(isolate_).empty_string();
1487 msg <<
"suspect-read" << kNext << class_name << kNext << name;
1488 msg.WriteToLogFile();
1492 void AppendFunctionMessage(Log::MessageBuilder& msg,
const char* reason,
1493 int script_id,
double time_delta,
int start_position,
1494 int end_position, base::ElapsedTimer* timer) {
1495 msg <<
"function" << Logger::kNext << reason << Logger::kNext << script_id
1496 << Logger::kNext << start_position << Logger::kNext << end_position
1497 << Logger::kNext << time_delta << Logger::kNext
1498 << timer->Elapsed().InMicroseconds() << Logger::kNext;
1502 void Logger::FunctionEvent(
const char* reason,
int script_id,
double time_delta,
1503 int start_position,
int end_position,
1504 String function_name) {
1505 if (!log_->IsEnabled() || !FLAG_log_function_events)
return;
1506 Log::MessageBuilder msg(log_);
1507 AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
1508 end_position, &timer_);
1509 if (!function_name.is_null()) msg << function_name;
1510 msg.WriteToLogFile();
1513 void Logger::FunctionEvent(
const char* reason,
int script_id,
double time_delta,
1514 int start_position,
int end_position,
1515 const char* function_name,
1516 size_t function_name_length) {
1517 if (!log_->IsEnabled() || !FLAG_log_function_events)
return;
1518 Log::MessageBuilder msg(log_);
1519 AppendFunctionMessage(msg, reason, script_id, time_delta, start_position,
1520 end_position, &timer_);
1521 if (function_name_length > 0) {
1522 msg.AppendString(function_name, function_name_length);
1524 msg.WriteToLogFile();
1527 void Logger::CompilationCacheEvent(
const char* action,
const char* cache_type,
1528 SharedFunctionInfo* sfi) {
1529 if (!log_->IsEnabled() || !FLAG_log_function_events)
return;
1530 Log::MessageBuilder msg(log_);
1532 if (sfi->script()->IsScript()) {
1533 script_id = Script::cast(sfi->script())->
id();
1535 msg <<
"compilation-cache" << Logger::kNext << action << Logger::kNext
1536 << cache_type << Logger::kNext << script_id << Logger::kNext
1537 << sfi->StartPosition() << Logger::kNext << sfi->EndPosition()
1538 << Logger::kNext << timer_.Elapsed().InMicroseconds();
1539 msg.WriteToLogFile();
1542 void Logger::ScriptEvent(ScriptEventType type,
int script_id) {
1543 if (!log_->IsEnabled() || !FLAG_log_function_events)
return;
1544 Log::MessageBuilder msg(log_);
1545 msg <<
"script" << Logger::kNext;
1547 case ScriptEventType::kReserveId:
1548 msg <<
"reserve-id";
1550 case ScriptEventType::kCreate:
1553 case ScriptEventType::kDeserialize:
1554 msg <<
"deserialize";
1556 case ScriptEventType::kBackgroundCompile:
1557 msg <<
"background-compile";
1559 case ScriptEventType::kStreamingCompile:
1560 msg <<
"streaming-compile";
1563 msg << Logger::kNext << script_id << Logger::kNext
1564 << timer_.Elapsed().InMicroseconds();
1565 msg.WriteToLogFile();
1568 void Logger::ScriptDetails(Script* script) {
1569 if (!log_->IsEnabled() || !FLAG_log_function_events)
return;
1571 Log::MessageBuilder msg(log_);
1572 msg <<
"script-details" << Logger::kNext << script->id() << Logger::kNext;
1573 if (script->name()->IsString()) {
1574 msg << String::cast(script->name());
1576 msg << Logger::kNext << script->line_offset() << Logger::kNext
1577 << script->column_offset() << Logger::kNext;
1578 if (script->source_mapping_url()->IsString()) {
1579 msg << String::cast(script->source_mapping_url());
1581 msg.WriteToLogFile();
1583 EnsureLogScriptSource(script);
1586 bool Logger::EnsureLogScriptSource(Script* script) {
1587 if (!log_->IsEnabled())
return false;
1588 Log::MessageBuilder msg(log_);
1590 int script_id = script->id();
1591 if (logged_source_code_.find(script_id) != logged_source_code_.end()) {
1595 logged_source_code_.insert(script_id);
1596 Object* source_object = script->source();
1597 if (!source_object->IsString())
return false;
1598 String source_code = String::cast(source_object);
1599 msg <<
"script-source" << kNext << script_id << kNext;
1602 if (script->name()->IsString()) {
1603 msg << String::cast(script->name()) << kNext;
1605 msg <<
"<unknown>" << kNext;
1610 msg.WriteToLogFile();
1614 void Logger::RuntimeCallTimerEvent() {
1615 RuntimeCallStats* stats = isolate_->counters()->runtime_call_stats();
1616 RuntimeCallCounter* counter = stats->current_counter();
1617 if (counter ==
nullptr)
return;
1618 Log::MessageBuilder msg(log_);
1619 msg <<
"active-runtime-timer" << kNext << counter->name();
1620 msg.WriteToLogFile();
1624 if (!log_->IsEnabled() || !FLAG_prof_cpp)
return;
1625 if (V8_UNLIKELY(FLAG_runtime_stats ==
1626 v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE)) {
1627 RuntimeCallTimerEvent();
1629 Log::MessageBuilder msg(log_);
1630 msg << kLogEventsNames[CodeEventListener::TICK_EVENT] << kNext
1631 <<
reinterpret_cast<void*
>(sample->pc) << kNext
1632 << timer_.Elapsed().InMicroseconds();
1633 if (sample->has_external_callback) {
1634 msg << kNext << 1 << kNext
1635 <<
reinterpret_cast<void*
>(sample->external_callback_entry);
1637 msg << kNext << 0 << kNext << reinterpret_cast<void*>(sample->tos);
1639 msg << kNext << static_cast<int>(sample->state);
1640 if (overflow) msg << kNext <<
"overflow";
1641 for (
unsigned i = 0;
i < sample->frames_count; ++
i) {
1642 msg << kNext << reinterpret_cast<void*>(sample->stack[
i]);
1644 msg.WriteToLogFile();
1647 void Logger::ICEvent(
const char* type,
bool keyed, Map map, Object* key,
1648 char old_state,
char new_state,
const char* modifier,
1649 const char* slow_stub_reason) {
1650 if (!log_->IsEnabled() || !FLAG_trace_ic)
return;
1651 Log::MessageBuilder msg(log_);
1652 if (keyed) msg <<
"Keyed";
1655 Address pc = isolate_->GetAbstractPC(&line, &column);
1656 msg << type << kNext << reinterpret_cast<void*>(pc) << kNext << line << kNext
1657 << column << kNext << old_state << kNext << new_state << kNext
1658 << reinterpret_cast<void*>(map.ptr()) << kNext;
1660 msg << Smi::ToInt(key);
1661 }
else if (key->IsNumber()) {
1662 msg << key->Number();
1663 }
else if (key->IsName()) {
1664 msg << Name::cast(key);
1666 msg << kNext << modifier << kNext;
1667 if (slow_stub_reason !=
nullptr) {
1668 msg << slow_stub_reason;
1670 msg.WriteToLogFile();
1673 void Logger::MapEvent(
const char* type, Map from, Map to,
const char* reason,
1674 HeapObject* name_or_sfi) {
1675 DisallowHeapAllocation no_gc;
1676 if (!log_->IsEnabled() || !FLAG_trace_maps)
return;
1677 if (!to.is_null()) MapDetails(to);
1682 if (!isolate_->bootstrapper()->IsActive()) {
1683 pc = isolate_->GetAbstractPC(&line, &column);
1685 Log::MessageBuilder msg(log_);
1686 msg <<
"map" << kNext << type << kNext << timer_.Elapsed().InMicroseconds()
1687 << kNext << reinterpret_cast<void*>(from.ptr()) << kNext
1688 << reinterpret_cast<void*>(to.ptr()) << kNext
1689 << reinterpret_cast<void*>(pc) << kNext << line << kNext << column
1690 << kNext << reason << kNext;
1693 if (name_or_sfi->IsName()) {
1694 msg << Name::cast(name_or_sfi);
1695 }
else if (name_or_sfi->IsSharedFunctionInfo()) {
1696 SharedFunctionInfo* sfi = SharedFunctionInfo::cast(name_or_sfi);
1697 msg << sfi->DebugName();
1698 #if V8_SFI_HAS_UNIQUE_ID 1699 msg <<
" " << sfi->unique_id();
1700 #endif // V8_SFI_HAS_UNIQUE_ID 1703 msg.WriteToLogFile();
1706 void Logger::MapCreate(Map map) {
1707 if (!log_->IsEnabled() || !FLAG_trace_maps)
return;
1708 DisallowHeapAllocation no_gc;
1709 Log::MessageBuilder msg(log_);
1710 msg <<
"map-create" << kNext << timer_.Elapsed().InMicroseconds() << kNext
1711 <<
reinterpret_cast<void*
>(map.ptr());
1712 msg.WriteToLogFile();
1715 void Logger::MapDetails(Map map) {
1716 if (!log_->IsEnabled() || !FLAG_trace_maps)
return;
1717 DisallowHeapAllocation no_gc;
1718 Log::MessageBuilder msg(log_);
1719 msg <<
"map-details" << kNext << timer_.Elapsed().InMicroseconds() << kNext
1720 <<
reinterpret_cast<void*
>(map.ptr()) << kNext;
1721 if (FLAG_trace_maps_details) {
1722 std::ostringstream buffer;
1723 map->PrintMapDetails(buffer);
1724 msg << buffer.str().c_str();
1726 msg.WriteToLogFile();
1729 void Logger::StopProfiler() {
1730 if (!log_->IsEnabled())
return;
1731 if (profiler_ !=
nullptr) {
1733 is_logging_ =
false;
1734 RemoveCodeEventListener(
this);
1740 void Logger::LogFailure() {
1744 static void AddFunctionAndCode(SharedFunctionInfo* sfi,
1745 AbstractCode code_object,
1746 Handle<SharedFunctionInfo>* sfis,
1747 Handle<AbstractCode>* code_objects,
int offset) {
1748 if (sfis !=
nullptr) {
1749 sfis[offset] = Handle<SharedFunctionInfo>(sfi, sfi->GetIsolate());
1751 if (code_objects !=
nullptr) {
1752 code_objects[offset] = Handle<AbstractCode>(code_object, sfi->GetIsolate());
1756 static int EnumerateCompiledFunctions(Heap* heap,
1757 Handle<SharedFunctionInfo>* sfis,
1758 Handle<AbstractCode>* code_objects) {
1759 HeapIterator iterator(heap);
1760 DisallowHeapAllocation no_gc;
1761 int compiled_funcs_count = 0;
1765 for (HeapObject* obj = iterator.next(); obj !=
nullptr;
1766 obj = iterator.next()) {
1767 if (obj->IsSharedFunctionInfo()) {
1768 SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
1769 if (sfi->is_compiled() &&
1770 (!sfi->script()->IsScript() ||
1771 Script::cast(sfi->script())->HasValidSource())) {
1772 AddFunctionAndCode(sfi, AbstractCode::cast(sfi->abstract_code()), sfis,
1773 code_objects, compiled_funcs_count);
1774 ++compiled_funcs_count;
1776 }
else if (obj->IsJSFunction()) {
1779 JSFunction*
function = JSFunction::cast(obj);
1780 SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
1781 Object* maybe_script = sfi->script();
1782 if (maybe_script->IsScript() &&
1783 !Script::cast(maybe_script)->HasValidSource()) {
1789 if (function->IsOptimized()) {
1790 AddFunctionAndCode(sfi, AbstractCode::cast(function->code()), sfis,
1791 code_objects, compiled_funcs_count);
1792 ++compiled_funcs_count;
1796 return compiled_funcs_count;
1799 static int EnumerateWasmModuleObjects(
1800 Heap* heap, Handle<WasmModuleObject>* module_objects) {
1801 HeapIterator iterator(heap);
1802 DisallowHeapAllocation no_gc;
1803 int module_objects_count = 0;
1805 for (HeapObject* obj = iterator.next(); obj !=
nullptr;
1806 obj = iterator.next()) {
1807 if (obj->IsWasmModuleObject()) {
1808 WasmModuleObject* module = WasmModuleObject::cast(obj);
1809 if (module_objects !=
nullptr) {
1810 module_objects[module_objects_count] = handle(module, heap->isolate());
1812 module_objects_count++;
1815 return module_objects_count;
1818 void Logger::LogCodeObject(Object*
object) {
1819 existing_code_logger_.LogCodeObject(
object);
1822 void Logger::LogCodeObjects() { existing_code_logger_.LogCodeObjects(); }
1824 void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
1825 Handle<AbstractCode> code) {
1826 existing_code_logger_.LogExistingFunction(shared, code);
1829 void Logger::LogCompiledFunctions() {
1830 existing_code_logger_.LogCompiledFunctions();
1833 void Logger::LogAccessorCallbacks() {
1834 Heap* heap = isolate_->heap();
1835 HeapIterator iterator(heap);
1836 DisallowHeapAllocation no_gc;
1837 for (HeapObject* obj = iterator.next(); obj !=
nullptr;
1838 obj = iterator.next()) {
1839 if (!obj->IsAccessorInfo())
continue;
1840 AccessorInfo* ai = AccessorInfo::cast(obj);
1841 if (!ai->name()->IsName())
continue;
1842 Address getter_entry = v8::ToCData<Address>(ai->getter());
1843 Name name = Name::cast(ai->name());
1844 if (getter_entry != 0) {
1845 #if USES_FUNCTION_DESCRIPTORS 1846 getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(getter_entry);
1848 PROFILE(isolate_, GetterCallbackEvent(name, getter_entry));
1850 Address setter_entry = v8::ToCData<Address>(ai->setter());
1851 if (setter_entry != 0) {
1852 #if USES_FUNCTION_DESCRIPTORS 1853 setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(setter_entry);
1855 PROFILE(isolate_, SetterCallbackEvent(name, setter_entry));
1860 void Logger::LogAllMaps() {
1861 DisallowHeapAllocation no_gc;
1862 Heap* heap = isolate_->heap();
1863 HeapIterator iterator(heap);
1864 for (HeapObject* obj = iterator.next(); obj !=
nullptr;
1865 obj = iterator.next()) {
1866 if (!obj->IsMap())
continue;
1867 Map map = Map::cast(obj);
1873 static void AddIsolateIdIfNeeded(std::ostream& os,
1875 if (FLAG_logfile_per_isolate) os <<
"isolate-" << isolate <<
"-";
1879 static void PrepareLogFileName(std::ostream& os,
1880 Isolate* isolate,
const char* file_name) {
1881 int dir_separator_count = 0;
1882 for (
const char* p = file_name; *p; p++) {
1883 if (base::OS::isDirectorySeparator(*p)) dir_separator_count++;
1886 for (
const char* p = file_name; *p; p++) {
1887 if (dir_separator_count == 0) {
1888 AddIsolateIdIfNeeded(os, isolate);
1889 dir_separator_count--;
1900 os << base::OS::GetCurrentProcessId();
1904 os << static_cast<int64_t>(
1905 V8::GetCurrentPlatform()->CurrentClockTimeMillis());
1917 if (base::OS::isDirectorySeparator(*p)) dir_separator_count--;
1924 bool Logger::SetUp(Isolate* isolate) {
1926 if (is_initialized_)
return true;
1927 is_initialized_ =
true;
1929 std::ostringstream log_file_name;
1930 std::ostringstream source_log_file_name;
1931 PrepareLogFileName(log_file_name, isolate, FLAG_logfile);
1932 log_ =
new Log(
this, log_file_name.str().c_str());
1934 if (FLAG_perf_basic_prof) {
1935 perf_basic_logger_ =
new PerfBasicLogger(isolate);
1936 AddCodeEventListener(perf_basic_logger_);
1939 if (FLAG_perf_prof) {
1940 perf_jit_logger_ =
new PerfJitLogger(isolate);
1941 AddCodeEventListener(perf_jit_logger_);
1945 ll_logger_ =
new LowLevelLogger(isolate, log_file_name.str().c_str());
1946 AddCodeEventListener(ll_logger_);
1949 ticker_ =
new Ticker(isolate, FLAG_prof_sampling_interval);
1951 if (Log::InitLogAtStart()) {
1957 if (FLAG_prof_cpp) {
1958 profiler_ =
new Profiler(isolate);
1960 profiler_->Engage();
1964 AddCodeEventListener(
this);
1971 void Logger::SetCodeEventHandler(
uint32_t options,
1972 JitCodeEventHandler event_handler) {
1974 RemoveCodeEventListener(jit_logger_);
1976 jit_logger_ =
nullptr;
1979 if (event_handler) {
1980 jit_logger_ =
new JitLogger(isolate_, event_handler);
1981 AddCodeEventListener(jit_logger_);
1982 if (options & kJitCodeEventEnumExisting) {
1983 HandleScope scope(isolate_);
1985 LogCompiledFunctions();
1990 sampler::Sampler* Logger::sampler() {
1994 void Logger::StopProfilerThread() {
1995 if (profiler_ !=
nullptr) {
1996 profiler_->Disengage();
1998 profiler_ =
nullptr;
2002 FILE* Logger::TearDown() {
2003 if (!is_initialized_)
return nullptr;
2004 is_initialized_ =
false;
2007 StopProfilerThread();
2012 if (perf_basic_logger_) {
2013 RemoveCodeEventListener(perf_basic_logger_);
2014 delete perf_basic_logger_;
2015 perf_basic_logger_ =
nullptr;
2018 if (perf_jit_logger_) {
2019 RemoveCodeEventListener(perf_jit_logger_);
2020 delete perf_jit_logger_;
2021 perf_jit_logger_ =
nullptr;
2025 RemoveCodeEventListener(ll_logger_);
2027 ll_logger_ =
nullptr;
2031 RemoveCodeEventListener(jit_logger_);
2033 jit_logger_ =
nullptr;
2036 return log_->Close();
2039 void ExistingCodeLogger::LogCodeObject(Object*
object) {
2040 AbstractCode abstract_code = AbstractCode::cast(
object);
2041 CodeEventListener::LogEventsAndTags tag = CodeEventListener::STUB_TAG;
2042 const char* description =
"Unknown code from before profiling";
2043 switch (abstract_code->kind()) {
2044 case AbstractCode::INTERPRETED_FUNCTION:
2045 case AbstractCode::OPTIMIZED_FUNCTION:
2047 case AbstractCode::BYTECODE_HANDLER:
2049 case AbstractCode::STUB:
2051 CodeStub::MajorName(CodeStub::GetMajorKey(abstract_code->GetCode()));
2052 if (description ==
nullptr) description =
"A stub from before profiling";
2053 tag = CodeEventListener::STUB_TAG;
2055 case AbstractCode::REGEXP:
2056 description =
"Regular expression code";
2057 tag = CodeEventListener::REG_EXP_TAG;
2059 case AbstractCode::BUILTIN:
2060 if (Code::cast(
object)->is_interpreter_trampoline_builtin() &&
2061 Code::cast(
object) !=
2062 *BUILTIN_CODE(isolate_, InterpreterEntryTrampoline)) {
2066 isolate_->builtins()->name(abstract_code->GetCode()->builtin_index());
2067 tag = CodeEventListener::BUILTIN_TAG;
2069 case AbstractCode::WASM_FUNCTION:
2070 description =
"A Wasm function";
2071 tag = CodeEventListener::FUNCTION_TAG;
2073 case AbstractCode::JS_TO_WASM_FUNCTION:
2074 description =
"A JavaScript to Wasm adapter";
2075 tag = CodeEventListener::STUB_TAG;
2077 case AbstractCode::WASM_TO_JS_FUNCTION:
2078 description =
"A Wasm to JavaScript adapter";
2079 tag = CodeEventListener::STUB_TAG;
2081 case AbstractCode::WASM_INTERPRETER_ENTRY:
2082 description =
"A Wasm to Interpreter adapter";
2083 tag = CodeEventListener::STUB_TAG;
2085 case AbstractCode::C_WASM_ENTRY:
2086 description =
"A C to Wasm entry stub";
2087 tag = CodeEventListener::STUB_TAG;
2089 case AbstractCode::NUMBER_OF_KINDS:
2092 CALL_CODE_EVENT_HANDLER(CodeCreateEvent(tag, abstract_code, description))
2095 void ExistingCodeLogger::LogCodeObjects() {
2096 Heap* heap = isolate_->heap();
2097 HeapIterator iterator(heap);
2098 DisallowHeapAllocation no_gc;
2099 for (HeapObject* obj = iterator.next(); obj !=
nullptr;
2100 obj = iterator.next()) {
2101 if (obj->IsCode()) LogCodeObject(obj);
2102 if (obj->IsBytecodeArray()) LogCodeObject(obj);
2106 void ExistingCodeLogger::LogCompiledFunctions() {
2107 Heap* heap = isolate_->heap();
2108 HandleScope scope(isolate_);
2109 const int compiled_funcs_count =
2110 EnumerateCompiledFunctions(heap,
nullptr,
nullptr);
2111 ScopedVector<Handle<SharedFunctionInfo>> sfis(compiled_funcs_count);
2112 ScopedVector<Handle<AbstractCode>> code_objects(compiled_funcs_count);
2113 EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
2117 for (
int i = 0;
i < compiled_funcs_count; ++
i) {
2118 if (sfis[
i]->function_data()->IsInterpreterData()) {
2119 LogExistingFunction(
2121 Handle<AbstractCode>(
2122 AbstractCode::cast(sfis[
i]->InterpreterTrampoline()), isolate_),
2123 CodeEventListener::INTERPRETED_FUNCTION_TAG);
2125 if (code_objects[
i].is_identical_to(BUILTIN_CODE(isolate_, CompileLazy)))
2127 LogExistingFunction(sfis[
i], code_objects[
i]);
2130 const int wasm_module_objects_count =
2131 EnumerateWasmModuleObjects(heap,
nullptr);
2132 std::unique_ptr<Handle<WasmModuleObject>[]> module_objects(
2133 new Handle<WasmModuleObject>[wasm_module_objects_count]);
2134 EnumerateWasmModuleObjects(heap, module_objects.get());
2135 for (
int i = 0;
i < wasm_module_objects_count; ++
i) {
2136 module_objects[
i]->native_module()->LogWasmCodes(isolate_);
2140 void ExistingCodeLogger::LogExistingFunction(
2141 Handle<SharedFunctionInfo> shared, Handle<AbstractCode> code,
2142 CodeEventListener::LogEventsAndTags tag) {
2143 if (shared->script()->IsScript()) {
2144 Handle<Script> script(Script::cast(shared->script()), isolate_);
2145 int line_num = Script::GetLineNumber(script, shared->StartPosition()) + 1;
2147 Script::GetColumnNumber(script, shared->StartPosition()) + 1;
2148 if (script->name()->IsString()) {
2149 Handle<String> script_name(String::cast(script->name()), isolate_);
2151 CALL_CODE_EVENT_HANDLER(
2152 CodeCreateEvent(Logger::ToNativeByScript(tag, *script), *code,
2153 *shared, *script_name, line_num, column_num))
2156 CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
2157 Logger::ToNativeByScript(CodeEventListener::SCRIPT_TAG, *script),
2158 *code, *shared, *script_name))
2161 CALL_CODE_EVENT_HANDLER(CodeCreateEvent(
2162 Logger::ToNativeByScript(tag, *script), *code, *shared,
2163 ReadOnlyRoots(isolate_).empty_string(), line_num, column_num))
2165 }
else if (shared->IsApiFunction()) {
2167 FunctionTemplateInfo* fun_data = shared->get_api_func_data();
2168 Object* raw_call_data = fun_data->call_code();
2169 if (!raw_call_data->IsUndefined(isolate_)) {
2170 CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
2171 Object* callback_obj = call_data->callback();
2172 Address entry_point = v8::ToCData<Address>(callback_obj);
2173 #if USES_FUNCTION_DESCRIPTORS 2174 entry_point = *FUNCTION_ENTRYPOINT_ADDRESS(entry_point);
2176 CALL_CODE_EVENT_HANDLER(CallbackEvent(shared->DebugName(), entry_point))
2181 #undef CALL_CODE_EVENT_HANDLER