feat(bench press): detect major gcs

This commit is contained in:
Tobias Bosch 2015-03-04 09:59:18 -08:00
parent eb6385e143
commit 146d731e73
5 changed files with 85 additions and 59 deletions

View File

@ -43,8 +43,8 @@ export class PerflogMetric extends Metric {
'render': 'render time in ms',
'gcTime': 'gc time in ms',
'gcAmount': 'gc amount in kbytes',
'gcTimeInScript': 'gc time during script execution in ms',
'gcAmountInScript': 'gc amount during script execution in kbytes'
'majorGcTime': 'time of major gcs in ms',
'majorGcAmount': 'amount of major gcs in kbytes'
};
if (this._microIterations > 0) {
res['scriptMicroAvg'] = 'average script time for a micro iteration';
@ -124,12 +124,13 @@ export class PerflogMetric extends Metric {
'render': 0,
'gcTime': 0,
'gcAmount': 0,
'gcTimeInScript': 0,
'gcAmountInScript': 0
'majorGcTime': 0,
'majorGcAmount': 0
};
var markStartEvent = null;
var markEndEvent = null;
var gcTimeInScript = 0;
var intervalStarts = {};
events.forEach( (event) => {
@ -148,19 +149,24 @@ export class PerflogMetric extends Metric {
var duration = event['ts'] - startEvent['ts'];
intervalStarts[name] = null;
if (StringWrapper.equals(name, 'gc')) {
var amount = (startEvent['args']['usedHeapSize'] - event['args']['usedHeapSize']) / 1000;
result['gcTime'] += duration;
result['gcAmount'] += (startEvent['args']['usedHeapSize'] - event['args']['usedHeapSize']) / 1000;
if (isPresent(intervalStarts['script'])) {
result['gcTimeInScript'] += duration;
result['gcAmountInScript'] += result['gcAmount'];
result['gcAmount'] += amount;
var majorGc = event['args']['majorGc'];
if (isPresent(majorGc) && majorGc) {
result['majorGcTime'] += duration;
result['majorGcAmount'] += amount;
}
} else {
if (isPresent(intervalStarts['script'])) {
gcTimeInScript += duration;
}
} else if (StringWrapper.equals(name, 'script') || StringWrapper.equals(name, 'render')) {
result[name] += duration;
}
}
}
});
result['script'] -= result['gcTimeInScript'];
result['script'] -= gcTimeInScript;
if (this._microIterations > 0) {
result['scriptMicroAvg'] = result['script'] / this._microIterations;
}

View File

@ -61,10 +61,13 @@ export class ChromeDriverExtension extends WebDriverExtension {
if (isBlank(normalizedEvents)) {
normalizedEvents = [];
}
var majorGCPids = {};
chromeEvents.forEach( (event) => {
var cat = event['cat'];
var name = event['name'];
var args = event['args'];
var pid = event['pid'];
var ph = event['ph'];
if (StringWrapper.equals(cat, 'disabled-by-default-devtools.timeline')) {
if (StringWrapper.equals(name, 'FunctionCall') &&
(isBlank(args) || isBlank(args['data']) || !StringWrapper.equals(args['data']['scriptName'], 'InjectedScript'))) {
@ -81,17 +84,28 @@ export class ChromeDriverExtension extends WebDriverExtension {
'name': 'render'
}));
} else if (StringWrapper.equals(name, 'GCEvent')) {
var normArgs = {
'usedHeapSize': isPresent(args['usedHeapSizeAfter']) ? args['usedHeapSizeAfter'] : args['usedHeapSizeBefore']
};
if (StringWrapper.equals(event['ph'], 'E')) {
normArgs['majorGc'] = isPresent(majorGCPids[pid]) && majorGCPids[pid];
}
majorGCPids[pid] = false;
ListWrapper.push(normalizedEvents, normalizeEvent(event, {
'name': 'gc',
'args': {
'usedHeapSize': isPresent(args['usedHeapSizeAfter']) ? args['usedHeapSizeAfter'] : args['usedHeapSizeBefore']
}
'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;
}
}
}
});
return normalizedEvents;

View File

@ -221,7 +221,7 @@ export function main() {
});
});
['script', 'gcTime', 'render'].forEach( (metricName) => {
['script', 'render'].forEach( (metricName) => {
it(`should support ${metricName} metric`, (done) => {
aggregate([
eventFactory.start(metricName, 0),
@ -233,12 +233,28 @@ export function main() {
});
});
it('should support gcAmount metric', (done) => {
it('should support gcTime/gcAmount metric', (done) => {
aggregate([
eventFactory.start('gc', 0, {'usedHeapSize': 2500}),
eventFactory.end('gc', 5, {'usedHeapSize': 1000})
]).then((data) => {
expect(data['gcTime']).toBe(5);
expect(data['gcAmount']).toBe(1.5);
expect(data['majorGcTime']).toBe(0);
expect(data['majorGcAmount']).toBe(0);
done();
});
});
it('should support majorGcTime/majorGcAmount metric', (done) => {
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);
done();
});
});
@ -280,48 +296,6 @@ export function main() {
});
describe('gcTimeInScript / gcAmountInScript', () => {
it('should detect gc during script execution with begin/end events', (done) => {
aggregate([
eventFactory.start('script', 0),
eventFactory.start('gc', 1, {'usedHeapSize': 10000}),
eventFactory.end('gc', 4, {'usedHeapSize': 0}),
eventFactory.end('script', 5)
]).then((data) => {
expect(data['gcTimeInScript']).toBe(3);
expect(data['gcAmountInScript']).toBe(10.0);
done();
});
});
it('should detect gc during script execution with complete events', (done) => {
aggregate([
eventFactory.complete('script', 0, 5),
eventFactory.start('gc', 1, {'usedHeapSize': 10000}),
eventFactory.end('gc', 4, {'usedHeapSize': 0})
]).then((data) => {
expect(data['gcTimeInScript']).toBe(3);
expect(data['gcAmountInScript']).toBe(10.0);
done();
});
});
it('should ignore gc outside of script execution', (done) => {
aggregate([
eventFactory.start('gc', 1, {'usedHeapSize': 10}),
eventFactory.end('gc', 4, {'usedHeapSize': 0}),
eventFactory.start('script', 0),
eventFactory.end('script', 5)
]).then((data) => {
expect(data['gcTimeInScript']).toEqual(0.0);
expect(data['gcAmountInScript']).toEqual(0.0);
done();
});
});
});
});
});

