From a5c0bc44acd6edbb4110b08d555aa16bbfda0a5e Mon Sep 17 00:00:00 2001 From: Peter Marshall Date: Mon, 30 Jul 2018 13:54:55 +0200 Subject: [PATCH] deps: backport 4 CPU profiler commits from upstream V8 [cpu-profiler] Add a new profiling mode with a more detailed call tree. https://chromium.googlesource.com/v8/v8.git/+/ecae80cdb350dde1e654c531b56f5b6c44dc8c77 [cpu-profiler] Reuse free slots in code_entries_ https://chromium.googlesource.com/v8/v8.git/+/3e1126bf15e62c433c4e9cb21316d182f691c63a [cpu-profiler] Only store deopt inline frames for functions that need it https://chromium.googlesource.com/v8/v8.git/+/0bfcbdd4726920755e51dab28c18ab93e050819b [cpu-profiler] Use instruction start as the key for the CodeMap https://chromium.googlesource.com/v8/v8.git/+/ba752ea4c50713dff1e94f45a79db3ba968a8d66 PR-URL: https://github.com/nodejs/node/pull/22028 Reviewed-By: Ruben Bridgewater Reviewed-By: Benedikt Meurer --- common.gypi | 2 +- deps/v8/include/v8-profiler.h | 17 ++ deps/v8/src/api.cc | 9 +- deps/v8/src/code-events.h | 4 +- deps/v8/src/heap/mark-compact.cc | 2 +- deps/v8/src/log.cc | 25 +-- deps/v8/src/log.h | 4 +- deps/v8/src/perf-jit.cc | 2 +- deps/v8/src/perf-jit.h | 4 +- deps/v8/src/profiler/cpu-profiler-inl.h | 16 +- deps/v8/src/profiler/cpu-profiler.cc | 14 +- deps/v8/src/profiler/cpu-profiler.h | 23 +- deps/v8/src/profiler/profile-generator-inl.h | 3 +- deps/v8/src/profiler/profile-generator.cc | 210 ++++++++++++------ deps/v8/src/profiler/profile-generator.h | 97 +++++--- deps/v8/src/profiler/profiler-listener.cc | 88 ++++---- deps/v8/src/profiler/profiler-listener.h | 5 +- deps/v8/src/snapshot/serializer.h | 4 +- deps/v8/test/cctest/cctest.status | 1 + deps/v8/test/cctest/test-cpu-profiler.cc | 98 ++++++-- deps/v8/test/cctest/test-profile-generator.cc | 45 +++- 21 files changed, 469 insertions(+), 204 deletions(-) diff --git a/common.gypi b/common.gypi index fcfdbfef28188a..a085594786e46f 100644 --- a/common.gypi +++ b/common.gypi @@ -29,7 +29,7 @@ # Reset this number to 0 on major V8 upgrades. # Increment by one for each non-official patch applied to deps/v8. - 'v8_embedder_string': '-node.22', + 'v8_embedder_string': '-node.23', # Enable disassembler for `--print-code` v8 options 'v8_enable_disassembler': 1, diff --git a/deps/v8/include/v8-profiler.h b/deps/v8/include/v8-profiler.h index c61027b3b94e45..0ee9000a51c666 100644 --- a/deps/v8/include/v8-profiler.h +++ b/deps/v8/include/v8-profiler.h @@ -273,6 +273,16 @@ class V8_EXPORT CpuProfile { void Delete(); }; +enum CpuProfilingMode { + // In the resulting CpuProfile tree, intermediate nodes in a stack trace + // (from the root to a leaf) will have line numbers that point to the start + // line of the function, rather than the line of the callsite of the child. + kLeafNodeLineNumbers, + // In the resulting CpuProfile tree, nodes are separated based on the line + // number of their callsite in their parent. + kCallerLineNumbers, +}; + /** * Interface for controlling CPU profiling. Instance of the * profiler can be created using v8::CpuProfiler::New method. @@ -316,6 +326,13 @@ class V8_EXPORT CpuProfiler { * |record_samples| parameter controls whether individual samples should * be recorded in addition to the aggregated tree. */ + void StartProfiling(Local title, CpuProfilingMode mode, + bool record_samples = false); + /** + * The same as StartProfiling above, but the CpuProfilingMode defaults to + * kLeafNodeLineNumbers mode, which was the previous default behavior of the + * profiler. + */ void StartProfiling(Local title, bool record_samples = false); /** diff --git a/deps/v8/src/api.cc b/deps/v8/src/api.cc index 83a2fbc8ea459c..6799af22f99f9e 100644 --- a/deps/v8/src/api.cc +++ b/deps/v8/src/api.cc @@ -10005,7 +10005,7 @@ const char* CpuProfileNode::GetScriptResourceNameStr() const { } int CpuProfileNode::GetLineNumber() const { - return reinterpret_cast(this)->entry()->line_number(); + return reinterpret_cast(this)->line_number(); } @@ -10143,9 +10143,14 @@ void CpuProfiler::CollectSample() { void CpuProfiler::StartProfiling(Local title, bool record_samples) { reinterpret_cast(this)->StartProfiling( - *Utils::OpenHandle(*title), record_samples); + *Utils::OpenHandle(*title), record_samples, kLeafNodeLineNumbers); } +void CpuProfiler::StartProfiling(Local title, CpuProfilingMode mode, + bool record_samples) { + reinterpret_cast(this)->StartProfiling( + *Utils::OpenHandle(*title), record_samples, mode); +} CpuProfile* CpuProfiler::StopProfiling(Local title) { return reinterpret_cast( diff --git a/deps/v8/src/code-events.h b/deps/v8/src/code-events.h index caed5160f47a24..51946289124a8b 100644 --- a/deps/v8/src/code-events.h +++ b/deps/v8/src/code-events.h @@ -83,7 +83,7 @@ class CodeEventListener { virtual void GetterCallbackEvent(Name* name, Address entry_point) = 0; virtual void SetterCallbackEvent(Name* name, Address entry_point) = 0; virtual void RegExpCodeCreateEvent(AbstractCode* code, String* source) = 0; - virtual void CodeMoveEvent(AbstractCode* from, Address to) = 0; + virtual void CodeMoveEvent(AbstractCode* from, AbstractCode* to) = 0; virtual void SharedFunctionInfoMoveEvent(Address from, Address to) = 0; virtual void CodeMovingGCEvent() = 0; virtual void CodeDisableOptEvent(AbstractCode* code, @@ -155,7 +155,7 @@ class CodeEventDispatcher { void RegExpCodeCreateEvent(AbstractCode* code, String* source) { CODE_EVENT_DISPATCH(RegExpCodeCreateEvent(code, source)); } - void CodeMoveEvent(AbstractCode* from, Address to) { + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) { CODE_EVENT_DISPATCH(CodeMoveEvent(from, to)); } void SharedFunctionInfoMoveEvent(Address from, Address to) { diff --git a/deps/v8/src/heap/mark-compact.cc b/deps/v8/src/heap/mark-compact.cc index 66575f8250070d..e69551f70e4055 100644 --- a/deps/v8/src/heap/mark-compact.cc +++ b/deps/v8/src/heap/mark-compact.cc @@ -1136,7 +1136,7 @@ class ProfilingMigrationObserver final : public MigrationObserver { int size) final { if (dest == CODE_SPACE || (dest == OLD_SPACE && dst->IsBytecodeArray())) { PROFILE(heap_->isolate(), - CodeMoveEvent(AbstractCode::cast(src), dst->address())); + CodeMoveEvent(AbstractCode::cast(src), AbstractCode::cast(dst))); } heap_->OnMoveEvent(dst, src, size); } diff --git a/deps/v8/src/log.cc b/deps/v8/src/log.cc index fb3b4761a34e78..da9e126879f21a 100644 --- a/deps/v8/src/log.cc +++ b/deps/v8/src/log.cc @@ -270,7 +270,7 @@ class PerfBasicLogger : public CodeEventLogger { PerfBasicLogger(); ~PerfBasicLogger() override; - void CodeMoveEvent(AbstractCode* from, Address to) override {} + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override {} void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared) override {} @@ -492,7 +492,7 @@ class LowLevelLogger : public CodeEventLogger { explicit LowLevelLogger(const char* file_name); ~LowLevelLogger() override; - void CodeMoveEvent(AbstractCode* from, Address to) override; + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override; void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared) override {} void SnapshotPositionEvent(HeapObject* obj, int pos); @@ -610,11 +610,10 @@ void LowLevelLogger::LogRecordedBuffer(const wasm::WasmCode* code, code->instructions().length()); } -void LowLevelLogger::CodeMoveEvent(AbstractCode* from, Address to) { +void LowLevelLogger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) { CodeMoveStruct event; event.from_address = from->InstructionStart(); - size_t header_size = from->InstructionStart() - from->address(); - event.to_address = to + header_size; + event.to_address = to->InstructionStart(); LogWriteStruct(event); } @@ -636,7 +635,7 @@ class JitLogger : public CodeEventLogger { public: explicit JitLogger(JitCodeEventHandler code_event_handler); - void CodeMoveEvent(AbstractCode* from, Address to) override; + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override; void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared) override {} void AddCodeLinePosInfoEvent(void* jit_handler_data, int pc_offset, @@ -694,7 +693,7 @@ void JitLogger::LogRecordedBuffer(const wasm::WasmCode* code, const char* name, code_event_handler_(&event); } -void JitLogger::CodeMoveEvent(AbstractCode* from, Address to) { +void JitLogger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) { base::LockGuard guard(&logger_mutex_); JitCodeEvent event; @@ -703,12 +702,7 @@ void JitLogger::CodeMoveEvent(AbstractCode* from, Address to) { from->IsCode() ? JitCodeEvent::JIT_CODE : JitCodeEvent::BYTE_CODE; event.code_start = reinterpret_cast(from->InstructionStart()); event.code_len = from->InstructionSize(); - - // Calculate the header size. - const size_t header_size = from->InstructionStart() - from->address(); - - // Calculate the new start address of the instructions. - event.new_code_start = reinterpret_cast(to + header_size); + event.new_code_start = reinterpret_cast(to->InstructionStart()); code_event_handler_(&event); } @@ -1450,9 +1444,10 @@ void Logger::RegExpCodeCreateEvent(AbstractCode* code, String* source) { msg.WriteToLogFile(); } -void Logger::CodeMoveEvent(AbstractCode* from, Address to) { +void Logger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) { if (!is_listening_to_code_events()) return; - MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(), to); + MoveEventInternal(CodeEventListener::CODE_MOVE_EVENT, from->address(), + to->address()); } namespace { diff --git a/deps/v8/src/log.h b/deps/v8/src/log.h index ad254097e6659c..35f668855960b2 100644 --- a/deps/v8/src/log.h +++ b/deps/v8/src/log.h @@ -209,7 +209,7 @@ class Logger : public CodeEventListener { // Emits a code create event for a RegExp. void RegExpCodeCreateEvent(AbstractCode* code, String* source); // Emits a code move event. - void CodeMoveEvent(AbstractCode* from, Address to); + void CodeMoveEvent(AbstractCode* from, AbstractCode* to); // Emits a code line info record event. void CodeLinePosInfoRecordEvent(Address code_start, ByteArray* source_position_table); @@ -466,7 +466,7 @@ class ExternalCodeEventListener : public CodeEventListener { void GetterCallbackEvent(Name* name, Address entry_point) override {} void SetterCallbackEvent(Name* name, Address entry_point) override {} void SharedFunctionInfoMoveEvent(Address from, Address to) override {} - void CodeMoveEvent(AbstractCode* from, Address to) override {} + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override {} void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared) override {} void CodeMovingGCEvent() override {} diff --git a/deps/v8/src/perf-jit.cc b/deps/v8/src/perf-jit.cc index b20af564bb200d..dfccb293d186fe 100644 --- a/deps/v8/src/perf-jit.cc +++ b/deps/v8/src/perf-jit.cc @@ -419,7 +419,7 @@ void PerfJitLogger::LogWriteUnwindingInfo(Code* code) { LogWriteBytes(padding_bytes, static_cast(padding_size)); } -void PerfJitLogger::CodeMoveEvent(AbstractCode* from, Address to) { +void PerfJitLogger::CodeMoveEvent(AbstractCode* from, AbstractCode* to) { // We may receive a CodeMove event if a BytecodeArray object moves. Otherwise // code relocation is not supported. CHECK(from->IsBytecodeArray()); diff --git a/deps/v8/src/perf-jit.h b/deps/v8/src/perf-jit.h index ef83e9423d1987..bbcc79dd1c4a65 100644 --- a/deps/v8/src/perf-jit.h +++ b/deps/v8/src/perf-jit.h @@ -41,7 +41,7 @@ class PerfJitLogger : public CodeEventLogger { PerfJitLogger(); virtual ~PerfJitLogger(); - void CodeMoveEvent(AbstractCode* from, Address to) override; + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override; void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared) override {} @@ -118,7 +118,7 @@ class PerfJitLogger : public CodeEventLogger { // PerfJitLogger is only implemented on Linux class PerfJitLogger : public CodeEventLogger { public: - void CodeMoveEvent(AbstractCode* from, Address to) override { + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override { UNIMPLEMENTED(); } diff --git a/deps/v8/src/profiler/cpu-profiler-inl.h b/deps/v8/src/profiler/cpu-profiler-inl.h index 3bc6541048b2d8..d8603c81685ae1 100644 --- a/deps/v8/src/profiler/cpu-profiler-inl.h +++ b/deps/v8/src/profiler/cpu-profiler-inl.h @@ -16,17 +16,17 @@ namespace v8 { namespace internal { void CodeCreateEventRecord::UpdateCodeMap(CodeMap* code_map) { - code_map->AddCode(start, entry, size); + code_map->AddCode(instruction_start, entry, instruction_size); } void CodeMoveEventRecord::UpdateCodeMap(CodeMap* code_map) { - code_map->MoveCode(from, to); + code_map->MoveCode(from_instruction_start, to_instruction_start); } void CodeDisableOptEventRecord::UpdateCodeMap(CodeMap* code_map) { - CodeEntry* entry = code_map->FindEntry(start); + CodeEntry* entry = code_map->FindEntry(instruction_start); if (entry != nullptr) { entry->set_bailout_reason(bailout_reason); } @@ -34,13 +34,17 @@ void CodeDisableOptEventRecord::UpdateCodeMap(CodeMap* code_map) { void CodeDeoptEventRecord::UpdateCodeMap(CodeMap* code_map) { - CodeEntry* entry = code_map->FindEntry(start); - if (entry != nullptr) entry->set_deopt_info(deopt_reason, deopt_id); + CodeEntry* entry = code_map->FindEntry(instruction_start); + if (entry == nullptr) return; + std::vector frames_vector( + deopt_frames, deopt_frames + deopt_frame_count); + entry->set_deopt_info(deopt_reason, deopt_id, std::move(frames_vector)); + delete[] deopt_frames; } void ReportBuiltinEventRecord::UpdateCodeMap(CodeMap* code_map) { - CodeEntry* entry = code_map->FindEntry(start); + CodeEntry* entry = code_map->FindEntry(instruction_start); if (!entry) { // Code objects for builtins should already have been added to the map but // some of them have been filtered out by CpuProfiler. diff --git a/deps/v8/src/profiler/cpu-profiler.cc b/deps/v8/src/profiler/cpu-profiler.cc index 9035be3eedf251..79606dc812ebda 100644 --- a/deps/v8/src/profiler/cpu-profiler.cc +++ b/deps/v8/src/profiler/cpu-profiler.cc @@ -345,20 +345,20 @@ void CpuProfiler::CollectSample() { } } -void CpuProfiler::StartProfiling(const char* title, bool record_samples) { - if (profiles_->StartProfiling(title, record_samples)) { +void CpuProfiler::StartProfiling(const char* title, bool record_samples, + ProfilingMode mode) { + if (profiles_->StartProfiling(title, record_samples, mode)) { TRACE_EVENT0("v8", "CpuProfiler::StartProfiling"); StartProcessorIfNotStarted(); } } - -void CpuProfiler::StartProfiling(String* title, bool record_samples) { - StartProfiling(profiles_->GetName(title), record_samples); +void CpuProfiler::StartProfiling(String* title, bool record_samples, + ProfilingMode mode) { + StartProfiling(profiles_->GetName(title), record_samples, mode); isolate_->debug()->feature_tracker()->Track(DebugFeatureTracker::kProfiler); } - void CpuProfiler::StartProcessorIfNotStarted() { if (processor_) { processor_->AddCurrentStack(isolate_); @@ -426,7 +426,7 @@ void CpuProfiler::LogBuiltins() { CodeEventsContainer evt_rec(CodeEventRecord::REPORT_BUILTIN); ReportBuiltinEventRecord* rec = &evt_rec.ReportBuiltinEventRecord_; Builtins::Name id = static_cast(i); - rec->start = builtins->builtin(id)->address(); + rec->instruction_start = builtins->builtin(id)->InstructionStart(); rec->builtin_id = id; processor_->Enqueue(evt_rec); } diff --git a/deps/v8/src/profiler/cpu-profiler.h b/deps/v8/src/profiler/cpu-profiler.h index 1ed0975c3adbcb..4e56c7bd7409e3 100644 --- a/deps/v8/src/profiler/cpu-profiler.h +++ b/deps/v8/src/profiler/cpu-profiler.h @@ -53,9 +53,9 @@ class CodeEventRecord { class CodeCreateEventRecord : public CodeEventRecord { public: - Address start; + Address instruction_start; CodeEntry* entry; - unsigned size; + unsigned instruction_size; INLINE(void UpdateCodeMap(CodeMap* code_map)); }; @@ -63,8 +63,8 @@ class CodeCreateEventRecord : public CodeEventRecord { class CodeMoveEventRecord : public CodeEventRecord { public: - Address from; - Address to; + Address from_instruction_start; + Address to_instruction_start; INLINE(void UpdateCodeMap(CodeMap* code_map)); }; @@ -72,7 +72,7 @@ class CodeMoveEventRecord : public CodeEventRecord { class CodeDisableOptEventRecord : public CodeEventRecord { public: - Address start; + Address instruction_start; const char* bailout_reason; INLINE(void UpdateCodeMap(CodeMap* code_map)); @@ -81,11 +81,13 @@ class CodeDisableOptEventRecord : public CodeEventRecord { class CodeDeoptEventRecord : public CodeEventRecord { public: - Address start; + Address instruction_start; const char* deopt_reason; int deopt_id; Address pc; int fp_to_sp_delta; + CpuProfileDeoptFrame* deopt_frames; + int deopt_frame_count; INLINE(void UpdateCodeMap(CodeMap* code_map)); }; @@ -93,7 +95,7 @@ class CodeDeoptEventRecord : public CodeEventRecord { class ReportBuiltinEventRecord : public CodeEventRecord { public: - Address start; + Address instruction_start; Builtins::Name builtin_id; INLINE(void UpdateCodeMap(CodeMap* code_map)); @@ -197,10 +199,13 @@ class CpuProfiler : public CodeEventObserver { static void CollectSample(Isolate* isolate); + typedef v8::CpuProfilingMode ProfilingMode; + void set_sampling_interval(base::TimeDelta value); void CollectSample(); - void StartProfiling(const char* title, bool record_samples = false); - void StartProfiling(String* title, bool record_samples); + void StartProfiling(const char* title, bool record_samples = false, + ProfilingMode mode = ProfilingMode::kLeafNodeLineNumbers); + void StartProfiling(String* title, bool record_samples, ProfilingMode mode); CpuProfile* StopProfiling(const char* title); CpuProfile* StopProfiling(String* title); int GetProfilesCount(); diff --git a/deps/v8/src/profiler/profile-generator-inl.h b/deps/v8/src/profiler/profile-generator-inl.h index 7ed6d54e172f09..31652ba9f98e83 100644 --- a/deps/v8/src/profiler/profile-generator-inl.h +++ b/deps/v8/src/profiler/profile-generator-inl.h @@ -33,10 +33,11 @@ inline CodeEntry* ProfileGenerator::FindEntry(Address address) { } ProfileNode::ProfileNode(ProfileTree* tree, CodeEntry* entry, - ProfileNode* parent) + ProfileNode* parent, int line_number) : tree_(tree), entry_(entry), self_ticks_(0), + line_number_(line_number), parent_(parent), id_(tree->next_node_id()) { tree_->EnqueueNode(this); diff --git a/deps/v8/src/profiler/profile-generator.cc b/deps/v8/src/profiler/profile-generator.cc index 388078455e87f6..4273234dd23d86 100644 --- a/deps/v8/src/profiler/profile-generator.cc +++ b/deps/v8/src/profiler/profile-generator.cc @@ -131,15 +131,14 @@ const std::vector>* CodeEntry::GetInlineStack( return it != rare_data_->inline_locations_.end() ? &it->second : nullptr; } -void CodeEntry::AddDeoptInlinedFrames( - int deopt_id, std::vector inlined_frames) { - EnsureRareData()->deopt_inlined_frames_.insert( - std::make_pair(deopt_id, std::move(inlined_frames))); -} - -bool CodeEntry::HasDeoptInlinedFramesFor(int deopt_id) const { - return rare_data_ && rare_data_->deopt_inlined_frames_.find(deopt_id) != - rare_data_->deopt_inlined_frames_.end(); +void CodeEntry::set_deopt_info( + const char* deopt_reason, int deopt_id, + std::vector inlined_frames) { + DCHECK(!has_deopt_info()); + RareData* rare_data = EnsureRareData(); + rare_data->deopt_reason_ = deopt_reason; + rare_data->deopt_id_ = deopt_id; + rare_data->deopt_inlined_frames_ = std::move(inlined_frames); } void CodeEntry::FillFunctionInfo(SharedFunctionInfo* shared) { @@ -158,12 +157,11 @@ CpuProfileDeoptInfo CodeEntry::GetDeoptInfo() { CpuProfileDeoptInfo info; info.deopt_reason = rare_data_->deopt_reason_; DCHECK_NE(kNoDeoptimizationId, rare_data_->deopt_id_); - if (rare_data_->deopt_inlined_frames_.find(rare_data_->deopt_id_) == - rare_data_->deopt_inlined_frames_.end()) { + if (rare_data_->deopt_inlined_frames_.empty()) { info.stack.push_back(CpuProfileDeoptFrame( {script_id_, static_cast(std::max(0, position()))})); } else { - info.stack = rare_data_->deopt_inlined_frames_[rare_data_->deopt_id_]; + info.stack = rare_data_->deopt_inlined_frames_; } return info; } @@ -180,18 +178,16 @@ void ProfileNode::CollectDeoptInfo(CodeEntry* entry) { entry->clear_deopt_info(); } - -ProfileNode* ProfileNode::FindChild(CodeEntry* entry) { - auto map_entry = children_.find(entry); +ProfileNode* ProfileNode::FindChild(CodeEntry* entry, int line_number) { + auto map_entry = children_.find({entry, line_number}); return map_entry != children_.end() ? map_entry->second : nullptr; } - -ProfileNode* ProfileNode::FindOrAddChild(CodeEntry* entry) { - auto map_entry = children_.find(entry); +ProfileNode* ProfileNode::FindOrAddChild(CodeEntry* entry, int line_number) { + auto map_entry = children_.find({entry, line_number}); if (map_entry == children_.end()) { - ProfileNode* node = new ProfileNode(tree_, entry, this); - children_[entry] = node; + ProfileNode* node = new ProfileNode(tree_, entry, this, line_number); + children_[{entry, line_number}] = node; children_list_.push_back(node); return node; } else { @@ -234,8 +230,9 @@ bool ProfileNode::GetLineTicks(v8::CpuProfileNode::LineTick* entries, void ProfileNode::Print(int indent) { - base::OS::Print("%5u %*s %s %d #%d", self_ticks_, indent, "", entry_->name(), - entry_->script_id(), id()); + int line_number = line_number_ != 0 ? line_number_ : entry_->line_number(); + base::OS::Print("%5u %*s %s:%d %d #%d", self_ticks_, indent, "", + entry_->name(), line_number, entry_->script_id(), id()); if (entry_->resource_name()[0] != '\0') base::OS::Print(" %s:%d", entry_->resource_name(), entry_->line_number()); base::OS::Print("\n"); @@ -304,7 +301,33 @@ ProfileNode* ProfileTree::AddPathFromEnd(const std::vector& path, for (auto it = path.rbegin(); it != path.rend(); ++it) { if (*it == nullptr) continue; last_entry = *it; - node = node->FindOrAddChild(*it); + node = node->FindOrAddChild(*it, v8::CpuProfileNode::kNoLineNumberInfo); + } + if (last_entry && last_entry->has_deopt_info()) { + node->CollectDeoptInfo(last_entry); + } + if (update_stats) { + node->IncrementSelfTicks(); + if (src_line != v8::CpuProfileNode::kNoLineNumberInfo) { + node->IncrementLineTicks(src_line); + } + } + return node; +} + +ProfileNode* ProfileTree::AddPathFromEnd(const ProfileStackTrace& path, + int src_line, bool update_stats, + ProfilingMode mode) { + ProfileNode* node = root_; + CodeEntry* last_entry = nullptr; + int parent_line_number = v8::CpuProfileNode::kNoLineNumberInfo; + for (auto it = path.rbegin(); it != path.rend(); ++it) { + if ((*it).code_entry == nullptr) continue; + last_entry = (*it).code_entry; + node = node->FindOrAddChild((*it).code_entry, parent_line_number); + parent_line_number = mode == ProfilingMode::kCallerLineNumbers + ? (*it).line_number + : v8::CpuProfileNode::kNoLineNumberInfo; } if (last_entry && last_entry->has_deopt_info()) { node->CollectDeoptInfo(last_entry); @@ -363,9 +386,10 @@ void ProfileTree::TraverseDepthFirst(Callback* callback) { using v8::tracing::TracedValue; CpuProfile::CpuProfile(CpuProfiler* profiler, const char* title, - bool record_samples) + bool record_samples, ProfilingMode mode) : title_(title), record_samples_(record_samples), + mode_(mode), start_time_(base::TimeTicks::HighResolutionNow()), top_down_(profiler->isolate()), profiler_(profiler), @@ -378,14 +402,16 @@ CpuProfile::CpuProfile(CpuProfiler* profiler, const char* title, } void CpuProfile::AddPath(base::TimeTicks timestamp, - const std::vector& path, int src_line, + const ProfileStackTrace& path, int src_line, bool update_stats) { ProfileNode* top_frame_node = - top_down_.AddPathFromEnd(path, src_line, update_stats); + top_down_.AddPathFromEnd(path, src_line, update_stats, mode_); + if (record_samples_ && !timestamp.IsNull()) { timestamps_.push_back(timestamp); samples_.push_back(top_frame_node); } + const int kSamplesFlushCount = 100; const int kNodesFlushCount = 10; if (samples_.size() - streaming_next_sample_ >= kSamplesFlushCount || @@ -482,13 +508,25 @@ void CpuProfile::Print() { } CodeMap::CodeMap() = default; -CodeMap::~CodeMap() = default; + +CodeMap::~CodeMap() { + // First clean the free list as it's otherwise impossible to tell + // the slot type. + unsigned free_slot = free_list_head_; + while (free_slot != kNoFreeSlot) { + unsigned next_slot = code_entries_[free_slot].next_free_slot; + code_entries_[free_slot].entry = nullptr; + free_slot = next_slot; + } + for (auto slot : code_entries_) delete slot.entry; +} void CodeMap::AddCode(Address addr, CodeEntry* entry, unsigned size) { ClearCodesInRange(addr, addr + size); - code_map_.emplace( - addr, CodeEntryInfo{static_cast(code_entries_.size()), size}); - code_entries_.push_back(std::unique_ptr(entry)); + unsigned index = AddCodeEntry(addr, entry); + code_map_.emplace(addr, CodeEntryMapInfo{index, size}); + DCHECK(entry->instruction_start() == kNullAddress || + addr == entry->instruction_start()); } void CodeMap::ClearCodesInRange(Address start, Address end) { @@ -499,9 +537,8 @@ void CodeMap::ClearCodesInRange(Address start, Address end) { } auto right = left; for (; right != code_map_.end() && right->first < end; ++right) { - std::unique_ptr& entry = code_entries_[right->second.index]; - if (!entry->used()) { - entry.reset(); + if (!entry(right->second.index)->used()) { + DeleteCodeEntry(right->second.index); } } code_map_.erase(left, right); @@ -511,28 +548,51 @@ CodeEntry* CodeMap::FindEntry(Address addr) { auto it = code_map_.upper_bound(addr); if (it == code_map_.begin()) return nullptr; --it; - Address end_address = it->first + it->second.size; - if (addr >= end_address) return nullptr; - CodeEntry* entry = code_entries_[it->second.index].get(); - DCHECK(entry); - return entry; + Address start_address = it->first; + Address end_address = start_address + it->second.size; + CodeEntry* ret = addr < end_address ? entry(it->second.index) : nullptr; + if (ret && ret->instruction_start() != kNullAddress) { + DCHECK_EQ(start_address, ret->instruction_start()); + DCHECK(addr >= start_address && addr < end_address); + } + return ret; } void CodeMap::MoveCode(Address from, Address to) { if (from == to) return; auto it = code_map_.find(from); if (it == code_map_.end()) return; - CodeEntryInfo info = it->second; + CodeEntryMapInfo info = it->second; code_map_.erase(it); DCHECK(from + info.size <= to || to + info.size <= from); ClearCodesInRange(to, to + info.size); code_map_.emplace(to, info); + + CodeEntry* entry = code_entries_[info.index].entry; + entry->set_instruction_start(to); +} + +unsigned CodeMap::AddCodeEntry(Address start, CodeEntry* entry) { + if (free_list_head_ == kNoFreeSlot) { + code_entries_.push_back(CodeEntrySlotInfo{entry}); + return static_cast(code_entries_.size()) - 1; + } + unsigned index = free_list_head_; + free_list_head_ = code_entries_[index].next_free_slot; + code_entries_[index].entry = entry; + return index; +} + +void CodeMap::DeleteCodeEntry(unsigned index) { + delete code_entries_[index].entry; + code_entries_[index].next_free_slot = free_list_head_; + free_list_head_ = index; } void CodeMap::Print() { for (const auto& pair : code_map_) { base::OS::Print("%p %5d %s\n", reinterpret_cast(pair.first), - pair.second.size, code_entries_[pair.second.index]->name()); + pair.second.size, entry(pair.second.index)->name()); } } @@ -542,7 +602,8 @@ CpuProfilesCollection::CpuProfilesCollection(Isolate* isolate) current_profiles_semaphore_(1) {} bool CpuProfilesCollection::StartProfiling(const char* title, - bool record_samples) { + bool record_samples, + ProfilingMode mode) { current_profiles_semaphore_.Wait(); if (static_cast(current_profiles_.size()) >= kMaxSimultaneousProfiles) { current_profiles_semaphore_.Signal(); @@ -557,7 +618,7 @@ bool CpuProfilesCollection::StartProfiling(const char* title, } } current_profiles_.emplace_back( - new CpuProfile(profiler_, title, record_samples)); + new CpuProfile(profiler_, title, record_samples, mode)); current_profiles_semaphore_.Signal(); return true; } @@ -608,8 +669,8 @@ void CpuProfilesCollection::RemoveProfile(CpuProfile* profile) { } void CpuProfilesCollection::AddPathToCurrentProfiles( - base::TimeTicks timestamp, const std::vector& path, - int src_line, bool update_stats) { + base::TimeTicks timestamp, const ProfileStackTrace& path, int src_line, + bool update_stats) { // As starting / stopping profiles is rare relatively to this // method, we don't bother minimizing the duration of lock holding, // e.g. copying contents of the list to a local vector. @@ -624,47 +685,52 @@ ProfileGenerator::ProfileGenerator(CpuProfilesCollection* profiles) : profiles_(profiles) {} void ProfileGenerator::RecordTickSample(const TickSample& sample) { - std::vector entries; + ProfileStackTrace stack_trace; // Conservatively reserve space for stack frames + pc + function + vm-state. // There could in fact be more of them because of inlined entries. - entries.reserve(sample.frames_count + 3); + stack_trace.reserve(sample.frames_count + 3); // The ProfileNode knows nothing about all versions of generated code for // the same JS function. The line number information associated with // the latest version of generated code is used to find a source line number // for a JS function. Then, the detected source line is passed to // ProfileNode to increase the tick count for this source line. - int src_line = v8::CpuProfileNode::kNoLineNumberInfo; + const int no_line_info = v8::CpuProfileNode::kNoLineNumberInfo; + int src_line = no_line_info; bool src_line_not_found = true; if (sample.pc != nullptr) { if (sample.has_external_callback && sample.state == EXTERNAL) { // Don't use PC when in external callback code, as it can point - // inside callback's code, and we will erroneously report + // inside a callback's code, and we will erroneously report // that a callback calls itself. - entries.push_back( - FindEntry(reinterpret_cast
(sample.external_callback_entry))); + stack_trace.push_back( + {FindEntry(reinterpret_cast
(sample.external_callback_entry)), + no_line_info}); } else { - CodeEntry* pc_entry = FindEntry(reinterpret_cast
(sample.pc)); - // If there is no pc_entry we're likely in native code. - // Find out, if top of stack was pointing inside a JS function - // meaning that we have encountered a frameless invocation. + Address attributed_pc = reinterpret_cast
(sample.pc); + CodeEntry* pc_entry = FindEntry(attributed_pc); + // If there is no pc_entry, we're likely in native code. Find out if the + // top of the stack (the return address) was pointing inside a JS + // function, meaning that we have encountered a frameless invocation. if (!pc_entry && !sample.has_external_callback) { - pc_entry = FindEntry(reinterpret_cast
(sample.tos)); + attributed_pc = reinterpret_cast
(sample.tos); + pc_entry = FindEntry(attributed_pc); } // If pc is in the function code before it set up stack frame or after the - // frame was destroyed SafeStackFrameIterator incorrectly thinks that - // ebp contains return address of the current function and skips caller's - // frame. Check for this case and just skip such samples. + // frame was destroyed, SafeStackFrameIterator incorrectly thinks that + // ebp contains the return address of the current function and skips the + // caller's frame. Check for this case and just skip such samples. if (pc_entry) { - int pc_offset = static_cast(reinterpret_cast
(sample.pc) - - pc_entry->instruction_start()); + int pc_offset = + static_cast(attributed_pc - pc_entry->instruction_start()); + DCHECK_GE(pc_offset, 0); src_line = pc_entry->GetSourceLine(pc_offset); if (src_line == v8::CpuProfileNode::kNoLineNumberInfo) { src_line = pc_entry->line_number(); } src_line_not_found = false; - entries.push_back(pc_entry); + stack_trace.push_back({pc_entry, src_line}); if (pc_entry->builtin_id() == Builtins::kFunctionPrototypeApply || pc_entry->builtin_id() == Builtins::kFunctionPrototypeCall) { @@ -675,7 +741,8 @@ void ProfileGenerator::RecordTickSample(const TickSample& sample) { // former case we don't so we simply replace the frame with // 'unresolved' entry. if (!sample.has_external_callback) { - entries.push_back(CodeEntry::unresolved_entry()); + stack_trace.push_back( + {CodeEntry::unresolved_entry(), no_line_info}); } } } @@ -684,17 +751,21 @@ void ProfileGenerator::RecordTickSample(const TickSample& sample) { for (unsigned i = 0; i < sample.frames_count; ++i) { Address stack_pos = reinterpret_cast
(sample.stack[i]); CodeEntry* entry = FindEntry(stack_pos); + int line_number = no_line_info; if (entry) { // Find out if the entry has an inlining stack associated. int pc_offset = static_cast(stack_pos - entry->instruction_start()); + DCHECK_GE(pc_offset, 0); const std::vector>* inline_stack = entry->GetInlineStack(pc_offset); if (inline_stack) { std::transform( inline_stack->rbegin(), inline_stack->rend(), - std::back_inserter(entries), - [](const std::unique_ptr& ptr) { return ptr.get(); }); + std::back_inserter(stack_trace), + [=](const std::unique_ptr& ptr) { + return CodeEntryAndLineNumber{ptr.get(), no_line_info}; + }); } // Skip unresolved frames (e.g. internal frame) and get source line of // the first JS caller. @@ -705,26 +776,27 @@ void ProfileGenerator::RecordTickSample(const TickSample& sample) { } src_line_not_found = false; } + line_number = entry->GetSourceLine(pc_offset); } - entries.push_back(entry); + stack_trace.push_back({entry, line_number}); } } if (FLAG_prof_browser_mode) { bool no_symbolized_entries = true; - for (auto e : entries) { - if (e != nullptr) { + for (auto e : stack_trace) { + if (e.code_entry != nullptr) { no_symbolized_entries = false; break; } } // If no frames were symbolized, put the VM state entry in. if (no_symbolized_entries) { - entries.push_back(EntryForVMState(sample.state)); + stack_trace.push_back({EntryForVMState(sample.state), no_line_info}); } } - profiles_->AddPathToCurrentProfiles(sample.timestamp, entries, src_line, + profiles_->AddPathToCurrentProfiles(sample.timestamp, stack_trace, src_line, sample.update_stats); } diff --git a/deps/v8/src/profiler/profile-generator.h b/deps/v8/src/profiler/profile-generator.h index 3b9c083b6de54e..e575a786481d51 100644 --- a/deps/v8/src/profiler/profile-generator.h +++ b/deps/v8/src/profiler/profile-generator.h @@ -6,9 +6,11 @@ #define V8_PROFILER_PROFILE_GENERATOR_H_ #include +#include #include #include #include +#include #include #include "include/v8-profiler.h" @@ -72,12 +74,9 @@ class CodeEntry { return rare_data_ ? rare_data_->bailout_reason_ : kEmptyBailoutReason; } - void set_deopt_info(const char* deopt_reason, int deopt_id) { - DCHECK(!has_deopt_info()); - RareData* rare_data = EnsureRareData(); - rare_data->deopt_reason_ = deopt_reason; - rare_data->deopt_id_ = deopt_id; - } + void set_deopt_info(const char* deopt_reason, int deopt_id, + std::vector inlined_frames); + CpuProfileDeoptInfo GetDeoptInfo(); bool has_deopt_info() const { return rare_data_ && rare_data_->deopt_id_ != kNoDeoptimizationId; @@ -108,10 +107,9 @@ class CodeEntry { const std::vector>* GetInlineStack( int pc_offset) const; - void AddDeoptInlinedFrames(int deopt_id, std::vector); - bool HasDeoptInlinedFramesFor(int deopt_id) const; - + void set_instruction_start(Address start) { instruction_start_ = start; } Address instruction_start() const { return instruction_start_; } + CodeEventListener::LogEventsAndTags tag() const { return TagField::decode(bit_field_); } @@ -143,8 +141,7 @@ class CodeEntry { int deopt_id_ = kNoDeoptimizationId; std::unordered_map>> inline_locations_; - std::unordered_map> - deopt_inlined_frames_; + std::vector deopt_inlined_frames_; }; RareData* EnsureRareData(); @@ -189,15 +186,24 @@ class CodeEntry { DISALLOW_COPY_AND_ASSIGN(CodeEntry); }; +struct CodeEntryAndLineNumber { + CodeEntry* code_entry; + int line_number; +}; + +typedef std::vector ProfileStackTrace; class ProfileTree; class ProfileNode { public: - inline ProfileNode(ProfileTree* tree, CodeEntry* entry, ProfileNode* parent); + inline ProfileNode(ProfileTree* tree, CodeEntry* entry, ProfileNode* parent, + int line_number = 0); - ProfileNode* FindChild(CodeEntry* entry); - ProfileNode* FindOrAddChild(CodeEntry* entry); + ProfileNode* FindChild( + CodeEntry* entry, + int line_number = v8::CpuProfileNode::kNoLineNumberInfo); + ProfileNode* FindOrAddChild(CodeEntry* entry, int line_number = 0); void IncrementSelfTicks() { ++self_ticks_; } void IncreaseSelfTicks(unsigned amount) { self_ticks_ += amount; } void IncrementLineTicks(int src_line); @@ -208,6 +214,10 @@ class ProfileNode { unsigned id() const { return id_; } unsigned function_id() const; ProfileNode* parent() const { return parent_; } + int line_number() const { + return line_number_ != 0 ? line_number_ : entry_->line_number(); + } + unsigned int GetHitLineCount() const { return static_cast(line_ticks_.size()); } @@ -222,20 +232,25 @@ class ProfileNode { void Print(int indent); private: - struct CodeEntryEqual { - bool operator()(CodeEntry* entry1, CodeEntry* entry2) const { - return entry1 == entry2 || entry1->IsSameFunctionAs(entry2); + struct Equals { + bool operator()(CodeEntryAndLineNumber lhs, + CodeEntryAndLineNumber rhs) const { + return lhs.code_entry->IsSameFunctionAs(rhs.code_entry) && + lhs.line_number == rhs.line_number; } }; - struct CodeEntryHash { - std::size_t operator()(CodeEntry* entry) const { return entry->GetHash(); } + struct Hasher { + std::size_t operator()(CodeEntryAndLineNumber pair) const { + return pair.code_entry->GetHash() ^ ComputeIntegerHash(pair.line_number); + } }; ProfileTree* tree_; CodeEntry* entry_; unsigned self_ticks_; - std::unordered_map + std::unordered_map children_; + int line_number_; std::vector children_list_; ProfileNode* parent_; unsigned id_; @@ -253,10 +268,17 @@ class ProfileTree { explicit ProfileTree(Isolate* isolate); ~ProfileTree(); + typedef v8::CpuProfilingMode ProfilingMode; + ProfileNode* AddPathFromEnd( const std::vector& path, int src_line = v8::CpuProfileNode::kNoLineNumberInfo, bool update_stats = true); + ProfileNode* AddPathFromEnd( + const ProfileStackTrace& path, + int src_line = v8::CpuProfileNode::kNoLineNumberInfo, + bool update_stats = true, + ProfilingMode mode = ProfilingMode::kLeafNodeLineNumbers); ProfileNode* root() const { return root_; } unsigned next_node_id() { return next_node_id_++; } unsigned GetFunctionId(const ProfileNode* node); @@ -293,10 +315,13 @@ class ProfileTree { class CpuProfile { public: - CpuProfile(CpuProfiler* profiler, const char* title, bool record_samples); + typedef v8::CpuProfilingMode ProfilingMode; + + CpuProfile(CpuProfiler* profiler, const char* title, bool record_samples, + ProfilingMode mode); // Add pc -> ... -> main() call path to the profile. - void AddPath(base::TimeTicks timestamp, const std::vector& path, + void AddPath(base::TimeTicks timestamp, const ProfileStackTrace& path, int src_line, bool update_stats); void FinishProfile(); @@ -322,6 +347,7 @@ class CpuProfile { const char* title_; bool record_samples_; + ProfilingMode mode_; base::TimeTicks start_time_; base::TimeTicks end_time_; std::vector samples_; @@ -344,15 +370,27 @@ class CodeMap { void Print(); private: - struct CodeEntryInfo { + struct CodeEntryMapInfo { unsigned index; unsigned size; }; + union CodeEntrySlotInfo { + CodeEntry* entry; + unsigned next_free_slot; + }; + + static constexpr unsigned kNoFreeSlot = std::numeric_limits::max(); + void ClearCodesInRange(Address start, Address end); + unsigned AddCodeEntry(Address start, CodeEntry*); + void DeleteCodeEntry(unsigned index); - std::deque> code_entries_; - std::map code_map_; + CodeEntry* entry(unsigned index) { return code_entries_[index].entry; } + + std::deque code_entries_; + std::map code_map_; + unsigned free_list_head_ = kNoFreeSlot; DISALLOW_COPY_AND_ASSIGN(CodeMap); }; @@ -361,8 +399,11 @@ class CpuProfilesCollection { public: explicit CpuProfilesCollection(Isolate* isolate); + typedef v8::CpuProfilingMode ProfilingMode; + void set_cpu_profiler(CpuProfiler* profiler) { profiler_ = profiler; } - bool StartProfiling(const char* title, bool record_samples); + bool StartProfiling(const char* title, bool record_samples, + ProfilingMode mode = ProfilingMode::kLeafNodeLineNumbers); CpuProfile* StopProfiling(const char* title); std::vector>* profiles() { return &finished_profiles_; @@ -373,8 +414,8 @@ class CpuProfilesCollection { // Called from profile generator thread. void AddPathToCurrentProfiles(base::TimeTicks timestamp, - const std::vector& path, - int src_line, bool update_stats); + const ProfileStackTrace& path, int src_line, + bool update_stats); // Limits the number of profiles that can be simultaneously collected. static const int kMaxSimultaneousProfiles = 100; diff --git a/deps/v8/src/profiler/profiler-listener.cc b/deps/v8/src/profiler/profiler-listener.cc index 70d907b2165970..e3c2c140fb619f 100644 --- a/deps/v8/src/profiler/profiler-listener.cc +++ b/deps/v8/src/profiler/profiler-listener.cc @@ -26,9 +26,9 @@ ProfilerListener::~ProfilerListener() = default; void ProfilerListener::CallbackEvent(Name* name, Address entry_point) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = entry_point; + rec->instruction_start = entry_point; rec->entry = NewCodeEntry(CodeEventListener::CALLBACK_TAG, GetName(name)); - rec->size = 1; + rec->instruction_size = 1; DispatchCodeEvent(evt_rec); } @@ -36,13 +36,13 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, AbstractCode* code, const char* name) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = code->address(); + rec->instruction_start = code->InstructionStart(); rec->entry = NewCodeEntry( tag, GetFunctionName(name), CodeEntry::kEmptyResourceName, CpuProfileNode::kNoLineNumberInfo, CpuProfileNode::kNoColumnNumberInfo, nullptr, code->InstructionStart()); RecordInliningInfo(rec->entry, code); - rec->size = code->ExecutableSize(); + rec->instruction_size = code->InstructionSize(); DispatchCodeEvent(evt_rec); } @@ -50,13 +50,13 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, AbstractCode* code, Name* name) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = code->address(); + rec->instruction_start = code->InstructionStart(); rec->entry = NewCodeEntry( tag, GetFunctionName(name), CodeEntry::kEmptyResourceName, CpuProfileNode::kNoLineNumberInfo, CpuProfileNode::kNoColumnNumberInfo, nullptr, code->InstructionStart()); RecordInliningInfo(rec->entry, code); - rec->size = code->ExecutableSize(); + rec->instruction_size = code->InstructionSize(); DispatchCodeEvent(evt_rec); } @@ -66,7 +66,7 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, Name* script_name) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = code->address(); + rec->instruction_start = code->InstructionStart(); rec->entry = NewCodeEntry(tag, GetFunctionName(shared->DebugName()), GetName(InferScriptName(script_name, shared)), CpuProfileNode::kNoLineNumberInfo, @@ -74,7 +74,7 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, code->InstructionStart()); RecordInliningInfo(rec->entry, code); rec->entry->FillFunctionInfo(shared); - rec->size = code->ExecutableSize(); + rec->instruction_size = code->InstructionSize(); DispatchCodeEvent(evt_rec); } @@ -85,7 +85,7 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, int column) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = abstract_code->address(); + rec->instruction_start = abstract_code->InstructionStart(); std::unique_ptr line_table; if (shared->script()->IsScript()) { Script* script = Script::cast(shared->script()); @@ -106,9 +106,8 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, GetName(InferScriptName(script_name, shared)), line, column, std::move(line_table), abstract_code->InstructionStart()); RecordInliningInfo(rec->entry, abstract_code); - RecordDeoptInlinedFrames(rec->entry, abstract_code); rec->entry->FillFunctionInfo(shared); - rec->size = abstract_code->ExecutableSize(); + rec->instruction_size = abstract_code->InstructionSize(); DispatchCodeEvent(evt_rec); } @@ -117,7 +116,7 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, wasm::WasmName name) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = code->instruction_start(); + rec->instruction_start = code->instruction_start(); // TODO(herhut): Instead of sanitizing here, make sure all wasm functions // have names. const char* name_ptr = @@ -126,15 +125,15 @@ void ProfilerListener::CodeCreateEvent(CodeEventListener::LogEventsAndTags tag, CpuProfileNode::kNoLineNumberInfo, CpuProfileNode::kNoColumnNumberInfo, nullptr, code->instruction_start()); - rec->size = code->instructions().length(); + rec->instruction_size = code->instructions().length(); DispatchCodeEvent(evt_rec); } -void ProfilerListener::CodeMoveEvent(AbstractCode* from, Address to) { +void ProfilerListener::CodeMoveEvent(AbstractCode* from, AbstractCode* to) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_MOVE); CodeMoveEventRecord* rec = &evt_rec.CodeMoveEventRecord_; - rec->from = from->address(); - rec->to = to; + rec->from_instruction_start = from->InstructionStart(); + rec->to_instruction_start = to->InstructionStart(); DispatchCodeEvent(evt_rec); } @@ -142,7 +141,7 @@ void ProfilerListener::CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_DISABLE_OPT); CodeDisableOptEventRecord* rec = &evt_rec.CodeDisableOptEventRecord_; - rec->start = code->address(); + rec->instruction_start = code->InstructionStart(); rec->bailout_reason = GetBailoutReason(shared->disable_optimization_reason()); DispatchCodeEvent(evt_rec); } @@ -152,21 +151,25 @@ void ProfilerListener::CodeDeoptEvent(Code* code, DeoptKind kind, Address pc, CodeEventsContainer evt_rec(CodeEventRecord::CODE_DEOPT); CodeDeoptEventRecord* rec = &evt_rec.CodeDeoptEventRecord_; Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(code, pc); - rec->start = code->address(); + rec->instruction_start = code->InstructionStart(); rec->deopt_reason = DeoptimizeReasonToString(info.deopt_reason); rec->deopt_id = info.deopt_id; rec->pc = pc; rec->fp_to_sp_delta = fp_to_sp_delta; + + // When a function is deoptimized, we store the deoptimized frame information + // for the use of GetDeoptInfos(). + AttachDeoptInlinedFrames(code, rec); DispatchCodeEvent(evt_rec); } void ProfilerListener::GetterCallbackEvent(Name* name, Address entry_point) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = entry_point; + rec->instruction_start = entry_point; rec->entry = NewCodeEntry(CodeEventListener::CALLBACK_TAG, GetConsName("get ", name)); - rec->size = 1; + rec->instruction_size = 1; DispatchCodeEvent(evt_rec); } @@ -174,23 +177,22 @@ void ProfilerListener::RegExpCodeCreateEvent(AbstractCode* code, String* source) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = code->address(); + rec->instruction_start = code->InstructionStart(); rec->entry = NewCodeEntry( CodeEventListener::REG_EXP_TAG, GetConsName("RegExp: ", source), CodeEntry::kEmptyResourceName, CpuProfileNode::kNoLineNumberInfo, - CpuProfileNode::kNoColumnNumberInfo, nullptr, - code->raw_instruction_start()); - rec->size = code->ExecutableSize(); + CpuProfileNode::kNoColumnNumberInfo, nullptr, code->InstructionStart()); + rec->instruction_size = code->InstructionSize(); DispatchCodeEvent(evt_rec); } void ProfilerListener::SetterCallbackEvent(Name* name, Address entry_point) { CodeEventsContainer evt_rec(CodeEventRecord::CODE_CREATION); CodeCreateEventRecord* rec = &evt_rec.CodeCreateEventRecord_; - rec->start = entry_point; + rec->instruction_start = entry_point; rec->entry = NewCodeEntry(CodeEventListener::CALLBACK_TAG, GetConsName("set ", name)); - rec->size = 1; + rec->instruction_size = 1; DispatchCodeEvent(evt_rec); } @@ -254,16 +256,18 @@ void ProfilerListener::RecordInliningInfo(CodeEntry* entry, } } -void ProfilerListener::RecordDeoptInlinedFrames(CodeEntry* entry, - AbstractCode* abstract_code) { - if (abstract_code->kind() != AbstractCode::OPTIMIZED_FUNCTION) return; - Handle code(abstract_code->GetCode()); - +void ProfilerListener::AttachDeoptInlinedFrames(Code* code, + CodeDeoptEventRecord* rec) { + int deopt_id = rec->deopt_id; SourcePosition last_position = SourcePosition::Unknown(); int mask = RelocInfo::ModeMask(RelocInfo::DEOPT_ID) | RelocInfo::ModeMask(RelocInfo::DEOPT_SCRIPT_OFFSET) | RelocInfo::ModeMask(RelocInfo::DEOPT_INLINING_ID); - for (RelocIterator it(*code, mask); !it.done(); it.next()) { + + rec->deopt_frames = nullptr; + rec->deopt_frame_count = 0; + + for (RelocIterator it(code, mask); !it.done(); it.next()) { RelocInfo* info = it.rinfo(); if (info->rmode() == RelocInfo::DEOPT_SCRIPT_OFFSET) { int script_offset = static_cast(info->data()); @@ -274,25 +278,29 @@ void ProfilerListener::RecordDeoptInlinedFrames(CodeEntry* entry, continue; } if (info->rmode() == RelocInfo::DEOPT_ID) { - int deopt_id = static_cast(info->data()); + if (deopt_id != static_cast(info->data())) continue; DCHECK(last_position.IsKnown()); - std::vector inlined_frames; // SourcePosition::InliningStack allocates a handle for the SFI of each // frame. These don't escape this function, but quickly add up. This // scope limits their lifetime. HandleScope scope(isolate_); - for (SourcePositionInfo& pos_info : last_position.InliningStack(code)) { + std::vector stack = + last_position.InliningStack(handle(code)); + CpuProfileDeoptFrame* deopt_frames = + new CpuProfileDeoptFrame[stack.size()]; + + int deopt_frame_count = 0; + for (SourcePositionInfo& pos_info : stack) { if (pos_info.position.ScriptOffset() == kNoSourcePosition) continue; if (pos_info.script.is_null()) continue; int script_id = pos_info.script->id(); size_t offset = static_cast(pos_info.position.ScriptOffset()); - inlined_frames.push_back(CpuProfileDeoptFrame({script_id, offset})); - } - if (!inlined_frames.empty() && - !entry->HasDeoptInlinedFramesFor(deopt_id)) { - entry->AddDeoptInlinedFrames(deopt_id, std::move(inlined_frames)); + deopt_frames[deopt_frame_count++] = {script_id, offset}; } + rec->deopt_frames = deopt_frames; + rec->deopt_frame_count = deopt_frame_count; + break; } } } diff --git a/deps/v8/src/profiler/profiler-listener.h b/deps/v8/src/profiler/profiler-listener.h index eafefcd753c153..313a6808c45e16 100644 --- a/deps/v8/src/profiler/profiler-listener.h +++ b/deps/v8/src/profiler/profiler-listener.h @@ -15,6 +15,7 @@ namespace v8 { namespace internal { class CodeEventsContainer; +class CodeDeoptEventRecord; class CodeEventObserver { public: @@ -43,7 +44,7 @@ class ProfilerListener : public CodeEventListener { wasm::WasmName name) override; void CodeMovingGCEvent() override {} - void CodeMoveEvent(AbstractCode* from, Address to) override; + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override; void CodeDisableOptEvent(AbstractCode* code, SharedFunctionInfo* shared) override; void CodeDeoptEvent(Code* code, DeoptKind kind, Address pc, @@ -79,7 +80,7 @@ class ProfilerListener : public CodeEventListener { private: void RecordInliningInfo(CodeEntry* entry, AbstractCode* abstract_code); - void RecordDeoptInlinedFrames(CodeEntry* entry, AbstractCode* abstract_code); + void AttachDeoptInlinedFrames(Code* code, CodeDeoptEventRecord* rec); Name* InferScriptName(Name* name, SharedFunctionInfo* info); V8_INLINE void DispatchCodeEvent(const CodeEventsContainer& evt_rec) { observer_->CodeEventHandler(evt_rec); diff --git a/deps/v8/src/snapshot/serializer.h b/deps/v8/src/snapshot/serializer.h index c387bc046a16df..f1061a6c2f6212 100644 --- a/deps/v8/src/snapshot/serializer.h +++ b/deps/v8/src/snapshot/serializer.h @@ -28,8 +28,8 @@ class CodeAddressMap : public CodeEventLogger { isolate_->logger()->RemoveCodeEventListener(this); } - void CodeMoveEvent(AbstractCode* from, Address to) override { - address_to_name_map_.Move(from->address(), to); + void CodeMoveEvent(AbstractCode* from, AbstractCode* to) override { + address_to_name_map_.Move(from->address(), to->address()); } void CodeDisableOptEvent(AbstractCode* code, diff --git a/deps/v8/test/cctest/cctest.status b/deps/v8/test/cctest/cctest.status index d6d6030222bf39..da069e0a269386 100644 --- a/deps/v8/test/cctest/cctest.status +++ b/deps/v8/test/cctest/cctest.status @@ -75,6 +75,7 @@ # BUG(5193). The cpu profiler tests are notoriously flaky. 'test-profile-generator/RecordStackTraceAtStartProfiling': [SKIP], 'test-cpu-profiler/CollectCpuProfile': [SKIP], + 'test-cpu-profiler/CollectCpuProfileCallerLineNumbers': [FAIL, PASS], 'test-cpu-profiler/CollectCpuProfileSamples': [SKIP], 'test-cpu-profiler/CollectDeoptEvents': [SKIP], 'test-cpu-profiler/CpuProfileDeepStack': [SKIP], diff --git a/deps/v8/test/cctest/test-cpu-profiler.cc b/deps/v8/test/cctest/test-cpu-profiler.cc index 4936542e14d98d..f74bdf1ede87f5 100644 --- a/deps/v8/test/cctest/test-cpu-profiler.cc +++ b/deps/v8/test/cctest/test-cpu-profiler.cc @@ -176,27 +176,29 @@ TEST(CodeEvents) { "comment"); profiler_listener.CodeCreateEvent(i::Logger::BUILTIN_TAG, comment2_code, "comment2"); - profiler_listener.CodeMoveEvent(comment2_code, moved_code->address()); + profiler_listener.CodeMoveEvent(comment2_code, moved_code); // Enqueue a tick event to enable code events processing. - EnqueueTickSampleEvent(processor, aaa_code->address()); + EnqueueTickSampleEvent(processor, aaa_code->InstructionStart()); isolate->logger()->RemoveCodeEventListener(&profiler_listener); processor->StopSynchronously(); // Check the state of profile generator. - CodeEntry* aaa = generator->code_map()->FindEntry(aaa_code->address()); + CodeEntry* aaa = + generator->code_map()->FindEntry(aaa_code->InstructionStart()); CHECK(aaa); CHECK_EQ(0, strcmp(aaa_str, aaa->name())); CodeEntry* comment = - generator->code_map()->FindEntry(comment_code->address()); + generator->code_map()->FindEntry(comment_code->InstructionStart()); CHECK(comment); CHECK_EQ(0, strcmp("comment", comment->name())); - CHECK(!generator->code_map()->FindEntry(comment2_code->address())); + CHECK(!generator->code_map()->FindEntry(comment2_code->InstructionStart())); - CodeEntry* comment2 = generator->code_map()->FindEntry(moved_code->address()); + CodeEntry* comment2 = + generator->code_map()->FindEntry(moved_code->InstructionStart()); CHECK(comment2); CHECK_EQ(0, strcmp("comment2", comment2->name())); } @@ -298,11 +300,11 @@ TEST(Issue1398) { profiler_listener.CodeCreateEvent(i::Logger::BUILTIN_TAG, code, "bbb"); v8::TickSample* sample = processor->StartTickSample(); - sample->pc = reinterpret_cast(code->address()); + sample->pc = reinterpret_cast(code->InstructionStart()); sample->tos = nullptr; sample->frames_count = v8::TickSample::kMaxFramesCount; for (unsigned i = 0; i < sample->frames_count; ++i) { - sample->stack[i] = reinterpret_cast(code->address()); + sample->stack[i] = reinterpret_cast(code->InstructionStart()); } processor->FinishTickSample(); @@ -428,11 +430,14 @@ class ProfilerHelper { profiler_->Dispose(); } + typedef v8::CpuProfilingMode ProfilingMode; + v8::CpuProfile* Run(v8::Local function, v8::Local argv[], int argc, unsigned min_js_samples = 0, unsigned min_external_samples = 0, - bool collect_samples = false); + bool collect_samples = false, + ProfilingMode mode = ProfilingMode::kLeafNodeLineNumbers); v8::CpuProfiler* profiler() { return profiler_; } @@ -445,11 +450,11 @@ v8::CpuProfile* ProfilerHelper::Run(v8::Local function, v8::Local argv[], int argc, unsigned min_js_samples, unsigned min_external_samples, - bool collect_samples) { + bool collect_samples, ProfilingMode mode) { v8::Local profile_name = v8_str("my_profile"); profiler_->SetSamplingInterval(100); - profiler_->StartProfiling(profile_name, collect_samples); + profiler_->StartProfiling(profile_name, mode, collect_samples); v8::internal::CpuProfiler* iprofiler = reinterpret_cast(profiler_); @@ -509,7 +514,6 @@ static const v8::CpuProfileNode* GetChild(v8::Local context, return result; } - static void CheckSimpleBranch(v8::Local context, const v8::CpuProfileNode* node, const char* names[], int length) { @@ -519,7 +523,6 @@ static void CheckSimpleBranch(v8::Local context, } } - static const ProfileNode* GetSimpleBranch(v8::Local context, v8::CpuProfile* profile, const char* names[], int length) { @@ -530,6 +533,41 @@ static const ProfileNode* GetSimpleBranch(v8::Local context, return reinterpret_cast(node); } +struct NameLinePair { + const char* name; + int line_number; +}; + +static const v8::CpuProfileNode* FindChild(const v8::CpuProfileNode* node, + NameLinePair pair) { + for (int i = 0, count = node->GetChildrenCount(); i < count; ++i) { + const v8::CpuProfileNode* child = node->GetChild(i); + // The name and line number must match, or if the requested line number was + // -1, then match any function of the same name. + if (strcmp(child->GetFunctionNameStr(), pair.name) == 0 && + (child->GetLineNumber() == pair.line_number || + pair.line_number == -1)) { + return child; + } + } + return nullptr; +} + +static const v8::CpuProfileNode* GetChild(const v8::CpuProfileNode* node, + NameLinePair pair) { + const v8::CpuProfileNode* result = FindChild(node, pair); + if (!result) FATAL("Failed to GetChild: %s:%d", pair.name, pair.line_number); + return result; +} + +static void CheckBranch(const v8::CpuProfileNode* node, NameLinePair path[], + int length) { + for (int i = 0; i < length; i++) { + NameLinePair pair = path[i]; + node = GetChild(node, pair); + } +} + static const char* cpu_profiler_test_source = "%NeverOptimizeFunction(loop);\n" "%NeverOptimizeFunction(delay);\n" @@ -610,6 +648,40 @@ TEST(CollectCpuProfile) { profile->Delete(); } +TEST(CollectCpuProfileCallerLineNumbers) { + i::FLAG_allow_natives_syntax = true; + LocalContext env; + v8::HandleScope scope(env->GetIsolate()); + + CompileRun(cpu_profiler_test_source); + v8::Local function = GetFunction(env.local(), "start"); + + int32_t profiling_interval_ms = 200; + v8::Local args[] = { + v8::Integer::New(env->GetIsolate(), profiling_interval_ms)}; + ProfilerHelper helper(env.local()); + helper.Run(function, args, arraysize(args), 1000, 0, false, + v8::CpuProfilingMode::kCallerLineNumbers); + v8::CpuProfile* profile = + helper.Run(function, args, arraysize(args), 1000, 0, false, + v8::CpuProfilingMode::kCallerLineNumbers); + + const v8::CpuProfileNode* root = profile->GetTopDownRoot(); + const v8::CpuProfileNode* start_node = GetChild(root, {"start", 27}); + const v8::CpuProfileNode* foo_node = GetChild(start_node, {"foo", 30}); + + NameLinePair bar_branch[] = {{"bar", 23}, {"delay", 19}, {"loop", 18}}; + CheckBranch(foo_node, bar_branch, arraysize(bar_branch)); + NameLinePair baz_branch[] = {{"baz", 25}, {"delay", 20}, {"loop", 18}}; + CheckBranch(foo_node, baz_branch, arraysize(baz_branch)); + NameLinePair delay_at22_branch[] = {{"delay", 22}, {"loop", 18}}; + CheckBranch(foo_node, delay_at22_branch, arraysize(delay_at22_branch)); + NameLinePair delay_at24_branch[] = {{"delay", 24}, {"loop", 18}}; + CheckBranch(foo_node, delay_at24_branch, arraysize(delay_at24_branch)); + + profile->Delete(); +} + static const char* hot_deopt_no_frame_entry_test_source = "%NeverOptimizeFunction(foo);\n" "%NeverOptimizeFunction(start);\n" diff --git a/deps/v8/test/cctest/test-profile-generator.cc b/deps/v8/test/cctest/test-profile-generator.cc index c605efe1951f22..b53bf148e615e4 100644 --- a/deps/v8/test/cctest/test-profile-generator.cc +++ b/deps/v8/test/cctest/test-profile-generator.cc @@ -64,6 +64,25 @@ TEST(ProfileNodeFindOrAddChild) { CHECK_EQ(childNode3, node->FindOrAddChild(&entry3)); } +TEST(ProfileNodeFindOrAddChildWithLineNumber) { + CcTest::InitializeVM(); + ProfileTree tree(CcTest::i_isolate()); + ProfileNode* root = tree.root(); + CodeEntry a(i::CodeEventListener::FUNCTION_TAG, "a"); + ProfileNode* a_node = root->FindOrAddChild(&a, -1); + + // a --(22)--> child1 + // --(23)--> child1 + + CodeEntry child1(i::CodeEventListener::FUNCTION_TAG, "child1"); + ProfileNode* child1_node = a_node->FindOrAddChild(&child1, 22); + CHECK(child1_node); + CHECK_EQ(child1_node, a_node->FindOrAddChild(&child1, 22)); + + ProfileNode* child2_node = a_node->FindOrAddChild(&child1, 23); + CHECK(child2_node); + CHECK_NE(child1_node, child2_node); +} TEST(ProfileNodeFindOrAddChildForSameFunction) { CcTest::InitializeVM(); @@ -172,6 +191,29 @@ TEST(ProfileTreeAddPathFromEnd) { CHECK_EQ(1u, node4->self_ticks()); } +TEST(ProfileTreeAddPathFromEndWithLineNumbers) { + CcTest::InitializeVM(); + CodeEntry a(i::CodeEventListener::FUNCTION_TAG, "a"); + CodeEntry b(i::CodeEventListener::FUNCTION_TAG, "b"); + CodeEntry c(i::CodeEventListener::FUNCTION_TAG, "c"); + ProfileTree tree(CcTest::i_isolate()); + ProfileTreeTestHelper helper(&tree); + + ProfileStackTrace path = {{&c, 5}, {&b, 3}, {&a, 1}}; + tree.AddPathFromEnd(path, v8::CpuProfileNode::kNoLineNumberInfo, true, + v8::CpuProfilingMode::kCallerLineNumbers); + + ProfileNode* a_node = + tree.root()->FindChild(&a, v8::CpuProfileNode::kNoLineNumberInfo); + tree.Print(); + CHECK(a_node); + + ProfileNode* b_node = a_node->FindChild(&b, 1); + CHECK(b_node); + + ProfileNode* c_node = b_node->FindChild(&c, 3); + CHECK(c_node); +} TEST(ProfileTreeCalculateTotalTicks) { CcTest::InitializeVM(); @@ -634,7 +676,8 @@ int GetFunctionLineNumber(CpuProfiler& profiler, LocalContext& env, i::Handle func = i::Handle::cast( v8::Utils::OpenHandle(*v8::Local::Cast( env->Global()->Get(env.local(), v8_str(name)).ToLocalChecked()))); - CodeEntry* func_entry = code_map->FindEntry(func->abstract_code()->address()); + CodeEntry* func_entry = + code_map->FindEntry(func->abstract_code()->InstructionStart()); if (!func_entry) FATAL("%s", name); return func_entry->line_number(); }