Commit 56d8b279 authored by Alexei Filippov's avatar Alexei Filippov Committed by Commit Bot

DevTools: Fix loading CPU profiles having last GC sample

When the last sample in a profile happen to be a (garbage collector), the
forEachFrame function failed to close last opened stack frames.

BUG=822909

Change-Id: I5165491e1aa1b92466aec339aa848186c89eb9f9
Reviewed-on: https://chromium-review.googlesource.com/967272
Commit-Queue: Alexei Filippov <alph@chromium.org>
Reviewed-by: default avatarAndrey Kosyakov <caseq@chromium.org>
Cr-Commit-Position: refs/heads/master@{#543880}
parent c367e9d9
Tests profile ending with GC node is parsed correctly.
Profile tree:
(root) id:1 total:3 self:0 depth:-1
(garbage collector) id:2 total:1 self:1 depth:0
foo id:3 total:2 self:1 depth:0
bar id:4 total:1 self:1 depth:1
samples: 4, 4, 3, 4, 2
timestamps: 1, 1.5, 1.75, 2.75, 3, 4
forEachFrame iterator structure:
+ 0 foo 1
+ 1 bar 1
- 1 bar 1 0.75 0.75
+ 1 bar 2.75
+ 2 (garbage collector) 3
- 2 (garbage collector) 3 1 1
- 1 bar 2.75 1.25 0.25
- 0 foo 1 3 1
// Copyright 2018 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
(async function() {
TestRunner.addResult(`Tests profile ending with GC node is parsed correctly.`);
await TestRunner.loadModule('cpu_profiler_test_runner');
var profile = {
startTime: 1000,
endTime: 4000,
nodes: [
{id: 1, hitCount: 0, callFrame: {functionName: '(root)'}, children: [2,3]},
{id: 2, hitCount: 1000, callFrame: {functionName: '(garbage collector)'}},
{id: 3, hitCount: 1000, callFrame: {functionName: 'foo'}, children: [4]},
{id: 4, hitCount: 1000, callFrame: {functionName: 'bar'}}
],
timeDeltas: [500, 250, 1000, 250, 1000],
samples: [4, 4, 3, 4, 2]
};
var model = new SDK.CPUProfileDataModel(profile);
TestRunner.addResult('Profile tree:');
printTree('', model.profileHead);
function printTree(padding, node) {
TestRunner.addResult(
`${padding}${node.functionName} id:${node.id} total:${node.total} self:${node.self} depth:${node.depth}`);
node.children.sort((a, b) => a.id - b.id).forEach(printTree.bind(null, padding + ' '));
}
TestRunner.addResult('samples: ' + model.samples.join(', '));
TestRunner.addResult('timestamps: ' + model.timestamps.join(', '));
TestRunner.addResult('forEachFrame iterator structure:');
model.forEachFrame(
(depth, node, ts) =>
TestRunner.addResult(' '.repeat(depth) + `+ ${depth} ${node.callFrame.functionName} ${ts}`),
(depth, node, ts, total, self) =>
TestRunner.addResult(' '.repeat(depth) + `- ${depth} ${node.callFrame.functionName} ${ts} ${total} ${self}`),
);
TestRunner.completeTest();
})();
Tests streaming CPU profile within trace log.
JSFrame: 111.000 / 6.500 foo
JSFrame: 114.500 / 2.500 bar
JSFrame: 110.000 / 7.000 foo
JSFrame: 114.000 / 2.000 bar
......@@ -8,19 +8,19 @@ InvalidateLayout: 210 0.00/0.00
Layout: 220 50.00/50.00
Program: 400 40.00/100.00
EventDispatch: 410 40.00/60.00
FunctionCall: 420 1.00/10.00
FunctionCall: 420 0.00/10.00
JSSample: 420 0.00/0.00
JSFrame: 420 5.00/10.00
JSSample: 421 0.00/0.00
JSFrame: 421 4.00/9.00
JSFrame: 422 3.00/3.00
JSSample: 422 0.00/0.00
JSFrame: 423 3.00/3.00
JSSample: 423 0.00/0.00
JSSample: 424 0.00/0.00
JSSample: 425 0.00/0.00
JSFrame: 425 2.00/2.00
JSSample: 426 0.00/0.00
JSFrame: 426 2.00/2.00
JSSample: 427 0.00/0.00
JSSample: 428 0.00/0.00
JSSample: 429 0.00/0.00
FunctionCall: 440 10.00/10.00
Animation: 445 0.00/800.00
timestamp: 450 0.00/895.00
......
......@@ -91,11 +91,12 @@ SDK.CPUProfileDataModel = class extends SDK.ProfileTreeModel {
if (!profile.timeDeltas)
return null;
let lastTimeUsec = profile.startTime;
const timestamps = new Array(profile.timeDeltas.length);
for (let i = 0; i < timestamps.length; ++i) {
lastTimeUsec += profile.timeDeltas[i];
const timestamps = new Array(profile.timeDeltas.length + 1);
for (let i = 0; i < profile.timeDeltas.length; ++i) {
timestamps[i] = lastTimeUsec;
lastTimeUsec += profile.timeDeltas[i];
}
timestamps[profile.timeDeltas.length] = lastTimeUsec;
return timestamps;
}
......@@ -210,9 +211,12 @@ SDK.CPUProfileDataModel = class extends SDK.ProfileTreeModel {
// Convert samples from usec to msec
for (let i = 0; i < timestamps.length; ++i)
timestamps[i] /= 1000;
const averageSample = (timestamps.peekLast() - timestamps[0]) / (timestamps.length - 1);
// Add an extra timestamp used to calculate the last sample duration.
this.timestamps.push(timestamps.peekLast() + averageSample);
if (this.samples.length === timestamps.length) {
// Support for a legacy format where were no timeDeltas.
// Add an extra timestamp used to calculate the last sample duration.
const averageSample = (timestamps.peekLast() - timestamps[0]) / (timestamps.length - 1);
this.timestamps.push(timestamps.peekLast() + averageSample);
}
this.profileStartTime = timestamps[0];
this.profileEndTime = timestamps.peekLast();
}
......@@ -263,18 +267,22 @@ SDK.CPUProfileDataModel = class extends SDK.ProfileTreeModel {
let stackTop = 0;
const stackNodes = [];
let prevId = this.profileHead.id;
let sampleTime = timestamps[samplesCount];
let sampleTime;
let gcParentNode = null;
// Extra slots for gc being put on top,
// and one at the bottom to allow safe stackTop-1 access.
const stackDepth = this.maxDepth + 3;
if (!this._stackStartTimes)
this._stackStartTimes = new Float64Array(this.maxDepth + 2);
this._stackStartTimes = new Float64Array(stackDepth);
const stackStartTimes = this._stackStartTimes;
if (!this._stackChildrenDuration)
this._stackChildrenDuration = new Float64Array(this.maxDepth + 2);
this._stackChildrenDuration = new Float64Array(stackDepth);
const stackChildrenDuration = this._stackChildrenDuration;
let node;
for (let sampleIndex = startIndex; sampleIndex < samplesCount; sampleIndex++) {
let sampleIndex;
for (sampleIndex = startIndex; sampleIndex < samplesCount; sampleIndex++) {
sampleTime = timestamps[sampleIndex];
if (sampleTime >= stopTime)
break;
......@@ -337,12 +345,14 @@ SDK.CPUProfileDataModel = class extends SDK.ProfileTreeModel {
prevId = id;
}
sampleTime = timestamps[sampleIndex] || this.profileEndTime;
if (idToNode.get(prevId) === gcNode) {
const start = stackStartTimes[stackTop];
const duration = sampleTime - start;
stackChildrenDuration[stackTop - 1] += duration;
closeFrameCallback(gcParentNode.depth + 1, node, start, duration, duration - stackChildrenDuration[stackTop]);
--stackTop;
prevId = gcParentNode.id;
}
for (let node = idToNode.get(prevId); node.parent; node = node.parent) {
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment