refactor(bench press): rename metrics and adapt them to the features of the browser

* Rename metrics, add `Time` suffix to all so that they are
  more consistent
* iOS does not give us `gc` metrics, so they should not be reported
* Rename `scriptMicroAvg` into `microScriptTimeAvg`
* Rename previous `script` metric into `pureScriptTime` metric,
  and keep `scriptTime` metric as the overall time, so that we still
  have a shared metric across devices independent of the supported
  browser features
* `microScriptTimeAvg` is now based on overall `scriptTime`, including
  gc and render time.
* Move more shared DI tokens into `common_options` (previously
  `sample_options`).

Closes #930
This commit is contained in:
Tobias Bosch
2015-03-06 17:34:27 -08:00
parent 75ecaf02b9
commit 21a293b017
16 changed files with 214 additions and 147 deletions

View File

@ -13,9 +13,13 @@ import {
import { List, ListWrapper } from 'angular2/src/facade/collection';
import { PromiseWrapper, Promise } from 'angular2/src/facade/async';
import { isPresent } from 'angular2/src/facade/lang';
import { isPresent, isBlank } from 'angular2/src/facade/lang';
import { Metric, PerflogMetric, WebDriverExtension, bind, Injector, Options } from 'benchpress/common';
import {
Metric, PerflogMetric, WebDriverExtension,
PerfLogFeatures,
bind, Injector, Options
} from 'benchpress/common';
import { TraceEventFactory } from '../trace_event_factory';
@ -23,15 +27,19 @@ export function main() {
var commandLog;
var eventFactory = new TraceEventFactory('timeline', 'pid0');
function createMetric(perfLogs, microIterations = 0) {
function createMetric(perfLogs, microIterations = 0, perfLogFeatures = null) {
commandLog = [];
if (isBlank(perfLogFeatures)) {
perfLogFeatures = new PerfLogFeatures({render: true, gc: true});
}
var bindings = [
Options.DEFAULT_BINDINGS,
PerflogMetric.BINDINGS,
bind(PerflogMetric.SET_TIMEOUT).toValue( (fn, millis) => {
ListWrapper.push(commandLog, ['setTimeout', millis]);
fn();
}),
bind(WebDriverExtension).toValue(new MockDriverExtension(perfLogs, commandLog)),
bind(WebDriverExtension).toValue(new MockDriverExtension(perfLogs, commandLog, perfLogFeatures)),
bind(Options.MICRO_ITERATIONS).toValue(microIterations)
];
return new Injector(bindings).get(PerflogMetric);
@ -39,8 +47,29 @@ export function main() {
describe('perflog metric', () => {
it('should describe itself', () => {
expect(createMetric([[]]).describe()['script']).toBe('script execution time in ms');
it('should describe itself based on the perfLogFeatrues', () => {
expect(createMetric([[]], 0, new PerfLogFeatures()).describe()).toEqual({
'scriptTime': 'script execution time in ms, including gc and render',
'pureScriptTime': 'script execution time in ms, without gc nor render'
});
expect(createMetric([[]], 0, new PerfLogFeatures({
render: true,
gc: false
})).describe()).toEqual({
'scriptTime': 'script execution time in ms, including gc and render',
'pureScriptTime': 'script execution time in ms, without gc nor render',
'renderTime': 'render time in and ouside of script in ms',
});
expect(createMetric([[]]).describe()).toEqual({
'scriptTime': 'script execution time in ms, including gc and render',
'pureScriptTime': 'script execution time in ms, without gc nor render',
'renderTime': 'render time in and ouside of script in ms',
'gcTime': 'gc time in and ouside of script in ms',
'gcAmount': 'gc amount in kbytes',
'majorGcTime': 'time of major gcs in ms'
});
});
describe('beginMeasure', () => {
@ -76,7 +105,7 @@ export function main() {
['timeEnd', 'benchpress0', null],
'readPerfLog'
]);
expect(data['script']).toBe(2);
expect(data['scriptTime']).toBe(2);
async.done();
});
@ -128,7 +157,7 @@ export function main() {
[ 'setTimeout', 100 ],
'readPerfLog'
]);
expect(data['script']).toBe(3);
expect(data['scriptTime']).toBe(3);
async.done();
});
@ -144,7 +173,7 @@ export function main() {
metric.beginMeasure()
.then( (_) => metric.endMeasure(true) )
.then( (data) => {
expect(data['script']).toBe(0);
expect(data['scriptTime']).toBe(0);
return metric.endMeasure(true)
})
.then( (data) => {
@ -155,7 +184,7 @@ export function main() {
['timeEnd', 'benchpress1', 'benchpress2'],
'readPerfLog'
]);
expect(data['script']).toBe(3);
expect(data['scriptTime']).toBe(3);
async.done();
});
@ -179,7 +208,7 @@ export function main() {
eventFactory.start('script', 0),
eventFactory.end('script', 5)
]).then((data) => {
expect(data['script']).toBe(5);
expect(data['scriptTime']).toBe(5);
async.done();
});
}));
@ -191,7 +220,7 @@ export function main() {
eventFactory.start('script', 10),
eventFactory.end('script', 17)
]).then((data) => {
expect(data['script']).toBe(12);
expect(data['scriptTime']).toBe(12);
async.done();
});
}));
@ -200,7 +229,7 @@ export function main() {
aggregate([
eventFactory.end('script', 10)
]).then((data) => {
expect(data['script']).toBe(0);
expect(data['scriptTime']).toBe(0);
async.done();
});
}));
@ -209,7 +238,7 @@ export function main() {
aggregate([
eventFactory.start('script', 10)
]).then((data) => {
expect(data['script']).toBe(0);
expect(data['scriptTime']).toBe(0);
async.done();
});
}));
@ -227,22 +256,30 @@ export function main() {
metric.beginMeasure()
.then( (_) => metric.endMeasure(false) )
.then((data) => {
expect(data['script']).toBe(5);
expect(data['scriptTime']).toBe(5);
async.done();
});
}));
['script', 'render'].forEach( (metricName) => {
it(`should support ${metricName} metric`, inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.start(metricName, 0),
eventFactory.end(metricName, 5)
]).then((data) => {
expect(data[metricName]).toBe(5);
async.done();
});
}));
});
it('should support scriptTime metric', inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.start('script', 0),
eventFactory.end('script', 5)
]).then((data) => {
expect(data['scriptTime']).toBe(5);
async.done();
});
}));
it('should support renderTime metric', inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.start('render', 0),
eventFactory.end('render', 5)
]).then((data) => {
expect(data['renderTime']).toBe(5);
async.done();
});
}));
it('should support gcTime/gcAmount metric', inject([AsyncTestCompleter], (async) => {
aggregate([
@ -252,55 +289,55 @@ export function main() {
expect(data['gcTime']).toBe(5);
expect(data['gcAmount']).toBe(1.5);
expect(data['majorGcTime']).toBe(0);
expect(data['majorGcAmount']).toBe(0);
async.done();
});
}));
it('should support majorGcTime/majorGcAmount metric', inject([AsyncTestCompleter], (async) => {
it('should support majorGcTime metric', inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.start('gc', 0, {'usedHeapSize': 2500}),
eventFactory.end('gc', 5, {'usedHeapSize': 1000, 'majorGc': true})
]).then((data) => {
expect(data['gcTime']).toBe(5);
expect(data['gcAmount']).toBe(1.5);
expect(data['majorGcTime']).toBe(5);
expect(data['majorGcAmount']).toBe(1.5);
async.done();
});
}));
it('should subtract gcTime in script from script time', inject([AsyncTestCompleter], (async) => {
it('should support pureScriptTime = scriptTime-gcTime-renderTime', inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.start('script', 0),
eventFactory.start('gc', 1, {'usedHeapSize': 1000}),
eventFactory.end('gc', 4, {'usedHeapSize': 0}),
eventFactory.end('script', 5)
eventFactory.start('render', 4),
eventFactory.end('render', 5),
eventFactory.end('script', 6)
]).then((data) => {
expect(data['script']).toBe(2);
expect(data['scriptTime']).toBe(6);
expect(data['pureScriptTime']).toBe(2);
async.done();
});
}));
describe('microIterations', () => {
it('should not report scriptMicroAvg if microIterations = 0', inject([AsyncTestCompleter], (async) => {
it('should not report microScriptTimeAvg if microIterations = 0', inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.start('script', 0),
eventFactory.end('script', 5)
], 0).then((data) => {
expect(isPresent(data['scriptMicroAvg'])).toBe(false);
expect(isPresent(data['microScriptTimeAvg'])).toBe(false);
async.done();
});
}));
it('should report scriptMicroAvg', inject([AsyncTestCompleter], (async) => {
it('should report microScriptTimeAvg', inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.start('script', 0),
eventFactory.end('script', 5)
], 4).then((data) => {
expect(data['script']).toBe(5);
expect(data['scriptMicroAvg']).toBe(5/4);
expect(data['scriptTime']).toBe(5);
expect(data['microScriptTimeAvg']).toBe(5/4);
async.done();
});
}));
@ -315,10 +352,12 @@ export function main() {
class MockDriverExtension extends WebDriverExtension {
_perfLogs:List;
_commandLog:List;
constructor(perfLogs, commandLog) {
_perfLogFeatures:PerfLogFeatures;
constructor(perfLogs, commandLog, perfLogFeatures) {
super();
this._perfLogs = perfLogs;
this._commandLog = commandLog;
this._perfLogFeatures = perfLogFeatures;
}
timeBegin(name):Promise {
@ -331,6 +370,10 @@ class MockDriverExtension extends WebDriverExtension {
return PromiseWrapper.resolve(null);
}
perfLogFeatures():PerfLogFeatures {
return this._perfLogFeatures;
}
readPerfLog():Promise {
ListWrapper.push(this._commandLog, 'readPerfLog');
if (this._perfLogs.length > 0) {

View File

@ -17,7 +17,8 @@ import { PromiseWrapper } from 'angular2/src/facade/async';
import {
bind, Injector,
SampleDescription,
MeasureValues
MeasureValues,
Options
} from 'benchpress/common';
@ -32,7 +33,8 @@ export function main() {
JsonFileReporter.BINDINGS,
bind(SampleDescription).toValue(new SampleDescription(sampleId, descriptions, metrics)),
bind(JsonFileReporter.PATH).toValue(path),
bind(JsonFileReporter.WRITE_FILE).toValue((filename, content) => {
bind(Options.NOW).toValue( () => DateWrapper.fromMillis(1234) ),
bind(Options.WRITE_FILE).toValue((filename, content) => {
loggedFile = {
'filename': filename,
'content': content

View File

@ -50,15 +50,17 @@ export function main() {
if (isBlank(driverExtension)) {
driverExtension = new MockDriverExtension([]);
}
var bindings = ListWrapper.concat(Sampler.BINDINGS, [
var bindings = [
Options.DEFAULT_BINDINGS,
Sampler.BINDINGS,
bind(Metric).toValue(metric),
bind(Reporter).toValue(reporter),
bind(WebDriverAdapter).toValue(driver),
bind(WebDriverExtension).toValue(driverExtension),
bind(Options.EXECUTE).toValue(execute),
bind(Validator).toValue(validator),
bind(Sampler.TIME).toValue( () => DateWrapper.fromMillis(time++) )
]);
bind(Options.NOW).toValue( () => DateWrapper.fromMillis(time++) )
];
if (isPresent(prepare)) {
ListWrapper.push(bindings, bind(Options.PREPARE).toValue(prepare));
}

View File

@ -41,12 +41,9 @@ export function main() {
return extension;
}
it('should force gc via window.gc()', inject([AsyncTestCompleter], (async) => {
createExtension().gc().then( (_) => {
expect(log).toEqual([['executeScript', 'window.gc()']]);
async.done();
});
}));
it('should throw on forcing gc', () => {
expect( () => createExtension().gc() ).toThrowError('Force GC is not supported on iOS');
});
it('should mark the timeline via console.time()', inject([AsyncTestCompleter], (async) => {
createExtension().timeBegin('someName').then( (_) => {
@ -124,18 +121,6 @@ export function main() {
});
}));
it('should report gc', inject([AsyncTestCompleter], (async) => {
createExtension([
gcRecord(1, 3, 21)
]).readPerfLog().then( (events) => {
expect(events).toEqual([
normEvents.start('gc', 1, {'usedHeapSize': 0}),
normEvents.end('gc', 3, {'usedHeapSize': -21}),
]);
async.done();
});
}));
['RecalculateStyles', 'Layout', 'UpdateLayerTree', 'Paint', 'Rasterize', 'CompositeLayers'].forEach( (recordType) => {
it(`should report ${recordType}`, inject([AsyncTestCompleter], (async) => {
createExtension([
@ -224,17 +209,6 @@ function internalScriptRecord(startTime, endTime) {
};
}
function gcRecord(startTime, endTime, gcAmount) {
return {
'type': 'GCEvent',
'startTime': startTime,
'endTime': endTime,
'data': {
'usedHeapSizeDelta': gcAmount
}
};
}
class MockDriverAdapter extends WebDriverAdapter {
_log:List;
_perfRecords:List;