X Tutup
Skip to content

feat(benchpress): add mean frame time metric #2474

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
goderbauer wants to merge 1 commit into from
Closed

feat(benchpress): add mean frame time metric #2474

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 5 additions & 1 deletion modules/benchpress/src/common_options.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,8 @@ export class Options {
static get WRITE_FILE() { return _WRITE_FILE; }
// TODO(tbosch): use static values when our transpiler supports them
static get MICRO_METRICS() { return _MICRO_METRICS; }
// TODO(tbosch): use static values when our transpiler supports them
static get CAPTURE_FRAMES() { return _CAPTURE_FRAMES; }
}

var _SAMPLE_ID = new OpaqueToken('Options.sampleId');
Expand All @@ -38,6 +40,7 @@ var _USER_AGENT = new OpaqueToken('Options.userAgent');
var _MICRO_METRICS = new OpaqueToken('Options.microMetrics');
var _NOW = new OpaqueToken('Options.now');
var _WRITE_FILE = new OpaqueToken('Options.writeFile');
var _CAPTURE_FRAMES = new OpaqueToken('Options.frameCapture');

var _DEFAULT_BINDINGS = [
bind(_DEFAULT_DESCRIPTION)
Expand All @@ -46,5 +49,6 @@ var _DEFAULT_BINDINGS = [
bind(_FORCE_GC).toValue(false),
bind(_PREPARE).toValue(false),
bind(_MICRO_METRICS).toValue({}),
bind(_NOW).toValue(() => DateWrapper.now())
bind(_NOW).toValue(() => DateWrapper.now()),
bind(_CAPTURE_FRAMES).toValue(false)
];
83 changes: 78 additions & 5 deletions modules/benchpress/src/metric/perflog_metric.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,8 @@ export class PerflogMetric extends Metric {
* @param microMetrics Name and description of metrics provided via console.time / console.timeEnd
**/
constructor(private _driverExtension: WebDriverExtension, private _setTimeout: Function,
private _microMetrics: StringMap<string, any>, private _forceGc: boolean) {
private _microMetrics: StringMap<string, any>, private _forceGc: boolean,
private _captureFrames: boolean) {
super();

this._remainingEvents = [];
Expand All @@ -60,6 +61,11 @@ export class PerflogMetric extends Metric {
res['forcedGcAmount'] = 'forced gc amount in kbytes';
}
}
if (this._captureFrames) {
res['meanFrameTime'] = this._perfLogFeatures.frameCapture ?
'mean frame time in ms (target: 16.6ms for 60fps)' :
'WARNING: Metric requested, but not supported by driver';
}
StringMapWrapper.forEach(this._microMetrics,
(desc, name) => { StringMapWrapper.set(res, name, desc); });
return res;
Expand All @@ -83,9 +89,13 @@ export class PerflogMetric extends Metric {

_endPlainMeasureAndMeasureForceGc(restartMeasure: boolean) {
return this._endMeasure(true).then((measureValues) => {
// disable frame capture for measurments during forced gc
var originalFrameCaptureValue = this._captureFrames;
this._captureFrames = false;
return this._driverExtension.gc()
.then((_) => this._endMeasure(restartMeasure))
.then((forceGcMeasureValues) => {
this._captureFrames = originalFrameCaptureValue;
StringMapWrapper.set(measureValues, 'forcedGcTime', forceGcMeasureValues['gcTime']);
StringMapWrapper.set(measureValues, 'forcedGcAmount', forceGcMeasureValues['gcAmount']);
return measureValues;
Expand Down Expand Up @@ -161,13 +171,21 @@ export class PerflogMetric extends Metric {
if (this._perfLogFeatures.render) {
result['renderTime'] = 0;
}
if (this._captureFrames) {
result['meanFrameTime'] = 0;
}
StringMapWrapper.forEach(this._microMetrics, (desc, name) => { result[name] = 0; });

var markStartEvent = null;
var markEndEvent = null;
var gcTimeInScript = 0;
var renderTimeInScript = 0;

var frameTimestamps = [];
var frameTimes = [];
var frameCaptureStartEvent = null;
var frameCaptureEndEvent = null;

var intervalStarts: StringMap<string, any> = {};
var intervalStartCount: StringMap<string, number> = {};
events.forEach((event) => {
Expand All @@ -185,8 +203,37 @@ export class PerflogMetric extends Metric {
} else if (StringWrapper.equals(ph, 'e') && StringWrapper.equals(name, markName)) {
markEndEvent = event;
}

if (isPresent(markStartEvent) && isBlank(markEndEvent) &&
event['pid'] === markStartEvent['pid']) {
if (StringWrapper.equals(ph, 'b') && StringWrapper.equals(name, _MARK_NAME_FRAME_CAPUTRE)) {
if (isPresent(frameCaptureStartEvent)) {
throw new BaseException('can capture frames only once per benchmark run');
}
if (!this._captureFrames) {
throw new BaseException(
'found start event for frame capture, but frame capture was not requested in benchpress')
}
frameCaptureStartEvent = event;
} else if (StringWrapper.equals(ph, 'e') &&
StringWrapper.equals(name, _MARK_NAME_FRAME_CAPUTRE)) {
if (isBlank(frameCaptureStartEvent)) {
throw new BaseException('missing start event for frame capture');
}
frameCaptureEndEvent = event;
}

if (StringWrapper.equals(ph, 'I') || StringWrapper.equals(ph, 'i')) {
if (isPresent(frameCaptureStartEvent) && isBlank(frameCaptureEndEvent) &&
StringWrapper.equals(name, 'frame')) {
ListWrapper.push(frameTimestamps, event['ts']);
if (frameTimestamps.length >= 2) {
ListWrapper.push(frameTimes, frameTimestamps[frameTimestamps.length - 1] -
frameTimestamps[frameTimestamps.length - 2]);
}
}
}

if (StringWrapper.equals(ph, 'B') || StringWrapper.equals(ph, 'b')) {
if (isBlank(intervalStarts[name])) {
intervalStartCount[name] = 1;
Expand Down Expand Up @@ -227,8 +274,25 @@ export class PerflogMetric extends Metric {
}
}
});
if (!isPresent(markStartEvent) || !isPresent(markEndEvent)) {
// not all events have been received, no further processing for now
return null;
}

if (isPresent(markEndEvent) && isPresent(frameCaptureStartEvent) &&
isBlank(frameCaptureEndEvent)) {
throw new BaseException('missing end event for frame capture');
}
if (this._captureFrames && isBlank(frameCaptureStartEvent)) {
throw new BaseException(
'frame capture requested in benchpress, but no start event was found');
}
if (frameTimes.length > 0) {
result['meanFrameTime'] =
ListWrapper.reduce(frameTimes, (a, b) => a + b, 0) / frameTimes.length;
}
result['pureScriptTime'] = result['scriptTime'] - gcTimeInScript - renderTimeInScript;
return isPresent(markStartEvent) && isPresent(markEndEvent) ? result : null;
return result;
}

_markName(index) { return `${_MARK_NAME_PREFIX}${index}`; }
Expand All @@ -239,10 +303,19 @@ var _MAX_RETRY_COUNT = 20;
var _MARK_NAME_PREFIX = 'benchpress';
var _SET_TIMEOUT = new OpaqueToken('PerflogMetric.setTimeout');

var _MARK_NAME_FRAME_CAPUTRE = 'frameCapture';

var _BINDINGS = [
bind(PerflogMetric)
.toFactory((driverExtension, setTimeout, microMetrics, forceGc) =>
new PerflogMetric(driverExtension, setTimeout, microMetrics, forceGc),
[WebDriverExtension, _SET_TIMEOUT, Options.MICRO_METRICS, Options.FORCE_GC]),
.toFactory(
(driverExtension, setTimeout, microMetrics, forceGc, captureFrames) =>
new PerflogMetric(driverExtension, setTimeout, microMetrics, forceGc, captureFrames),
[
WebDriverExtension,
_SET_TIMEOUT,
Options.MICRO_METRICS,
Options.FORCE_GC,
Options.CAPTURE_FRAMES
]),
bind(_SET_TIMEOUT).toValue((fn, millis) => TimerWrapper.setTimeout(fn, millis))
];
7 changes: 6 additions & 1 deletion modules/benchpress/src/web_driver_extension.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -66,10 +66,15 @@ export class WebDriverExtension {
export class PerfLogFeatures {
render: boolean;
gc: boolean;
frameCapture: boolean;

constructor({render = false, gc = false}: {render?: boolean, gc?: boolean} = {}) {
constructor({render = false, gc = false,
frameCapture = false}: {render?: boolean,
gc?: boolean,
frameCapture?: boolean} = {}) {
this.render = render;
this.gc = gc;
this.frameCapture = frameCapture;
}
}

Expand Down
33 changes: 32 additions & 1 deletion modules/benchpress/src/webdriver/chrome_driver_extension.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,13 @@ import {WebDriverExtension, PerfLogFeatures} from '../web_driver_extension';
import {WebDriverAdapter} from '../web_driver_adapter';
import {Promise} from 'angular2/src/facade/async';

/**
* Set the following 'traceCategories' to collect metrics in Chrome:
* 'v8,blink.console,disabled-by-default-devtools.timeline'
*
* In order to collect the frame rate related metrics, add 'benchmark'
* to the list above.
*/
export class ChromeDriverExtension extends WebDriverExtension {
// TODO(tbosch): use static values when our transpiler supports them
static get BINDINGS(): List<Binding> { return _BINDINGS; }
Expand Down Expand Up @@ -73,12 +80,14 @@ export class ChromeDriverExtension extends WebDriverExtension {
(isBlank(args) || isBlank(args['data']) ||
!StringWrapper.equals(args['data']['scriptName'], 'InjectedScript'))) {
ListWrapper.push(normalizedEvents, normalizeEvent(event, {'name': 'script'}));

} else if (StringWrapper.equals(name, 'RecalculateStyles') ||
StringWrapper.equals(name, 'Layout') ||
StringWrapper.equals(name, 'UpdateLayerTree') ||
StringWrapper.equals(name, 'Paint') || StringWrapper.equals(name, 'Rasterize') ||
StringWrapper.equals(name, 'CompositeLayers')) {
ListWrapper.push(normalizedEvents, normalizeEvent(event, {'name': 'render'}));

} else if (StringWrapper.equals(name, 'GCEvent')) {
var normArgs = {
'usedHeapSize': isPresent(args['usedHeapSizeAfter']) ? args['usedHeapSizeAfter'] :
Expand All @@ -91,20 +100,42 @@ export class ChromeDriverExtension extends WebDriverExtension {
ListWrapper.push(normalizedEvents,
normalizeEvent(event, {'name': 'gc', 'args': normArgs}));
}

} else if (StringWrapper.equals(cat, 'blink.console')) {
ListWrapper.push(normalizedEvents, normalizeEvent(event, {'name': name}));

} else if (StringWrapper.equals(cat, 'v8')) {
if (StringWrapper.equals(name, 'majorGC')) {
if (StringWrapper.equals(ph, 'B')) {
majorGCPids[pid] = true;
}
}

} else if (StringWrapper.equals(cat, 'benchmark')) {
Copy link
Copy Markdown
Contributor

@tbosch tbosch Jun 11, 2015

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a little but too general as a marker. How about framesBenchmark, or just fps (e.g. used as console.time('fps')...

Copy link
Copy Markdown
Contributor Author

@goderbauer goderbauer Jun 11, 2015

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

benchmark is the name Chrome tracing is using as a category for the events I am looking for. I cannot change that as it is set by chrome. Below, I am filtering for the exact event name (BenchmarkInstrumentation::ImplThreadRenderingStats) within that category.

if (StringWrapper.equals(name, 'BenchmarkInstrumentation::ImplThreadRenderingStats')) {
var frameCount = event['args']['data']['frame_count'];
if (frameCount > 1) {
throw new BaseException('multi-frame render stats not supported');
}
if (frameCount == 1) {
ListWrapper.push(normalizedEvents, normalizeEvent(event, {'name': 'frame'}));
}
} else if (StringWrapper.equals(name, 'BenchmarkInstrumentation::DisplayRenderingStats') ||
StringWrapper.equals(name, 'vsync_before')) {
// TODO(goderbauer): If present, these events should be used instead of
// BenchmarkInstrumentation::ImplThreadRenderingStats.
// However, they never seem to appear in practice. Maybe they appear on a different
// platform?
throw new BaseException('NYI');
}
}
});
return normalizedEvents;
}

perfLogFeatures(): PerfLogFeatures { return new PerfLogFeatures({render: true, gc: true}); }
perfLogFeatures(): PerfLogFeatures {
return new PerfLogFeatures({render: true, gc: true, frameCapture: true});
}

supports(capabilities: StringMap<string, any>): boolean {
return StringWrapper.equals(capabilities['browserName'].toLowerCase(), 'chrome');
Expand Down
101 changes: 97 additions & 4 deletions modules/benchpress/test/metric/perflog_metric_spec.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -31,10 +31,11 @@ export function main() {
var commandLog;
var eventFactory = new TraceEventFactory('timeline', 'pid0');

function createMetric(perfLogs, microMetrics = null, perfLogFeatures = null, forceGc = null) {
function createMetric(perfLogs, microMetrics = null, perfLogFeatures = null, forceGc = null,
captureFrames = null) {
commandLog = [];
if (isBlank(perfLogFeatures)) {
perfLogFeatures = new PerfLogFeatures({render: true, gc: true});
perfLogFeatures = new PerfLogFeatures({render: true, gc: true, frameCapture: true});
}
if (isBlank(microMetrics)) {
microMetrics = StringMapWrapper.create();
Expand All @@ -54,6 +55,9 @@ export function main() {
if (isPresent(forceGc)) {
ListWrapper.push(bindings, bind(Options.FORCE_GC).toValue(forceGc));
}
if (isPresent(captureFrames)) {
ListWrapper.push(bindings, bind(Options.CAPTURE_FRAMES).toValue(captureFrames));
}
return Injector.resolveAndCreate(bindings).get(PerflogMetric);
}

Expand Down Expand Up @@ -98,6 +102,20 @@ export function main() {
expect(description['myMicroMetric']).toEqual('someDesc');
});

it('should describe itself if frame capture is requested and available', () => {
var description =
createMetric([[]], null, new PerfLogFeatures({frameCapture: true}), null, true)
.describe();
expect(description['meanFrameTime']).not.toContain('WARNING');
});

it('should describe itself if frame capture is requested and not available', () => {
var description =
createMetric([[]], null, new PerfLogFeatures({frameCapture: false}), null, true)
.describe();
expect(description['meanFrameTime']).toContain('WARNING');
});

describe('beginMeasure', () => {

it('should not force gc and mark the timeline', inject([AsyncTestCompleter], (async) => {
Expand Down Expand Up @@ -300,13 +318,88 @@ export function main() {

describe('aggregation', () => {

function aggregate(events, microMetrics = null) {
function aggregate(events, microMetrics = null, captureFrames = null) {
ListWrapper.insert(events, 0, eventFactory.markStart('benchpress0', 0));
ListWrapper.push(events, eventFactory.markEnd('benchpress0', 10));
var metric = createMetric([events], microMetrics);
var metric = createMetric([events], microMetrics, null, null, captureFrames);
return metric.beginMeasure().then((_) => metric.endMeasure(false));
}

describe('frame metrics', () => {
it('should calculate mean frame time', inject([AsyncTestCompleter], (async) => {
aggregate([
eventFactory.markStart('frameCapture', 0),
eventFactory.instant('frame', 1),
eventFactory.instant('frame', 3),
eventFactory.instant('frame', 4),
eventFactory.markEnd('frameCapture', 5)
],
null, true)
.then((data) => {
expect(data['meanFrameTime']).toBe(((3 - 1) + (4 - 3)) / 2);
async.done();
});
}));

it('should throw if no start event', inject([AsyncTestCompleter], (async) => {
PromiseWrapper.catchError(
aggregate(
[eventFactory.instant('frame', 4), eventFactory.markEnd('frameCapture', 5)],
null, true),
(err) => {
expect(() => { throw err; })
.toThrowError('missing start event for frame capture');
async.done();
});
}));

it('should throw if no end event', inject([AsyncTestCompleter], (async) => {
PromiseWrapper.catchError(
aggregate(
[eventFactory.markStart('frameCapture', 3), eventFactory.instant('frame', 4)],
null, true),
(err) => {
expect(() => { throw err; }).toThrowError('missing end event for frame capture');
async.done();
});
}));

it('should throw if trying to capture twice', inject([AsyncTestCompleter], (async) => {
PromiseWrapper.catchError(
aggregate([
eventFactory.markStart('frameCapture', 3),
eventFactory.markStart('frameCapture', 4)
],
null, true),
(err) => {
expect(() => { throw err; })
.toThrowError('can capture frames only once per benchmark run');
async.done();
});
}));

it('should throw if trying to capture when frame capture is disabled',
inject([AsyncTestCompleter], (async) => {
PromiseWrapper.catchError(aggregate([eventFactory.markStart('frameCapture', 3)]), (err) => {
expect(() => { throw err; })
.toThrowError(
'found start event for frame capture, but frame capture was not requested in benchpress');
async.done();
});
}));

it('should throw if frame capture is enabled, but nothing is captured',
inject([AsyncTestCompleter], (async) => {
PromiseWrapper.catchError(aggregate([], null, true), (err) => {
expect(() => { throw err; })
.toThrowError(
'frame capture requested in benchpress, but no start event was found');
async.done();
});
}));


});

it('should report a single interval', inject([AsyncTestCompleter], (async) => {
aggregate([eventFactory.start('script', 0), eventFactory.end('script', 5)])
Expand Down
Loading
X Tutup