View File

@ -17,6 +17,8 @@ export function main() {
var extension;
var blinkEvents = new TraceEventFactory('blink.console', 'pid0');
var v8Events = new TraceEventFactory('v8', 'pid0');
var v8EventsOtherProcess = new TraceEventFactory('v8', 'pid1');
var chromeTimelineEvents = new TraceEventFactory('disabled-by-default-devtools.timeline', 'pid0');
var normEvents = new TraceEventFactory('timeline', 'pid0');
@ -143,7 +145,37 @@ export function main() {
]).readPerfLog().then( (events) => {
expect(events).toEqual([
normEvents.start('gc', 1.0, {'usedHeapSize': 1000}),
normEvents.end('gc', 2.0, {'usedHeapSize': 0}),
normEvents.end('gc', 2.0, {'usedHeapSize': 0, 'majorGc': false}),
]);
done();
});
});
it('should report major gc', (done) => {
createExtension([
chromeTimelineEvents.start('GCEvent', 1000, {'usedHeapSizeBefore': 1000}),
v8EventsOtherProcess.start('majorGC', 1100, null),
v8EventsOtherProcess.end('majorGC', 1200, null),
chromeTimelineEvents.end('GCEvent', 2000, {'usedHeapSizeAfter': 0}),
]).readPerfLog().then( (events) => {
expect(events).toEqual([
normEvents.start('gc', 1.0, {'usedHeapSize': 1000}),
normEvents.end('gc', 2.0, {'usedHeapSize': 0, 'majorGc': false}),
]);
done();
});
});
it('should ignore major gc from different processes', (done) => {
createExtension([
chromeTimelineEvents.start('GCEvent', 1000, {'usedHeapSizeBefore': 1000}),
v8Events.start('majorGC', 1100, null),
v8Events.end('majorGC', 1200, null),
chromeTimelineEvents.end('GCEvent', 2000, {'usedHeapSizeAfter': 0}),
]).readPerfLog().then( (events) => {
expect(events).toEqual([
normEvents.start('gc', 1.0, {'usedHeapSize': 1000}),
normEvents.end('gc', 2.0, {'usedHeapSize': 0, 'majorGc': true}),
]);
done();
});

View File

@ -35,7 +35,7 @@ var browsers = argv['browsers'].split(',');
var CHROME_OPTIONS = {
'args': ['--js-flags=--expose-gc'],
'perfLoggingPrefs': {
'traceCategories': 'blink.console,disabled-by-default-devtools.timeline'
'traceCategories': 'v8,blink.console,disabled-by-default-devtools.timeline'
}
};