blob: 2d3dfe2d3993454bbbbcca248763b5222b6850cc [file] [log] [blame]
/**
* @license
* Copyright 2016 Google LLC
* SPDX-License-Identifier: Apache-2.0
*/
import '../../test/common-test-setup';
import {
GrReporting,
DEFAULT_STARTUP_TIMERS,
initErrorReporter,
InteractionReporter,
} from './gr-reporting_impl';
import {getAppContext} from '../app-context';
import {Deduping} from '../../api/reporting';
import {SinonFakeTimers, SinonStub} from 'sinon';
import {assert} from '@open-wc/testing';
import {grReportingMock} from './gr-reporting_mock';
import {Interaction} from '../../constants/reporting';
suite('gr-reporting tests', () => {
// We have to type as any because we access
// private properties for testing.
let service: any;
let clock: SinonFakeTimers;
let fakePerformance: any;
const NOW_TIME = 100;
setup(() => {
clock = sinon.useFakeTimers(NOW_TIME);
service = new GrReporting(getAppContext().flagsService);
service._baselines = {...DEFAULT_STARTUP_TIMERS};
sinon.stub(service, 'reporter');
});
teardown(() => {
clock.restore();
});
test('appStarted', () => {
fakePerformance = {
navigationStart: 1,
loadEventEnd: 2,
};
fakePerformance.toJSON = () => fakePerformance;
sinon.stub(service, 'performanceTiming').get(() => fakePerformance);
sinon.stub(window.performance, 'now').returns(42);
service.appStarted();
assert.isTrue(
service.reporter.calledWithMatch(
'timing-report',
'UI Latency',
'App Started',
42
)
);
assert.isTrue(
service.reporter.calledWithExactly(
'timing-report',
'UI Latency',
'NavResTime - loadEventEnd',
fakePerformance.loadEventEnd - fakePerformance.navigationStart,
undefined,
true
)
);
});
test('WebComponentsReady', () => {
sinon.stub(window.performance, 'now').returns(42);
service.timeEnd('WebComponentsReady');
assert.isTrue(
service.reporter.calledWithMatch(
'timing-report',
'UI Latency',
'WebComponentsReady',
42
)
);
});
test('beforeLocationChanged', () => {
service._baselines['garbage'] = 'monster';
sinon.stub(service, 'time');
service.beforeLocationChanged();
assert.isTrue(service.time.calledWithExactly('DashboardDisplayed'));
assert.isTrue(service.time.calledWithExactly('ChangeDisplayed'));
assert.isTrue(service.time.calledWithExactly('ChangeFullyLoaded'));
assert.isTrue(service.time.calledWithExactly('DiffViewDisplayed'));
assert.isTrue(service.time.calledWithExactly('FileListDisplayed'));
assert.isFalse(
Object.prototype.hasOwnProperty.call(service._baselines, 'garbage')
);
});
test('changeDisplayed', () => {
sinon.spy(service, 'timeEnd');
service.changeDisplayed();
assert.isFalse(service.timeEnd.calledWith('ChangeDisplayed'));
assert.isTrue(service.timeEnd.calledWith('StartupChangeDisplayed'));
service.changeDisplayed();
assert.isTrue(service.timeEnd.calledWith('ChangeDisplayed'));
});
test('changeFullyLoaded', () => {
sinon.spy(service, 'timeEnd');
service.changeFullyLoaded();
assert.isFalse(service.timeEnd.calledWithExactly('ChangeFullyLoaded'));
assert.isTrue(
service.timeEnd.calledWithExactly('StartupChangeFullyLoaded')
);
service.changeFullyLoaded();
assert.isTrue(service.timeEnd.calledWithExactly('ChangeFullyLoaded'));
});
test('diffViewDisplayed', () => {
sinon.spy(service, 'timeEnd');
service.diffViewDisplayed();
assert.isFalse(service.timeEnd.calledWith('DiffViewDisplayed'));
assert.isTrue(service.timeEnd.calledWith('StartupDiffViewDisplayed'));
service.diffViewDisplayed();
assert.isTrue(service.timeEnd.calledWith('DiffViewDisplayed'));
});
test('fileListDisplayed', () => {
sinon.spy(service, 'timeEnd');
service.fileListDisplayed();
assert.isFalse(service.timeEnd.calledWithExactly('FileListDisplayed'));
assert.isTrue(
service.timeEnd.calledWithExactly('StartupFileListDisplayed')
);
service.fileListDisplayed();
assert.isTrue(service.timeEnd.calledWithExactly('FileListDisplayed'));
});
test('dashboardDisplayed', () => {
sinon.spy(service, 'timeEnd');
service.dashboardDisplayed();
assert.isFalse(service.timeEnd.calledWith('DashboardDisplayed'));
assert.isTrue(service.timeEnd.calledWith('StartupDashboardDisplayed'));
service.dashboardDisplayed();
assert.isTrue(service.timeEnd.calledWith('DashboardDisplayed'));
});
test('dashboardDisplayed details', () => {
sinon.spy(service, 'timeEnd');
sinon.stub(window, 'performance').value({
memory: {
usedJSHeapSize: 1024 * 1024,
},
measure: () => {},
now: () => {
42;
},
});
service.reportRpcTiming('/changes/*~*/comments', 500);
service.dashboardDisplayed();
assert.isTrue(
service.timeEnd.calledWithExactly('StartupDashboardDisplayed', {
rpcList: [
{
anonymizedUrl: '/changes/*~*/comments',
elapsed: 500,
},
],
screenSize: {
width: window.screen.width,
height: window.screen.height,
},
viewport: {
width: document.documentElement.clientWidth,
height: document.documentElement.clientHeight,
},
usedJSHeapSizeMb: 1,
hiddenDurationMs: 0,
})
);
});
suite('hidden duration', () => {
let nowStub: sinon.SinonStub;
let visibilityStateStub: sinon.SinonStub;
const assertHiddenDurationsMs = (hiddenDurationMs: number) => {
service.dashboardDisplayed();
assert.isTrue(
service.timeEnd.calledWithMatch('StartupDashboardDisplayed', {
hiddenDurationMs,
})
);
};
setup(() => {
sinon.spy(service, 'timeEnd');
nowStub = sinon.stub(window.performance, 'now');
visibilityStateStub = {
value: value => {
Object.defineProperty(document, 'visibilityState', {
value,
configurable: true,
});
},
} as sinon.SinonStub;
});
test('starts in hidden', () => {
nowStub.returns(10);
visibilityStateStub.value('hidden');
service.onVisibilityChange();
nowStub.returns(15);
visibilityStateStub.value('visible');
service.onVisibilityChange();
assertHiddenDurationsMs(5);
});
test('full in hidden', () => {
nowStub.returns(10);
visibilityStateStub.value('hidden');
assertHiddenDurationsMs(10);
});
test('full in visible', () => {
nowStub.returns(10);
visibilityStateStub.value('visible');
assertHiddenDurationsMs(0);
});
test('accumulated', () => {
nowStub.returns(10);
visibilityStateStub.value('hidden');
service.onVisibilityChange();
nowStub.returns(15);
visibilityStateStub.value('visible');
service.onVisibilityChange();
nowStub.returns(20);
visibilityStateStub.value('hidden');
service.onVisibilityChange();
nowStub.returns(25);
assertHiddenDurationsMs(10);
});
test('reset after location change', () => {
nowStub.returns(10);
visibilityStateStub.value('hidden');
assertHiddenDurationsMs(10);
visibilityStateStub.value('visible');
nowStub.returns(15);
service.beforeLocationChanged();
service.timeEnd.resetHistory();
service.dashboardDisplayed();
assert.isTrue(
service.timeEnd.calledWithMatch('DashboardDisplayed', {
hiddenDurationMs: 0,
})
);
});
});
test('time and timeEnd', () => {
const nowStub = sinon.stub(window.performance, 'now').returns(0);
service.time('foo');
nowStub.returns(1);
service.time('bar');
nowStub.returns(2);
service.timeEnd('bar');
nowStub.returns(3);
service.timeEnd('foo');
assert.isTrue(
service.reporter.calledWithMatch('timing-report', 'UI Latency', 'foo', 3)
);
assert.isTrue(
service.reporter.calledWithMatch('timing-report', 'UI Latency', 'bar', 1)
);
});
test('timer object', () => {
const nowStub = sinon.stub(window.performance, 'now').returns(100);
const timer = service.getTimer('foo-bar');
nowStub.returns(150);
timer.end();
assert.isTrue(
service.reporter.calledWithMatch(
'timing-report',
'UI Latency',
'foo-bar',
50
)
);
});
test('timer object double call', () => {
const timer = service.getTimer('foo-bar');
timer.end();
assert.isTrue(service.reporter.calledOnce);
assert.throws(() => {
timer.end();
}, 'Timer for "foo-bar" already ended.');
});
test('timer object maximum', () => {
const nowStub = sinon.stub(window.performance, 'now').returns(100);
const timer = service.getTimer('foo-bar').withMaximum(100);
nowStub.returns(150);
timer.end();
assert.isTrue(service.reporter.calledOnce);
timer.reset();
nowStub.returns(260);
timer.end();
assert.isTrue(service.reporter.calledOnce);
});
test('reportExtension', () => {
service.reportExtension('foo');
assert.isTrue(
service.reporter.calledWithExactly(
'lifecycle',
'Extension detected',
'Extension detected',
undefined,
{name: 'foo'}
)
);
});
test('reportInteraction', () => {
service.reporter.restore();
sinon.spy(service, '_reportEvent');
service.pluginsLoaded(); // so we don't cache
service.reportInteraction('button-click', {name: 'sendReply'});
assert.isTrue(
service._reportEvent.getCall(2).calledWithMatch({
type: 'interaction',
name: 'button-click',
eventDetails: JSON.stringify({name: 'sendReply'}),
})
);
});
test('trackApi reports same event only once', () => {
sinon.spy(service, '_reportEvent');
const pluginApi = {getPluginName: () => 'test'};
service.trackApi(pluginApi, 'object', 'method');
service.trackApi(pluginApi, 'object', 'method');
assert.isTrue(service.reporter.calledOnce);
service.trackApi(pluginApi, 'object', 'method2');
assert.isTrue(service.reporter.calledTwice);
});
test('report start time', () => {
service.reporter.restore();
sinon.stub(window.performance, 'now').returns(42);
sinon.spy(service, '_reportEvent');
const dispatchStub = sinon.spy(document, 'dispatchEvent');
service.pluginsLoaded();
service.time('timeAction');
service.timeEnd('timeAction');
assert.isTrue(
service._reportEvent.getCall(2).calledWithMatch({
type: 'timing-report',
category: 'UI Latency',
name: 'timeAction',
value: 0,
eventStart: 42,
})
);
assert.equal(
(dispatchStub.getCall(2).args[0] as CustomEvent).detail.eventStart,
42
);
});
test('dedup', () => {
assert.isFalse(service._dedup('a', undefined, undefined));
assert.isFalse(service._dedup('a', undefined, undefined));
let deduping = Deduping.EVENT_ONCE_PER_SESSION;
assert.isFalse(service._dedup('b', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('b', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('b', {x: 'bar'}, deduping));
deduping = Deduping.DETAILS_ONCE_PER_SESSION;
assert.isFalse(service._dedup('c', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('c', {x: 'foo'}, deduping));
assert.isFalse(service._dedup('c', {x: 'bar'}, deduping));
assert.isTrue(service._dedup('c', {x: 'bar'}, deduping));
deduping = Deduping.EVENT_ONCE_PER_CHANGE;
service.setChangeId(1);
assert.isFalse(service._dedup('d', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('d', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('d', {x: 'bar'}, deduping));
service.setChangeId(2);
assert.isFalse(service._dedup('d', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('d', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('d', {x: 'bar'}, deduping));
deduping = Deduping.DETAILS_ONCE_PER_CHANGE;
service.setChangeId(1);
assert.isFalse(service._dedup('e', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('e', {x: 'foo'}, deduping));
assert.isFalse(service._dedup('e', {x: 'bar'}, deduping));
assert.isTrue(service._dedup('e', {x: 'bar'}, deduping));
service.setChangeId(2);
assert.isFalse(service._dedup('e', {x: 'foo'}, deduping));
assert.isTrue(service._dedup('e', {x: 'foo'}, deduping));
assert.isFalse(service._dedup('e', {x: 'bar'}, deduping));
assert.isTrue(service._dedup('e', {x: 'bar'}, deduping));
});
suite('plugins', () => {
setup(() => {
service.reporter.restore();
sinon.stub(service, '_reportEvent');
});
test('pluginsLoaded reports time', () => {
sinon.stub(window.performance, 'now').returns(42);
service.pluginsLoaded();
assert.isTrue(
service._reportEvent.calledWithMatch({
type: 'timing-report',
category: 'UI Latency',
name: 'PluginsLoaded',
value: 42,
})
);
});
test('pluginsLoaded reports plugins', () => {
service.pluginsLoaded(['foo', 'bar']);
assert.isTrue(
service._reportEvent.calledWithMatch({
type: 'lifecycle',
category: 'Plugins installed',
eventDetails: JSON.stringify({pluginsList: ['foo', 'bar']}),
})
);
});
test('caches reports if plugins are not loaded', () => {
service.timeEnd('foo');
assert.isFalse(service._reportEvent.called);
});
test('reports if plugins are loaded', () => {
service.pluginsLoaded();
assert.isTrue(service._reportEvent.called);
});
test('reports if metrics plugin xyz is loaded', () => {
service.pluginLoaded('metrics-xyz');
assert.isTrue(service._reportEvent.called);
});
test('reports cached events preserving order', () => {
service.time('foo');
service.time('bar');
service.timeEnd('foo');
service.pluginsLoaded();
service.timeEnd('bar');
assert.isTrue(
service._reportEvent.getCall(0).calledWithMatch({
type: 'timing-report',
category: 'UI Latency',
name: 'foo',
})
);
assert.isTrue(
service._reportEvent.getCall(1).calledWithMatch({
type: 'timing-report',
category: 'UI Latency',
name: 'PluginsLoaded',
})
);
assert.isTrue(
service._reportEvent
.getCall(2)
.calledWithMatch({type: 'lifecycle', category: 'Plugins installed'})
);
assert.isTrue(
service._reportEvent.getCall(3).calledWithMatch({
type: 'timing-report',
category: 'UI Latency',
name: 'bar',
})
);
});
});
test('search', () => {
service.locationChanged('_handleSomeRoute');
assert.isTrue(
service.reporter.calledWithExactly(
'nav-report',
'Location Changed',
'Page',
'_handleSomeRoute'
)
);
});
suite('exception logging', () => {
let fakeWindow: any;
let reporter: sinon.SinonStub;
const emulateThrow = function (
msg?: string,
url?: string,
line?: number,
column?: number,
error?: Error
) {
return fakeWindow.onerror(msg, url, line, column, error);
};
setup(() => {
reporter = service.reporter;
fakeWindow = {
handlers: {},
addEventListener(type: string, handler: object) {
this.handlers[type] = handler;
},
};
sinon.stub(console, 'error');
Object.defineProperty(getAppContext(), 'reportingService', {
get() {
return service;
},
});
const errorReporter = initErrorReporter(getAppContext().reportingService);
errorReporter.catchErrors(fakeWindow);
});
test('is reported', () => {
const error = new Error('bar');
error.stack = undefined;
emulateThrow('bar', 'http://url', 4, 2, error);
assert.isTrue(reporter.calledWith('error', 'exception', 'onError'));
});
test('is reported with message', () => {
const error = new Error('bar');
emulateThrow('bar', 'http://url', 4, 2, error);
const eventDetails = reporter.lastCall.args[4];
assert.equal(eventDetails.errorMessage, 'onError: bar');
});
test('is reported with stack', () => {
const error = new Error('bar');
emulateThrow('bar', 'http://url', 4, 2, error);
const eventDetails = reporter.lastCall.args[4];
assert.equal(error.stack, eventDetails.stack);
});
test('prevent default event handler', () => {
assert.isTrue(emulateThrow());
});
test('unhandled rejection', () => {
const newError = new Error('bar');
fakeWindow.handlers['unhandledrejection']({reason: newError});
assert.isTrue(
reporter.calledWith('error', 'exception', 'unhandledrejection')
);
});
});
});
suite('InteractionReporter', () => {
let interactionReporter: InteractionReporter;
let clock: SinonFakeTimers;
let stub: SinonStub;
let activeCalls: number[] = [];
let passiveCalls: number[] = [];
setup(() => {
clock = sinon.useFakeTimers(0);
activeCalls = [];
passiveCalls = [];
const reporting = grReportingMock;
stub = sinon
.stub(reporting, 'reportInteraction')
.callsFake((interaction: string | Interaction) => {
if (interaction === Interaction.USER_ACTIVE) {
activeCalls.push(clock.now);
}
if (interaction === Interaction.USER_PASSIVE) {
passiveCalls.push(clock.now);
}
});
interactionReporter = new InteractionReporter(reporting, 1000);
});
teardown(() => {
clock.restore();
interactionReporter.finalize();
});
test('interaction example', () => {
clock.tick(500);
clock.tick(1000);
document.dispatchEvent(new MouseEvent('mousemove'));
clock.tick(1000);
document.dispatchEvent(new MouseEvent('mousemove'));
document.dispatchEvent(new MouseEvent('scroll'));
document.dispatchEvent(new MouseEvent('wheel'));
clock.tick(1000);
clock.tick(1000);
clock.tick(1000);
document.dispatchEvent(new MouseEvent('mousemove'));
clock.tick(1000);
document.dispatchEvent(new MouseEvent('mousemove'));
clock.tick(1000);
assert.sameOrderedMembers(activeCalls, [2000, 3000, 6000, 7000]);
assert.sameOrderedMembers(passiveCalls, [1000, 4000, 5000]);
assert.isUndefined(stub.getCall(0).args[1].events);
assert.sameMembers(stub.getCall(1).args[1].events, ['mousemove']);
assert.sameMembers(stub.getCall(2).args[1].events, [
'mousemove',
'scroll',
'wheel',
]);
});
});