2016-08-03 18:00:07 -04:00
|
|
|
/**
|
|
|
|
* @license
|
|
|
|
* Copyright Google Inc. All Rights Reserved.
|
|
|
|
*
|
|
|
|
* Use of this source code is governed by an MIT-style license that can be
|
|
|
|
* found in the LICENSE file at https://angular.io/license
|
|
|
|
*/
|
|
|
|
|
2016-08-24 16:39:44 -04:00
|
|
|
import {Provider} from '@angular/core';
|
2016-09-27 20:12:25 -04:00
|
|
|
import {AsyncTestCompleter, beforeEach, describe, expect, inject, it} from '@angular/core/testing/testing_internal';
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
import {Metric, Options, PerfLogEvent, PerfLogFeatures, PerflogMetric, ReflectiveInjector, WebDriverExtension} from '../../index';
|
|
|
|
import {StringMapWrapper} from '../../src/facade/collection';
|
2016-09-30 12:26:53 -04:00
|
|
|
import {isPresent} from '../../src/facade/lang';
|
2015-05-27 17:57:54 -04:00
|
|
|
import {TraceEventFactory} from '../trace_event_factory';
|
|
|
|
|
|
|
|
export function main() {
|
2015-06-17 14:17:21 -04:00
|
|
|
var commandLog: any[];
|
2015-05-27 17:57:54 -04:00
|
|
|
var eventFactory = new TraceEventFactory('timeline', 'pid0');
|
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
function createMetric(
|
2016-08-26 19:34:08 -04:00
|
|
|
perfLogs: PerfLogEvent[], perfLogFeatures: PerfLogFeatures,
|
2016-08-03 18:00:07 -04:00
|
|
|
{microMetrics, forceGc, captureFrames, receivedData, requestCount}: {
|
|
|
|
microMetrics?: {[key: string]: string},
|
|
|
|
forceGc?: boolean,
|
|
|
|
captureFrames?: boolean,
|
|
|
|
receivedData?: boolean,
|
|
|
|
requestCount?: boolean
|
|
|
|
} = {}): Metric {
|
2015-05-27 17:57:54 -04:00
|
|
|
commandLog = [];
|
2016-09-30 12:26:53 -04:00
|
|
|
if (!perfLogFeatures) {
|
2015-12-09 20:15:55 -05:00
|
|
|
perfLogFeatures =
|
|
|
|
new PerfLogFeatures({render: true, gc: true, frameCapture: true, userTiming: true});
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
2016-09-30 12:26:53 -04:00
|
|
|
if (!microMetrics) {
|
2016-09-19 20:15:57 -04:00
|
|
|
microMetrics = {};
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
2016-08-24 16:39:44 -04:00
|
|
|
var providers: Provider[] = [
|
2016-08-03 18:00:07 -04:00
|
|
|
Options.DEFAULT_PROVIDERS, PerflogMetric.PROVIDERS,
|
|
|
|
{provide: Options.MICRO_METRICS, useValue: microMetrics}, {
|
2016-06-02 20:30:40 -04:00
|
|
|
provide: PerflogMetric.SET_TIMEOUT,
|
2016-08-26 19:34:08 -04:00
|
|
|
useValue: (fn: Function, millis: number) => {
|
2016-06-02 20:30:40 -04:00
|
|
|
commandLog.push(['setTimeout', millis]);
|
|
|
|
fn();
|
|
|
|
},
|
|
|
|
},
|
|
|
|
{
|
|
|
|
provide: WebDriverExtension,
|
|
|
|
useValue: new MockDriverExtension(perfLogs, commandLog, perfLogFeatures)
|
|
|
|
}
|
2015-05-27 17:57:54 -04:00
|
|
|
];
|
|
|
|
if (isPresent(forceGc)) {
|
2016-08-03 15:32:26 -04:00
|
|
|
providers.push({provide: Options.FORCE_GC, useValue: forceGc});
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
2015-06-09 18:19:26 -04:00
|
|
|
if (isPresent(captureFrames)) {
|
2016-06-02 20:30:40 -04:00
|
|
|
providers.push({provide: Options.CAPTURE_FRAMES, useValue: captureFrames});
|
2015-06-09 18:19:26 -04:00
|
|
|
}
|
2015-12-09 20:15:55 -05:00
|
|
|
if (isPresent(receivedData)) {
|
2016-06-02 20:30:40 -04:00
|
|
|
providers.push({provide: Options.RECEIVED_DATA, useValue: receivedData});
|
2015-12-09 20:15:55 -05:00
|
|
|
}
|
|
|
|
if (isPresent(requestCount)) {
|
2016-06-02 20:30:40 -04:00
|
|
|
providers.push({provide: Options.REQUEST_COUNT, useValue: requestCount});
|
2015-12-09 20:15:55 -05:00
|
|
|
}
|
2016-03-21 06:57:17 -04:00
|
|
|
return ReflectiveInjector.resolveAndCreate(providers).get(PerflogMetric);
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
|
|
|
|
|
|
|
describe('perflog metric', () => {
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
function sortedKeys(stringMap: {[key: string]: any}) {
|
|
|
|
var res: string[] = [];
|
2015-06-17 14:17:21 -04:00
|
|
|
StringMapWrapper.forEach(stringMap, (_, key) => { res.push(key); });
|
2015-05-27 17:57:54 -04:00
|
|
|
res.sort();
|
|
|
|
return res;
|
|
|
|
}
|
|
|
|
|
|
|
|
it('should describe itself based on the perfLogFeatrues', () => {
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(sortedKeys(createMetric([[]], new PerfLogFeatures()).describe())).toEqual([
|
|
|
|
'pureScriptTime', 'scriptTime'
|
|
|
|
]);
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2015-12-09 20:15:55 -05:00
|
|
|
expect(
|
|
|
|
sortedKeys(createMetric([[]], new PerfLogFeatures({render: true, gc: false})).describe()))
|
2015-05-27 17:57:54 -04:00
|
|
|
.toEqual(['pureScriptTime', 'renderTime', 'scriptTime']);
|
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(sortedKeys(createMetric([[]], null).describe())).toEqual([
|
|
|
|
'gcAmount', 'gcTime', 'majorGcTime', 'pureScriptTime', 'renderTime', 'scriptTime'
|
|
|
|
]);
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(sortedKeys(createMetric([[]], new PerfLogFeatures({render: true, gc: true}), {
|
|
|
|
forceGc: true
|
|
|
|
}).describe()))
|
2015-05-27 17:57:54 -04:00
|
|
|
.toEqual([
|
2016-08-03 18:00:07 -04:00
|
|
|
'forcedGcAmount', 'forcedGcTime', 'gcAmount', 'gcTime', 'majorGcTime', 'pureScriptTime',
|
|
|
|
'renderTime', 'scriptTime'
|
2015-05-27 17:57:54 -04:00
|
|
|
]);
|
2015-12-09 20:15:55 -05:00
|
|
|
|
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(sortedKeys(createMetric([[]], new PerfLogFeatures({userTiming: true}), {
|
|
|
|
receivedData: true,
|
|
|
|
requestCount: true
|
|
|
|
}).describe()))
|
2015-12-09 20:15:55 -05:00
|
|
|
.toEqual(['pureScriptTime', 'receivedData', 'requestCount', 'scriptTime']);
|
2015-05-27 17:57:54 -04:00
|
|
|
});
|
|
|
|
|
|
|
|
it('should describe itself based on micro metrics', () => {
|
2015-12-09 20:15:55 -05:00
|
|
|
var description =
|
|
|
|
createMetric([[]], null, {microMetrics: {'myMicroMetric': 'someDesc'}}).describe();
|
2015-05-27 17:57:54 -04:00
|
|
|
expect(description['myMicroMetric']).toEqual('someDesc');
|
|
|
|
});
|
|
|
|
|
2015-06-09 18:19:26 -04:00
|
|
|
it('should describe itself if frame capture is requested and available', () => {
|
2016-08-03 18:00:07 -04:00
|
|
|
var description = createMetric([[]], new PerfLogFeatures({frameCapture: true}), {
|
|
|
|
captureFrames: true
|
|
|
|
}).describe();
|
2015-06-15 14:05:16 -04:00
|
|
|
expect(description['frameTime.mean']).not.toContain('WARNING');
|
|
|
|
expect(description['frameTime.best']).not.toContain('WARNING');
|
|
|
|
expect(description['frameTime.worst']).not.toContain('WARNING');
|
|
|
|
expect(description['frameTime.smooth']).not.toContain('WARNING');
|
2015-06-09 18:19:26 -04:00
|
|
|
});
|
|
|
|
|
|
|
|
it('should describe itself if frame capture is requested and not available', () => {
|
2016-08-03 18:00:07 -04:00
|
|
|
var description = createMetric([[]], new PerfLogFeatures({frameCapture: false}), {
|
|
|
|
captureFrames: true
|
|
|
|
}).describe();
|
2015-06-15 14:05:16 -04:00
|
|
|
expect(description['frameTime.mean']).toContain('WARNING');
|
|
|
|
expect(description['frameTime.best']).toContain('WARNING');
|
|
|
|
expect(description['frameTime.worst']).toContain('WARNING');
|
|
|
|
expect(description['frameTime.smooth']).toContain('WARNING');
|
2015-06-09 18:19:26 -04:00
|
|
|
});
|
|
|
|
|
2015-05-27 17:57:54 -04:00
|
|
|
describe('beginMeasure', () => {
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should not force gc and mark the timeline',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric([[]], null);
|
2015-05-27 17:57:54 -04:00
|
|
|
metric.beginMeasure().then((_) => {
|
|
|
|
expect(commandLog).toEqual([['timeBegin', 'benchpress0']]);
|
|
|
|
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should force gc and mark the timeline',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric([[]], null, {forceGc: true});
|
2015-05-27 17:57:54 -04:00
|
|
|
metric.beginMeasure().then((_) => {
|
|
|
|
expect(commandLog).toEqual([['gc'], ['timeBegin', 'benchpress0']]);
|
|
|
|
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
});
|
|
|
|
|
|
|
|
describe('endMeasure', () => {
|
|
|
|
|
|
|
|
it('should mark and aggregate events in between the marks',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
var events = [[
|
|
|
|
eventFactory.markStart('benchpress0', 0), eventFactory.start('script', 4),
|
|
|
|
eventFactory.end('script', 6), eventFactory.markEnd('benchpress0', 10)
|
|
|
|
]];
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric(events, null);
|
2016-08-03 18:00:07 -04:00
|
|
|
metric.beginMeasure().then((_) => metric.endMeasure(false)).then((data) => {
|
|
|
|
expect(commandLog).toEqual([
|
|
|
|
['timeBegin', 'benchpress0'], ['timeEnd', 'benchpress0', null], 'readPerfLog'
|
|
|
|
]);
|
|
|
|
expect(data['scriptTime']).toBe(2);
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-09-15 11:51:55 -04:00
|
|
|
it('should mark and aggregate events since navigationStart',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
|
|
|
var events = [[
|
|
|
|
eventFactory.markStart('benchpress0', 0), eventFactory.start('script', 4),
|
|
|
|
eventFactory.end('script', 6), eventFactory.instant('navigationStart', 7),
|
|
|
|
eventFactory.start('script', 8), eventFactory.end('script', 9),
|
|
|
|
eventFactory.markEnd('benchpress0', 10)
|
|
|
|
]];
|
|
|
|
var metric = createMetric(events, null);
|
|
|
|
metric.beginMeasure().then((_) => metric.endMeasure(false)).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(1);
|
|
|
|
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should restart timing', inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
var events = [
|
|
|
|
[
|
|
|
|
eventFactory.markStart('benchpress0', 0),
|
|
|
|
eventFactory.markEnd('benchpress0', 1),
|
|
|
|
eventFactory.markStart('benchpress1', 2),
|
|
|
|
],
|
|
|
|
[eventFactory.markEnd('benchpress1', 3)]
|
|
|
|
];
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric(events, null);
|
2015-05-27 17:57:54 -04:00
|
|
|
metric.beginMeasure()
|
|
|
|
.then((_) => metric.endMeasure(true))
|
|
|
|
.then((_) => metric.endMeasure(true))
|
|
|
|
.then((_) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(commandLog).toEqual([
|
|
|
|
['timeBegin', 'benchpress0'], ['timeEnd', 'benchpress0', 'benchpress1'],
|
|
|
|
'readPerfLog', ['timeEnd', 'benchpress1', 'benchpress2'], 'readPerfLog'
|
|
|
|
]);
|
2015-05-27 17:57:54 -04:00
|
|
|
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
it('should loop and aggregate until the end mark is present',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
var events = [
|
|
|
|
[eventFactory.markStart('benchpress0', 0), eventFactory.start('script', 1)],
|
|
|
|
[eventFactory.end('script', 2)],
|
|
|
|
[
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.start('script', 3), eventFactory.end('script', 5),
|
2015-05-27 17:57:54 -04:00
|
|
|
eventFactory.markEnd('benchpress0', 10)
|
|
|
|
]
|
|
|
|
];
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric(events, null);
|
2016-08-03 18:00:07 -04:00
|
|
|
metric.beginMeasure().then((_) => metric.endMeasure(false)).then((data) => {
|
|
|
|
expect(commandLog).toEqual([
|
|
|
|
['timeBegin', 'benchpress0'], ['timeEnd', 'benchpress0', null], 'readPerfLog',
|
|
|
|
['setTimeout', 100], 'readPerfLog', ['setTimeout', 100], 'readPerfLog'
|
|
|
|
]);
|
|
|
|
expect(data['scriptTime']).toBe(3);
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
|
|
|
it('should store events after the end mark for the next call',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
var events = [
|
|
|
|
[
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.markStart('benchpress0', 0), eventFactory.markEnd('benchpress0', 1),
|
|
|
|
eventFactory.markStart('benchpress1', 1), eventFactory.start('script', 1),
|
2015-05-27 17:57:54 -04:00
|
|
|
eventFactory.end('script', 2)
|
|
|
|
],
|
|
|
|
[
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.start('script', 3), eventFactory.end('script', 5),
|
2015-05-27 17:57:54 -04:00
|
|
|
eventFactory.markEnd('benchpress1', 6)
|
|
|
|
]
|
|
|
|
];
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric(events, null);
|
2015-05-27 17:57:54 -04:00
|
|
|
metric.beginMeasure()
|
|
|
|
.then((_) => metric.endMeasure(true))
|
2015-06-03 16:42:57 -04:00
|
|
|
.then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(0);
|
2016-08-03 18:00:07 -04:00
|
|
|
return metric.endMeasure(true);
|
2015-06-03 16:42:57 -04:00
|
|
|
})
|
2015-05-27 17:57:54 -04:00
|
|
|
.then((data) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(commandLog).toEqual([
|
|
|
|
['timeBegin', 'benchpress0'], ['timeEnd', 'benchpress0', 'benchpress1'],
|
|
|
|
'readPerfLog', ['timeEnd', 'benchpress1', 'benchpress2'], 'readPerfLog'
|
|
|
|
]);
|
2015-05-27 17:57:54 -04:00
|
|
|
expect(data['scriptTime']).toBe(3);
|
|
|
|
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
describe('with forced gc', () => {
|
2016-08-26 19:34:08 -04:00
|
|
|
var events: PerfLogEvent[][];
|
2015-05-27 17:57:54 -04:00
|
|
|
beforeEach(() => {
|
2016-08-03 18:00:07 -04:00
|
|
|
events = [[
|
|
|
|
eventFactory.markStart('benchpress0', 0), eventFactory.start('script', 4),
|
|
|
|
eventFactory.end('script', 6), eventFactory.markEnd('benchpress0', 10),
|
|
|
|
eventFactory.markStart('benchpress1', 11),
|
|
|
|
eventFactory.start('gc', 12, {'usedHeapSize': 2500}),
|
|
|
|
eventFactory.end('gc', 15, {'usedHeapSize': 1000}),
|
|
|
|
eventFactory.markEnd('benchpress1', 20)
|
|
|
|
]];
|
2015-05-27 17:57:54 -04:00
|
|
|
});
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should measure forced gc', inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric(events, null, {forceGc: true});
|
2016-08-03 18:00:07 -04:00
|
|
|
metric.beginMeasure().then((_) => metric.endMeasure(false)).then((data) => {
|
|
|
|
expect(commandLog).toEqual([
|
|
|
|
['gc'], ['timeBegin', 'benchpress0'], ['timeEnd', 'benchpress0', 'benchpress1'],
|
|
|
|
'readPerfLog', ['gc'], ['timeEnd', 'benchpress1', null], 'readPerfLog'
|
|
|
|
]);
|
|
|
|
expect(data['forcedGcTime']).toBe(3);
|
|
|
|
expect(data['forcedGcAmount']).toBe(1.5);
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should restart after the forced gc if needed',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric(events, null, {forceGc: true});
|
2016-08-03 18:00:07 -04:00
|
|
|
metric.beginMeasure().then((_) => metric.endMeasure(true)).then((data) => {
|
|
|
|
expect(commandLog[5]).toEqual(['timeEnd', 'benchpress1', 'benchpress2']);
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
|
|
|
});
|
|
|
|
|
|
|
|
});
|
|
|
|
|
|
|
|
describe('aggregation', () => {
|
|
|
|
|
2015-12-09 20:15:55 -05:00
|
|
|
function aggregate(events: any[], {microMetrics, captureFrames, receivedData, requestCount}: {
|
|
|
|
microMetrics?: {[key: string]: string},
|
|
|
|
captureFrames?: boolean,
|
|
|
|
receivedData?: boolean,
|
|
|
|
requestCount?: boolean
|
|
|
|
} = {}) {
|
2015-10-07 12:09:43 -04:00
|
|
|
events.unshift(eventFactory.markStart('benchpress0', 0));
|
2015-06-17 14:17:21 -04:00
|
|
|
events.push(eventFactory.markEnd('benchpress0', 10));
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric([events], null, {
|
|
|
|
microMetrics: microMetrics,
|
|
|
|
captureFrames: captureFrames,
|
|
|
|
receivedData: receivedData,
|
|
|
|
requestCount: requestCount
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
return metric.beginMeasure().then((_) => metric.endMeasure(false));
|
|
|
|
}
|
|
|
|
|
2015-06-09 18:19:26 -04:00
|
|
|
describe('frame metrics', () => {
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should calculate mean frame time',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-06-19 13:18:44 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.markStart('frameCapture', 0), eventFactory.instant('frame', 1),
|
|
|
|
eventFactory.instant('frame', 3), eventFactory.instant('frame', 4),
|
2015-06-19 13:18:44 -04:00
|
|
|
eventFactory.markEnd('frameCapture', 5)
|
|
|
|
],
|
2015-12-09 20:15:55 -05:00
|
|
|
{captureFrames: true})
|
2015-06-09 18:19:26 -04:00
|
|
|
.then((data) => {
|
2015-06-15 14:05:16 -04:00
|
|
|
expect(data['frameTime.mean']).toBe(((3 - 1) + (4 - 3)) / 2);
|
2015-06-09 18:19:26 -04:00
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should throw if no start event',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-02 18:53:34 -04:00
|
|
|
|
|
|
|
aggregate(
|
|
|
|
[eventFactory.instant('frame', 4), eventFactory.markEnd('frameCapture', 5)],
|
|
|
|
{captureFrames: true})
|
|
|
|
.catch((err): any => {
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(() => {
|
|
|
|
throw err;
|
|
|
|
}).toThrowError('missing start event for frame capture');
|
2015-06-09 18:19:26 -04:00
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should throw if no end event',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-02 18:53:34 -04:00
|
|
|
|
|
|
|
aggregate(
|
|
|
|
[eventFactory.markStart('frameCapture', 3), eventFactory.instant('frame', 4)],
|
|
|
|
{captureFrames: true})
|
|
|
|
.catch((err): any => {
|
2015-06-09 18:19:26 -04:00
|
|
|
expect(() => { throw err; }).toThrowError('missing end event for frame capture');
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should throw if trying to capture twice',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-02 18:53:34 -04:00
|
|
|
|
|
|
|
aggregate(
|
|
|
|
[
|
|
|
|
eventFactory.markStart('frameCapture', 3),
|
|
|
|
eventFactory.markStart('frameCapture', 4)
|
|
|
|
],
|
|
|
|
{captureFrames: true})
|
|
|
|
.catch((err): any => {
|
2016-08-03 18:00:07 -04:00
|
|
|
expect(() => {
|
|
|
|
throw err;
|
|
|
|
}).toThrowError('can capture frames only once per benchmark run');
|
2015-06-09 18:19:26 -04:00
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
it('should throw if trying to capture when frame capture is disabled',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-02 18:53:34 -04:00
|
|
|
aggregate([eventFactory.markStart('frameCapture', 3)]).catch((err) => {
|
2015-06-09 18:19:26 -04:00
|
|
|
expect(() => { throw err; })
|
|
|
|
.toThrowError(
|
|
|
|
'found start event for frame capture, but frame capture was not requested in benchpress');
|
|
|
|
async.done();
|
2016-02-19 14:49:31 -05:00
|
|
|
return null;
|
2015-06-09 18:19:26 -04:00
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
it('should throw if frame capture is enabled, but nothing is captured',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-02 18:53:34 -04:00
|
|
|
aggregate([], {captureFrames: true}).catch((err): any => {
|
2015-06-09 18:19:26 -04:00
|
|
|
expect(() => { throw err; })
|
|
|
|
.toThrowError(
|
|
|
|
'frame capture requested in benchpress, but no start event was found');
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should calculate best and worst frame time',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-06-19 13:18:44 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.markStart('frameCapture', 0), eventFactory.instant('frame', 1),
|
|
|
|
eventFactory.instant('frame', 9), eventFactory.instant('frame', 15),
|
|
|
|
eventFactory.instant('frame', 18), eventFactory.instant('frame', 28),
|
|
|
|
eventFactory.instant('frame', 32), eventFactory.markEnd('frameCapture', 10)
|
2015-06-19 13:18:44 -04:00
|
|
|
],
|
2015-12-09 20:15:55 -05:00
|
|
|
{captureFrames: true})
|
2015-06-15 14:05:16 -04:00
|
|
|
.then((data) => {
|
|
|
|
expect(data['frameTime.worst']).toBe(10);
|
|
|
|
expect(data['frameTime.best']).toBe(3);
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
it('should calculate percentage of smoothness to be good',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-06-19 13:18:44 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.markStart('frameCapture', 0), eventFactory.instant('frame', 1),
|
|
|
|
eventFactory.instant('frame', 2), eventFactory.instant('frame', 3),
|
2015-06-19 13:18:44 -04:00
|
|
|
eventFactory.markEnd('frameCapture', 4)
|
|
|
|
],
|
2015-12-09 20:15:55 -05:00
|
|
|
{captureFrames: true})
|
2015-06-15 14:05:16 -04:00
|
|
|
.then((data) => {
|
|
|
|
expect(data['frameTime.smooth']).toBe(1.0);
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
it('should calculate percentage of smoothness to be bad',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-06-19 13:18:44 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.markStart('frameCapture', 0), eventFactory.instant('frame', 1),
|
|
|
|
eventFactory.instant('frame', 2), eventFactory.instant('frame', 22),
|
|
|
|
eventFactory.instant('frame', 23), eventFactory.instant('frame', 24),
|
2015-06-19 13:18:44 -04:00
|
|
|
eventFactory.markEnd('frameCapture', 4)
|
|
|
|
],
|
2015-12-09 20:15:55 -05:00
|
|
|
{captureFrames: true})
|
2015-06-15 14:05:16 -04:00
|
|
|
.then((data) => {
|
|
|
|
expect(data['frameTime.smooth']).toBe(0.75);
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
2015-06-09 18:19:26 -04:00
|
|
|
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should report a single interval',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
aggregate([
|
|
|
|
eventFactory.start('script', 0), eventFactory.end('script', 5)
|
|
|
|
]).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(5);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should sum up multiple intervals',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
aggregate([
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.start('script', 0), eventFactory.end('script', 5),
|
|
|
|
eventFactory.start('script', 10), eventFactory.end('script', 17)
|
|
|
|
]).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(12);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should ignore not started intervals',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
aggregate([eventFactory.end('script', 10)]).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(0);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should ignore not ended intervals',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
aggregate([eventFactory.start('script', 10)]).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(0);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should ignore nested intervals',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-06-03 12:47:15 -04:00
|
|
|
aggregate([
|
2016-08-03 18:00:07 -04:00
|
|
|
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();
|
|
|
|
});
|
2015-06-03 12:47:15 -04:00
|
|
|
}));
|
|
|
|
|
2015-05-27 17:57:54 -04:00
|
|
|
it('should ignore events from different processed as the start mark',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
var otherProcessEventFactory = new TraceEventFactory('timeline', 'pid1');
|
2015-12-09 20:15:55 -05:00
|
|
|
var metric = createMetric(
|
2016-08-03 18:00:07 -04:00
|
|
|
[[
|
|
|
|
eventFactory.markStart('benchpress0', 0), eventFactory.start('script', 0, null),
|
|
|
|
eventFactory.end('script', 5, null),
|
|
|
|
otherProcessEventFactory.start('script', 10, null),
|
|
|
|
otherProcessEventFactory.end('script', 17, null),
|
|
|
|
eventFactory.markEnd('benchpress0', 20)
|
|
|
|
]],
|
2015-12-09 20:15:55 -05:00
|
|
|
null);
|
2016-08-03 18:00:07 -04:00
|
|
|
metric.beginMeasure().then((_) => metric.endMeasure(false)).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(5);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should support scriptTime metric',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
aggregate([
|
|
|
|
eventFactory.start('script', 0), eventFactory.end('script', 5)
|
|
|
|
]).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(5);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should support renderTime metric',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
aggregate([
|
|
|
|
eventFactory.start('render', 0), eventFactory.end('render', 5)
|
|
|
|
]).then((data) => {
|
|
|
|
expect(data['renderTime']).toBe(5);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should support gcTime/gcAmount metric',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
aggregate([
|
|
|
|
eventFactory.start('gc', 0, {'usedHeapSize': 2500}),
|
|
|
|
eventFactory.end('gc', 5, {'usedHeapSize': 1000})
|
2016-08-03 18:00:07 -04:00
|
|
|
]).then((data) => {
|
|
|
|
expect(data['gcTime']).toBe(5);
|
|
|
|
expect(data['gcAmount']).toBe(1.5);
|
|
|
|
expect(data['majorGcTime']).toBe(0);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should support majorGcTime metric',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
aggregate([
|
|
|
|
eventFactory.start('gc', 0, {'usedHeapSize': 2500}),
|
|
|
|
eventFactory.end('gc', 5, {'usedHeapSize': 1000, 'majorGc': true})
|
2016-08-03 18:00:07 -04:00
|
|
|
]).then((data) => {
|
|
|
|
expect(data['gcTime']).toBe(5);
|
|
|
|
expect(data['majorGcTime']).toBe(5);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
|
|
|
it('should support pureScriptTime = scriptTime-gcTime-renderTime',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
aggregate([
|
2016-08-03 18:00:07 -04:00
|
|
|
eventFactory.start('script', 0), eventFactory.start('gc', 1, {'usedHeapSize': 1000}),
|
|
|
|
eventFactory.end('gc', 4, {'usedHeapSize': 0}), eventFactory.start('render', 4),
|
|
|
|
eventFactory.end('render', 5), eventFactory.end('script', 6)
|
|
|
|
]).then((data) => {
|
|
|
|
expect(data['scriptTime']).toBe(6);
|
|
|
|
expect(data['pureScriptTime']).toBe(2);
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-03 18:00:07 -04:00
|
|
|
describe('receivedData', () => {
|
|
|
|
it('should report received data since last navigationStart',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
|
|
|
eventFactory.instant('receivedData', 0, {'encodedDataLength': 1}),
|
|
|
|
eventFactory.instant('navigationStart', 1),
|
|
|
|
eventFactory.instant('receivedData', 2, {'encodedDataLength': 2}),
|
|
|
|
eventFactory.instant('navigationStart', 3),
|
|
|
|
eventFactory.instant('receivedData', 4, {'encodedDataLength': 4}),
|
|
|
|
eventFactory.instant('receivedData', 5, {'encodedDataLength': 8})
|
|
|
|
],
|
|
|
|
{receivedData: true})
|
|
|
|
.then((data) => {
|
|
|
|
expect(data['receivedData']).toBe(12);
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
});
|
|
|
|
|
|
|
|
describe('requestCount', () => {
|
|
|
|
it('should report count of requests sent since last navigationStart',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2016-08-03 18:00:07 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
|
|
|
eventFactory.instant('sendRequest', 0),
|
|
|
|
eventFactory.instant('navigationStart', 1),
|
|
|
|
eventFactory.instant('sendRequest', 2),
|
|
|
|
eventFactory.instant('navigationStart', 3),
|
|
|
|
eventFactory.instant('sendRequest', 4), eventFactory.instant('sendRequest', 5)
|
|
|
|
],
|
|
|
|
{requestCount: true})
|
|
|
|
.then((data) => {
|
|
|
|
expect(data['requestCount']).toBe(2);
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
});
|
2015-12-09 20:15:55 -05:00
|
|
|
|
2015-05-27 17:57:54 -04:00
|
|
|
describe('microMetrics', () => {
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should report micro metrics',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-06-19 13:18:44 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
|
|
|
eventFactory.markStart('mm1', 0),
|
|
|
|
eventFactory.markEnd('mm1', 5),
|
|
|
|
],
|
2015-12-09 20:15:55 -05:00
|
|
|
{microMetrics: {'mm1': 'micro metric 1'}})
|
2015-05-27 17:57:54 -04:00
|
|
|
.then((data) => {
|
|
|
|
expect(data['mm1']).toBe(5.0);
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
it('should ignore micro metrics that were not specified',
|
2016-08-26 19:34:08 -04:00
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-05-27 17:57:54 -04:00
|
|
|
aggregate([
|
|
|
|
eventFactory.markStart('mm1', 0),
|
|
|
|
eventFactory.markEnd('mm1', 5),
|
2016-08-03 18:00:07 -04:00
|
|
|
]).then((data) => {
|
|
|
|
expect(data['mm1']).toBeFalsy();
|
|
|
|
async.done();
|
|
|
|
});
|
2015-05-27 17:57:54 -04:00
|
|
|
}));
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
it('should report micro metric averages',
|
|
|
|
inject([AsyncTestCompleter], (async: AsyncTestCompleter) => {
|
2015-06-19 13:18:44 -04:00
|
|
|
aggregate(
|
|
|
|
[
|
|
|
|
eventFactory.markStart('mm1*20', 0),
|
|
|
|
eventFactory.markEnd('mm1*20', 5),
|
|
|
|
],
|
2015-12-09 20:15:55 -05:00
|
|
|
{microMetrics: {'mm1': 'micro metric 1'}})
|
2015-05-27 17:57:54 -04:00
|
|
|
.then((data) => {
|
|
|
|
expect(data['mm1']).toBe(5 / 20);
|
|
|
|
async.done();
|
|
|
|
});
|
|
|
|
}));
|
|
|
|
|
|
|
|
});
|
|
|
|
|
|
|
|
});
|
|
|
|
|
|
|
|
});
|
|
|
|
}
|
|
|
|
|
|
|
|
class MockDriverExtension extends WebDriverExtension {
|
2016-08-03 18:00:07 -04:00
|
|
|
constructor(
|
|
|
|
private _perfLogs: any[], private _commandLog: any[],
|
|
|
|
private _perfLogFeatures: PerfLogFeatures) {
|
2015-05-27 17:57:54 -04:00
|
|
|
super();
|
|
|
|
}
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
timeBegin(name: string): Promise<any> {
|
2015-06-17 14:17:21 -04:00
|
|
|
this._commandLog.push(['timeBegin', name]);
|
2016-08-02 18:53:34 -04:00
|
|
|
return Promise.resolve(null);
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
|
|
|
|
2016-08-26 19:34:08 -04:00
|
|
|
timeEnd(name: string, restartName: string): Promise<any> {
|
2015-06-17 14:17:21 -04:00
|
|
|
this._commandLog.push(['timeEnd', name, restartName]);
|
2016-08-02 18:53:34 -04:00
|
|
|
return Promise.resolve(null);
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
|
|
|
|
|
|
|
perfLogFeatures(): PerfLogFeatures { return this._perfLogFeatures; }
|
|
|
|
|
|
|
|
readPerfLog(): Promise<any> {
|
2015-06-17 14:17:21 -04:00
|
|
|
this._commandLog.push('readPerfLog');
|
2015-05-27 17:57:54 -04:00
|
|
|
if (this._perfLogs.length > 0) {
|
|
|
|
var next = this._perfLogs[0];
|
2015-10-07 12:09:43 -04:00
|
|
|
this._perfLogs.shift();
|
2016-08-02 18:53:34 -04:00
|
|
|
return Promise.resolve(next);
|
2015-05-27 17:57:54 -04:00
|
|
|
} else {
|
2016-08-02 18:53:34 -04:00
|
|
|
return Promise.resolve([]);
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
gc(): Promise<any> {
|
2015-06-17 14:17:21 -04:00
|
|
|
this._commandLog.push(['gc']);
|
2016-08-02 18:53:34 -04:00
|
|
|
return Promise.resolve(null);
|
2015-05-27 17:57:54 -04:00
|
|
|
}
|
|
|
|
}
|