Skip to content

Commit c280fe8

Browse files
committed
fix(benchpress): support nested intervals
Chrome sometimes reports nested `FunctionCall` intervals in the timeline, which should be ignored for measuring the `script` metric. Might solve angular#2116
1 parent b071b66 commit c280fe8

File tree

2 files changed

+47
-25
lines changed

2 files changed

+47
-25
lines changed

modules/benchpress/src/metric/perflog_metric.ts

Lines changed: 34 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -168,7 +168,8 @@ export class PerflogMetric extends Metric {
168168
var gcTimeInScript = 0;
169169
var renderTimeInScript = 0;
170170

171-
var intervalStarts = {};
171+
var intervalStarts: StringMap<string, any> = {};
172+
var intervalStartCount: StringMap<string, number> = {};
172173
events.forEach((event) => {
173174
var ph = event['ph'];
174175
var name = event['name'];
@@ -187,33 +188,41 @@ export class PerflogMetric extends Metric {
187188
if (isPresent(markStartEvent) && isBlank(markEndEvent) &&
188189
event['pid'] === markStartEvent['pid']) {
189190
if (StringWrapper.equals(ph, 'B') || StringWrapper.equals(ph, 'b')) {
190-
intervalStarts[name] = event;
191+
if (isBlank(intervalStarts[name])) {
192+
intervalStartCount[name] = 1;
193+
intervalStarts[name] = event;
194+
} else {
195+
intervalStartCount[name]++;
196+
}
191197
} else if ((StringWrapper.equals(ph, 'E') || StringWrapper.equals(ph, 'e')) &&
192198
isPresent(intervalStarts[name])) {
193-
var startEvent = intervalStarts[name];
194-
var duration = (event['ts'] - startEvent['ts']);
195-
intervalStarts[name] = null;
196-
if (StringWrapper.equals(name, 'gc')) {
197-
result['gcTime'] += duration;
198-
var amount =
199-
(startEvent['args']['usedHeapSize'] - event['args']['usedHeapSize']) / 1000;
200-
result['gcAmount'] += amount;
201-
var majorGc = event['args']['majorGc'];
202-
if (isPresent(majorGc) && majorGc) {
203-
result['majorGcTime'] += duration;
204-
}
205-
if (isPresent(intervalStarts['script'])) {
206-
gcTimeInScript += duration;
207-
}
208-
} else if (StringWrapper.equals(name, 'render')) {
209-
result['renderTime'] += duration;
210-
if (isPresent(intervalStarts['script'])) {
211-
renderTimeInScript += duration;
199+
intervalStartCount[name]--;
200+
if (intervalStartCount[name] === 0) {
201+
var startEvent = intervalStarts[name];
202+
var duration = (event['ts'] - startEvent['ts']);
203+
intervalStarts[name] = null;
204+
if (StringWrapper.equals(name, 'gc')) {
205+
result['gcTime'] += duration;
206+
var amount =
207+
(startEvent['args']['usedHeapSize'] - event['args']['usedHeapSize']) / 1000;
208+
result['gcAmount'] += amount;
209+
var majorGc = event['args']['majorGc'];
210+
if (isPresent(majorGc) && majorGc) {
211+
result['majorGcTime'] += duration;
212+
}
213+
if (isPresent(intervalStarts['script'])) {
214+
gcTimeInScript += duration;
215+
}
216+
} else if (StringWrapper.equals(name, 'render')) {
217+
result['renderTime'] += duration;
218+
if (isPresent(intervalStarts['script'])) {
219+
renderTimeInScript += duration;
220+
}
221+
} else if (StringWrapper.equals(name, 'script')) {
222+
result['scriptTime'] += duration;
223+
} else if (isPresent(this._microMetrics[name])) {
224+
result[name] += duration / microIterations;
212225
}
213-
} else if (StringWrapper.equals(name, 'script')) {
214-
result['scriptTime'] += duration;
215-
} else if (isPresent(this._microMetrics[name])) {
216-
result[name] += duration / microIterations;
217226
}
218227
}
219228
}

modules/benchpress/test/metric/perflog_metric_spec.ts

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -343,6 +343,19 @@ export function main() {
343343
});
344344
}));
345345

346+
it('should ignore nested intervals', inject([AsyncTestCompleter], (async) => {
347+
aggregate([
348+
eventFactory.start('script', 0),
349+
eventFactory.start('script', 5),
350+
eventFactory.end('script', 10),
351+
eventFactory.end('script', 17)
352+
])
353+
.then((data) => {
354+
expect(data['scriptTime']).toBe(17);
355+
async.done();
356+
});
357+
}));
358+
346359
it('should ignore events from different processed as the start mark',
347360
inject([AsyncTestCompleter], (async) => {
348361
var otherProcessEventFactory = new TraceEventFactory('timeline', 'pid1');

0 commit comments

Comments
 (0)