Reviewers: Jakob,
Description:
Log deopts with --log-timer-events.
[email protected]
BUG=
Please review this at https://codereview.chromium.org/17599007/
SVN Base: https://v8.googlecode.com/svn/branches/bleeding_edge
Affected files:
M src/deoptimizer.cc
M src/log.h
M src/log.cc
M tools/profviz/composer.js
Index: src/deoptimizer.cc
diff --git a/src/deoptimizer.cc b/src/deoptimizer.cc
index
eec86978ce4895df3dd74c6ca55e1fb88fa45c54..c7e6139251fdbcb8b126ea4aede7368edee2b3ee
100644
--- a/src/deoptimizer.cc
+++ b/src/deoptimizer.cc
@@ -716,6 +716,10 @@ void Deoptimizer::DoComputeOutputFrames() {
// Print some helpful diagnostic information.
int64_t start = OS::Ticks();
+ if (FLAG_log_timer_events &&
+ compiled_code_->kind() == Code::OPTIMIZED_FUNCTION) {
+ LOG(isolate(), CodeDeoptEvent(compiled_code_));
+ }
if (trace_) {
PrintF("[deoptimizing (DEOPT %s): begin 0x%08" V8PRIxPTR " ",
MessageFor(bailout_type_),
Index: src/log.cc
diff --git a/src/log.cc b/src/log.cc
index
82ce886fc9248cd31f49bca7e691b071bad4ff6c..128d3f8e948abd685a279e1b28d09660a3a6f5b0
100644
--- a/src/log.cc
+++ b/src/log.cc
@@ -637,6 +637,16 @@ void Logger::SharedLibraryEvent(const wchar_t*
library_path,
}
+void Logger::CodeDeoptEvent(Code* code) {
+ if (!log_->IsEnabled()) return;
+ ASSERT(FLAG_log_internal_timer_events);
+ LogMessageBuilder msg(this);
+ int since_epoch = static_cast<int>(OS::Ticks() - epoch_);
+ msg.Append("code-deopt,%ld,%d\n", since_epoch, code->CodeSize());
+ msg.WriteToLogFile();
+}
+
+
void Logger::TimerEvent(StartEnd se, const char* name) {
if (!log_->IsEnabled()) return;
ASSERT(FLAG_log_internal_timer_events);
Index: src/log.h
diff --git a/src/log.h b/src/log.h
index
f6e2ed99e3a13648e2c6b06dd6db054c90e3b9dd..07ecd0efe768da86efeb4159333a008da8ac926c
100644
--- a/src/log.h
+++ b/src/log.h
@@ -293,6 +293,8 @@ class Logger {
// ==== Events logged by --log-timer-events. ====
enum StartEnd { START, END };
+ void CodeDeoptEvent(Code* code);
+
void TimerEvent(StartEnd se, const char* name);
static void EnterExternal(Isolate* isolate);
Index: tools/profviz/composer.js
diff --git a/tools/profviz/composer.js b/tools/profviz/composer.js
index
2f7817928c591f2cd3545bddf21c9018fc20d41a..73d5b36ce277c7f70c8f15381fce1d226eff2308
100644
--- a/tools/profviz/composer.js
+++ b/tools/profviz/composer.js
@@ -41,7 +41,9 @@ function PlotScriptComposer(kResX, kResY) {
var kStackFrameWidth = 0.1; // Width of the lower stack frame
lines.
var kGapWidth = 0.05; // Gap between stack frame lines.
- var kY1Offset = 10; // Offset for stack frame vs. event
lines.
+ var kY1Offset = 11; // Offset for stack frame vs. event
lines.
+ var kDeoptRow = 7; // Row displaying deopts.
+ 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.
var kCodeKindLabelPadding = 100; // Padding for code kind labels.
@@ -52,6 +54,9 @@ function PlotScriptComposer(kResX, kResY) {
var kNumThreads = 2; // Number of threads.
var kExecutionThreadId = 0; // ID of main thread.
+ // Init values.
+ var num_timer_event = kY1Offset + 0.5;
+
// Data structures.
function TimerEvent(label, color, pause, thread_id) {
assert(thread_id >= 0 && thread_id < kNumThreads, "invalid thread id");
@@ -72,9 +77,13 @@ function PlotScriptComposer(kResX, kResY) {
}
function Range(start, end) {
- // Everthing here are in milliseconds.
- this.start = start;
- this.end = end;
+ this.start = start; // In milliseconds.
+ this.end = end; // In milliseconds.
+ }
+
+ function Deopt(time, size) {
+ this.time = time; // In milliseconds.
+ this.size = size; // In bytes.
}
Range.prototype.duration = function() { return this.end - this.start; }
@@ -83,9 +92,6 @@ function PlotScriptComposer(kResX, kResY) {
this.tick = tick;
}
- // Init values.
- var num_timer_event = kY1Offset + 0.5;
-
var TimerEvents = {
'V8.Execute':
new TimerEvent("execution", "#000000", false, 0),
@@ -127,6 +133,7 @@ function PlotScriptComposer(kResX, kResY) {
var code_map = new CodeMap();
var execution_pauses = [];
+ var deopts = [];
var event_stack = [];
var last_time_stamp = [];
for (var i = 0; i < kNumThreads; i++) {
@@ -312,6 +319,10 @@ function PlotScriptComposer(kResX, kResY) {
code_map.deleteCode(address);
};
+ var processCodeDeoptEvent = function(time, size) {
+ deopts.push(new Deopt(time, size));
+ }
+
var processSharedLibrary = function(name, start, end) {
var code_entry = new CodeMap.CodeEntry(end - start, name);
code_entry.kind = -3; // External code kind.
@@ -352,6 +363,8 @@ function PlotScriptComposer(kResX, kResY) {
processor: processCodeMoveEvent },
'code-delete': { parsers: [parseInt],
processor: processCodeDeleteEvent },
+ 'code-deopt': { parsers: [parseTimeStamp, parseInt],
+ processor: processCodeDeoptEvent },
'tick': { parsers: [parseInt, parseInt, parseTimeStamp,
null, null, parseInt, 'var-args'],
processor: processTickEvent }
@@ -422,18 +435,27 @@ function PlotScriptComposer(kResX, kResY) {
output("set style fill pattern 2 bo 1");
output("set style rect fs solid 1 noborder");
output("set style line 1 lt 1 lw 1 lc rgb \"#000000\"");
+ output("set style line 2 lt 1 lw 1 lc rgb \"#9944CC\"");
output("set xtics out nomirror");
output("unset key");
- function DrawBar(row, color, start, end, width) {
+ function DrawBarBase(color, start, end, top, bottom) {
obj_index++;
command = "set object " + obj_index + " rect";
- command += " from " + start + ", " + (row - width);
- command += " to " + end + ", " + (row + width);
+ command += " from " + start + ", " + top;
+ command += " to " + end + ", " + bottom;
command += " fc rgb \"" + color + "\"";
output(command);
}
+ function DrawBar(row, color, start, end, width) {
+ DrawBarBase(color, start, end, row + width, row - width);
+ }
+
+ function DrawHalfBar(row, color, start, end, width) {
+ DrawBarBase(color, start, end, row, row - width);
+ }
+
var percentages = {};
var total = 0;
for (var name in TimerEvents) {
@@ -446,6 +468,17 @@ function PlotScriptComposer(kResX, kResY) {
percentages[name] = (sum / (range_end - range_start) *
100).toFixed(1);
}
+ // Plot deopts.
+ deopts.sort(function(a, b) { return b.size - a.size; });
+ var max_deopt_size = deopts.length > 0 ? deopts[0].size : Infinity;
+
+ for (var i = 0; i < deopts.length; i++) {
+ var deopt = deopts[i];
+ DrawHalfBar(kDeoptRow, "#9944CC", deopt.time,
+ deopt.time + 10 * pause_tolerance,
+ deopt.size / max_deopt_size * kMaxDeoptLength);
+ }
+
// Name Y-axis.
var ytics = [];
for (name in TimerEvents) {
@@ -458,6 +491,8 @@ function PlotScriptComposer(kResX, kResY) {
ytics.push('"top ' + kStackFrames + ' js stack frames"' + ' ' +
(kY1Offset - 2));
ytics.push('"pause times" 0');
+ ytics.push('"max deopt size: ' + (max_deopt_size / 1024).toFixed(1) +
+ ' kB" ' + kDeoptRow);
output("set ytics out nomirror (" + ytics.join(', ') + ")");
// Plot timeline.
--
--
v8-dev mailing list
[email protected]
http://groups.google.com/group/v8-dev
---
You received this message because you are subscribed to the Google Groups "v8-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
For more options, visit https://groups.google.com/groups/opt_out.
