From c280fe816cb6ac79a7aa8468f8fa18aaca75c7ba Mon Sep 17 00:00:00 2001 From: Tobias Bosch Date: Wed, 3 Jun 2015 09:47:15 -0700 Subject: [PATCH] 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 #2116 --- .../benchpress/src/metric/perflog_metric.ts | 59 +++++++++++-------- .../test/metric/perflog_metric_spec.ts | 13 ++++ 2 files changed, 47 insertions(+), 25 deletions(-) diff --git a/modules/benchpress/src/metric/perflog_metric.ts b/modules/benchpress/src/metric/perflog_metric.ts index 304a845311..1044a15fda 100644 --- a/modules/benchpress/src/metric/perflog_metric.ts +++ b/modules/benchpress/src/metric/perflog_metric.ts @@ -168,7 +168,8 @@ export class PerflogMetric extends Metric { var gcTimeInScript = 0; var renderTimeInScript = 0; - var intervalStarts = {}; + var intervalStarts: StringMap = {}; + var intervalStartCount: StringMap = {}; events.forEach((event) => { var ph = event['ph']; var name = event['name']; @@ -187,33 +188,41 @@ export class PerflogMetric extends Metric { if (isPresent(markStartEvent) && isBlank(markEndEvent) && event['pid'] === markStartEvent['pid']) { if (StringWrapper.equals(ph, 'B') || StringWrapper.equals(ph, 'b')) { - intervalStarts[name] = event; + if (isBlank(intervalStarts[name])) { + intervalStartCount[name] = 1; + intervalStarts[name] = event; + } else { + intervalStartCount[name]++; + } } else if ((StringWrapper.equals(ph, 'E') || StringWrapper.equals(ph, 'e')) && isPresent(intervalStarts[name])) { - var startEvent = intervalStarts[name]; - var duration = (event['ts'] - startEvent['ts']); - intervalStarts[name] = null; - if (StringWrapper.equals(name, 'gc')) { - result['gcTime'] += duration; - var amount = - (startEvent['args']['usedHeapSize'] - event['args']['usedHeapSize']) / 1000; - result['gcAmount'] += amount; - var majorGc = event['args']['majorGc']; - if (isPresent(majorGc) && majorGc) { - result['majorGcTime'] += duration; + intervalStartCount[name]--; + if (intervalStartCount[name] === 0) { + var startEvent = intervalStarts[name]; + var duration = (event['ts'] - startEvent['ts']); + intervalStarts[name] = null; + if (StringWrapper.equals(name, 'gc')) { + result['gcTime'] += duration; + var amount = + (startEvent['args']['usedHeapSize'] - event['args']['usedHeapSize']) / 1000; + result['gcAmount'] += amount; + var majorGc = event['args']['majorGc']; + if (isPresent(majorGc) && majorGc) { + result['majorGcTime'] += duration; + } + if (isPresent(intervalStarts['script'])) { + gcTimeInScript += duration; + } + } else if (StringWrapper.equals(name, 'render')) { + result['renderTime'] += duration; + if (isPresent(intervalStarts['script'])) { + renderTimeInScript += duration; + } + } else if (StringWrapper.equals(name, 'script')) { + result['scriptTime'] += duration; + } else if (isPresent(this._microMetrics[name])) { + result[name] += duration / microIterations; } - if (isPresent(intervalStarts['script'])) { - gcTimeInScript += duration; - } - } else if (StringWrapper.equals(name, 'render')) { - result['renderTime'] += duration; - if (isPresent(intervalStarts['script'])) { - renderTimeInScript += duration; - } - } else if (StringWrapper.equals(name, 'script')) { - result['scriptTime'] += duration; - } else if (isPresent(this._microMetrics[name])) { - result[name] += duration / microIterations; } } } diff --git a/modules/benchpress/test/metric/perflog_metric_spec.ts b/modules/benchpress/test/metric/perflog_metric_spec.ts index ba1d4ba1cf..3a3e6e3b24 100644 --- a/modules/benchpress/test/metric/perflog_metric_spec.ts +++ b/modules/benchpress/test/metric/perflog_metric_spec.ts @@ -343,6 +343,19 @@ export function main() { }); })); + it('should ignore nested intervals', inject([AsyncTestCompleter], (async) => { + aggregate([ + eventFactory.start('script', 0), + eventFactory.start('script', 5), + eventFactory.end('script', 10), + eventFactory.end('script', 17) + ]) + .then((data) => { + expect(data['scriptTime']).toBe(17); + async.done(); + }); + })); + it('should ignore events from different processed as the start mark', inject([AsyncTestCompleter], (async) => { var otherProcessEventFactory = new TraceEventFactory('timeline', 'pid1');