From 2e8a6f5e99088cb646158eb3af2b9f7797d386cb Mon Sep 17 00:00:00 2001 From: "yangguo@chromium.org" Date: Fri, 13 Jun 2014 09:07:56 +0000 Subject: [PATCH] Mark timed range in the profile plot. R=jkummerow@chromium.org Review URL: https://codereview.chromium.org/333643006 git-svn-id: https://v8.googlecode.com/svn/branches/bleeding_edge@21832 ce2b1a6d-e550-0410-aec6-3dcde31c8c00 --- src/log.cc | 10 ++++++++++ src/log.h | 1 + src/runtime.cc | 1 + tools/profviz/composer.js | 20 +++++++++++++++++++- 4 files changed, 31 insertions(+), 1 deletion(-) diff --git a/src/log.cc b/src/log.cc index 05d8f7a..8135738 100644 --- a/src/log.cc +++ b/src/log.cc @@ -1076,6 +1076,16 @@ void Logger::CodeDeoptEvent(Code* code) { } +void Logger::CurrentTimeEvent() { + if (!log_->IsEnabled()) return; + ASSERT(FLAG_log_internal_timer_events); + Log::MessageBuilder msg(log_); + int since_epoch = static_cast(timer_.Elapsed().InMicroseconds()); + msg.Append("current-time,%ld\n", since_epoch); + msg.WriteToLogFile(); +} + + void Logger::TimerEvent(StartEnd se, const char* name) { if (!log_->IsEnabled()) return; ASSERT(FLAG_log_internal_timer_events); diff --git a/src/log.h b/src/log.h index b4ad5f8..e98874b 100644 --- a/src/log.h +++ b/src/log.h @@ -290,6 +290,7 @@ class Logger { enum StartEnd { START, END }; void CodeDeoptEvent(Code* code); + void CurrentTimeEvent(); void TimerEvent(StartEnd se, const char* name); diff --git a/src/runtime.cc b/src/runtime.cc index 13a45d5..d5903a0 100644 --- a/src/runtime.cc +++ b/src/runtime.cc @@ -9636,6 +9636,7 @@ RUNTIME_FUNCTION(Runtime_DebugTrace) { RUNTIME_FUNCTION(Runtime_DateCurrentTime) { HandleScope scope(isolate); ASSERT(args.length() == 0); + if (FLAG_log_timer_events) LOG(isolate, CurrentTimeEvent()); // According to ECMA-262, section 15.9.1, page 117, the precision of // the number in a Date object representing a particular instant in diff --git a/tools/profviz/composer.js b/tools/profviz/composer.js index 8c187e5..0520472 100644 --- a/tools/profviz/composer.js +++ b/tools/profviz/composer.js @@ -43,6 +43,7 @@ function PlotScriptComposer(kResX, kResY, error_output) { var kY1Offset = 11; // Offset for stack frame vs. event lines. var kDeoptRow = 7; // Row displaying deopts. + var kGetTimeHeight = 0.5; // Height of marker displaying timed part. var kMaxDeoptLength = 4; // Draw size of the largest deopt. var kPauseLabelPadding = 5; // Padding for pause time labels. var kNumPauseLabels = 7; // Number of biggest pauses to label. @@ -136,6 +137,7 @@ function PlotScriptComposer(kResX, kResY, error_output) { var code_map = new CodeMap(); var execution_pauses = []; var deopts = []; + var gettime = []; var event_stack = []; var last_time_stamp = []; for (var i = 0; i < kNumThreads; i++) { @@ -274,6 +276,10 @@ function PlotScriptComposer(kResX, kResY, error_output) { deopts.push(new Deopt(time, size)); } + var processCurrentTimeEvent = function(time) { + gettime.push(time); + } + var processSharedLibrary = function(name, start, end) { var code_entry = new CodeMap.CodeEntry(end - start, name); code_entry.kind = -3; // External code kind. @@ -316,6 +322,8 @@ function PlotScriptComposer(kResX, kResY, error_output) { processor: processCodeDeleteEvent }, 'code-deopt': { parsers: [parseTimeStamp, parseInt], processor: processCodeDeoptEvent }, + 'current-time': { parsers: [parseTimeStamp], + processor: processCurrentTimeEvent }, 'tick': { parsers: [parseInt, parseTimeStamp, null, null, parseInt, 'var-args'], processor: processTickEvent } @@ -391,12 +399,15 @@ function PlotScriptComposer(kResX, kResY, error_output) { output("set xtics out nomirror"); output("unset key"); - function DrawBarBase(color, start, end, top, bottom) { + function DrawBarBase(color, start, end, top, bottom, transparency) { obj_index++; command = "set object " + obj_index + " rect"; command += " from " + start + ", " + top; command += " to " + end + ", " + bottom; command += " fc rgb \"" + color + "\""; + if (transparency) { + command += " fs transparent solid " + transparency; + } output(command); } @@ -430,6 +441,13 @@ function PlotScriptComposer(kResX, kResY, error_output) { deopt.size / max_deopt_size * kMaxDeoptLength); } + // Plot current time polls. + if (gettime.length > 1) { + var start = gettime[0]; + var end = gettime.pop(); + DrawBarBase("#0000BB", start, end, kGetTimeHeight, 0, 0.2); + } + // Name Y-axis. var ytics = []; for (name in TimerEvents) { -- 2.7.4