Skip to content
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

Jump to bottom

feat: measure startup delay and journey duration #709

Merged
merged 3 commits into from
Jul 15, 2024
Merged

feat: measure startup delay and journey duration #709

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
8e2f758
feat: measure startup delay and journey duration
vigneshshanmugam Feb 27, 2023
3a20184
fix test
vigneshshanmugam Jul 12, 2024
be79456
move it under payload
vigneshshanmugam Jul 12, 2024
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
4 changes: 2 additions & 2 deletions __tests__/reporters/__snapshots__/json.test.ts.snap
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -195,7 +195,7 @@ exports[`json reporter screenshots write block & reference docs 1`] = `
{"type":"screenshot/block","_id":"e89af7cc2cae152df54ccf091793db64b3dfe995","@timestamp":1600300800000000,"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"blob":"/9j/2wBDAAYEBQYFBAYGBQYHBwYIChAKCgkJChQODwwQFxQYGBcUFhYaHSUfGhsjHBYWICwgIyYnKSopGR8tMC0oMCUoKSj/2wBDAQcHBwoIChMKChMoGhYaKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCj/wAARCABaAKADASIAAhEBAxEB/8QAFQABAQAAAAAAAAAAAAAAAAAAAAj/xAAUEAEAAAAAAAAAAAAAAAAAAAAA/8QAFAEBAAAAAAAAAAAAAAAAAAAAAP/EABQRAQAAAAAAAAAAAAAAAAAAAAD/2gAMAwEAAhEDEQA/AKcAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAB//9k=","blob_mime":"image/jpeg","package_version":"0.0.1"}
{"type":"screenshot/block","_id":"e89af7cc2cae152df54ccf091793db64b3dfe995","@timestamp":1600300800000000,"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"blob":"/9j/2wBDAAYEBQYFBAYGBQYHBwYIChAKCgkJChQODwwQFxQYGBcUFhYaHSUfGhsjHBYWICwgIyYnKSopGR8tMC0oMCUoKSj/2wBDAQcHBwoIChMKChMoGhYaKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCgoKCj/wAARCABaAKADASIAAhEBAxEB/8QAFQABAQAAAAAAAAAAAAAAAAAAAAj/xAAUEAEAAAAAAAAAAAAAAAAAAAAA/8QAFAEBAAAAAAAAAAAAAAAAAAAAAP/EABQRAQAAAAAAAAAAAAAAAAAAAAD/2gAMAwEAAhEDEQA/AKcAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAB//9k=","blob_mime":"image/jpeg","package_version":"0.0.1"}
{"type":"step/screenshot_ref","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1"},"step":{"name":"launch app","index":1},"root_fields":{"screenshot_ref":{"width":1280,"height":720,"blocks":[{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":0,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":0,"left":160,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":0,"left":320,"width":160,"height":90},{"hash":"7207d2da8fc8a9423ea2e38501061ba30dca2e49","top":0,"left":480,"width":160,"height":90},{"hash":"c895742d0c552bb1e90bb9054dce0a207e0612f4","top":0,"left":640,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":0,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":0,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":0,"left":1120,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":90,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":90,"left":160,"width":160,"height":90},{"hash":"8dab22ef3ba33256e102c7755d6d05309d447a5d","top":90,"left":320,"width":160,"height":90},{"hash":"0503e01e69b834685b61bb12b897189f70b7f8cf","top":90,"left":480,"width":160,"height":90},{"hash":"1e2e95c527b7911704f108caa2dc124b71a6906c","top":90,"left":640,"width":160,"height":90},{"hash":"6bb91d0bcccfe17810c585ff9676da9bf060e7ea","top":90,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":90,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":90,"left":1120,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":180,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":180,"left":160,"width":160,"height":90},{"hash":"4bef2a34c082065f7fd8a9246be3b82265640151","top":180,"left":320,"width":160,"height":90},{"hash":"166035c43b7ec64602a23cecb800d72d07a8fd07","top":180,"left":480,"width":160,"height":90},{"hash":"5da56b5b7ff6d979000b0e6c3e5047a07eb746a9","top":180,"left":640,"width":160,"height":90},{"hash":"2cd55289e3819c419182ad42af7b0e017ef252ec","top":180,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":180,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":180,"left":1120,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":270,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":270,"left":160,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":270,"left":320,"width":160,"height":90},{"hash":"fead29b7726776d52be4fa448f1e0c603f89ea21","top":270,"left":480,"width":160,"height":90},{"hash":"07b755d38bae03aac9cfd6c0f10d98387d81026d","top":270,"left":640,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":270,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":270,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":270,"left":1120,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":160,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":320,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":480,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":640,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":360,"left":1120,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":160,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":320,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":480,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":640,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":450,"left":1120,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":160,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":320,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":480,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":640,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":540,"left":1120,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":0,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":160,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":320,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":480,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":640,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":800,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":960,"width":160,"height":90},{"hash":"e89af7cc2cae152df54ccf091793db64b3dfe995","top":630,"left":1120,"width":160,"height":90}]},"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"package_version":"0.0.1"}
{"type":"journey/end","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1","status":"failed"},"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"payload":{"start":0,"end":2,"status":"failed"},"package_version":"0.0.1"}
{"type":"journey/end","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1","status":"failed","duration":{"us":2000000}},"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"payload":{"status":"failed","browser_delay_us":0,"process_startup_epoch_us":1600300800000000},"package_version":"0.0.1"}
"
`;

Expand All @@ -210,6 +210,6 @@ exports[`json reporter writes each step as NDJSON to the FD 1`] = `
{"type":"step/end","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1"},"step":{"name":"s1","index":1,"status":"succeeded","duration":{"us":10000000}},"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"payload":{"source":"function noop() { }","url":"dummy","status":"succeeded"},"url":"dummy","package_version":"0.0.1"}
{"type":"journey/network_info","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1"},"root_fields":{"user_agent":{},"http":{"request":{}},"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"payload":{"browser":{},"is_navigation_request":true},"package_version":"0.0.1"}
{"type":"journey/browserconsole","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1"},"step":{"name":"step-name","index":0},"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"payload":{"text":"Boom","type":"error"},"package_version":"0.0.1"}
{"type":"journey/end","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1","status":"succeeded"},"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"payload":{"start":0,"end":11,"status":"succeeded"},"package_version":"0.0.1"}
{"type":"journey/end","@timestamp":1600300800000000,"journey":{"name":"j1","id":"j1","status":"succeeded","duration":{"us":11000000}},"root_fields":{"os":{"platform":"darwin"},"package":{"name":"@elastic/synthetics","version":"0.0.1"}},"payload":{"status":"succeeded","browser_delay_us":2000000,"process_startup_epoch_us":1600300800000000},"package_version":"0.0.1"}
"
`;
1 change: 1 addition & 0 deletions __tests__/reporters/base.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -92,6 +92,7 @@ describe('base reporter', () => {
error,
start: 0,
end: 1,
browserDelay: 0,
options: {},
});
reporter.onEnd();
Expand Down
5 changes: 4 additions & 1 deletion __tests__/reporters/buildkite-cli.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,7 @@ describe('buildkite cli reporter', () => {
let stream: SonicBoom;
let reporter: BuildKiteCLIReporter;
const timestamp = 1600300800000000;
const j1 = journey('j1', () => {});
const j1 = journey('j1', () => { });

const readAndCloseStream = async () => {
/**
Expand Down Expand Up @@ -90,6 +90,7 @@ describe('buildkite cli reporter', () => {
},
start: 0,
end: 1,
browserDelay: 0,
options: {},
});
reporter.onEnd();
Expand All @@ -111,6 +112,7 @@ describe('buildkite cli reporter', () => {
error,
start: 0,
end: 1,
browserDelay: 0,
options: {},
});
reporter.onEnd();
Expand Down Expand Up @@ -138,6 +140,7 @@ describe('buildkite cli reporter', () => {
status: 'succeeded',
start: 4,
end: 6,
browserDelay: 0,
options: {},
});
reporter.onEnd();
Expand Down
24 changes: 21 additions & 3 deletions __tests__/reporters/json.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -48,9 +48,18 @@ jest.mock(
jest.fn(() => ({ version: '0.0.1', name: '@elastic/synthetics' }))
);

/**
* Mock the timeOrigin to log process startup time
*/
jest.mock('perf_hooks', () => ({
performance: {
timeOrigin: 1600300800000,
},
}));

describe('json reporter', () => {
let dest: string;
const j1 = journey('j1', () => {});
const j1 = journey('j1', () => { });
let stream: SonicBoom;
let reporter: JSONReporter;
const timestamp = 1600300800000000;
Expand Down Expand Up @@ -160,6 +169,7 @@ describe('json reporter', () => {
status: 'succeeded',
start: 0,
end: 11,
browserDelay: 2,
options: {},
networkinfo: [
{
Expand Down Expand Up @@ -238,6 +248,7 @@ describe('json reporter', () => {
timestamp,
start: 0,
end: 1,
browserDelay: 0,
status: 'failed',
error: myErr,
options: {},
Expand All @@ -254,6 +265,7 @@ describe('json reporter', () => {
timestamp,
start: 0,
end: 1,
browserDelay: 0,
status: 'failed',
error: 'boom' as any,
options: {},
Expand All @@ -269,11 +281,12 @@ describe('json reporter', () => {
const journeyOpts = { name: 'name', id: 'id', tags: ['tag1', 'tag2'] };

reporter.onJourneyEnd(
journey(journeyOpts, () => {}),
journey(journeyOpts, () => { }),
{
timestamp,
start: 0,
end: 1,
browserDelay: 0,
status: 'skipped',
options: {},
}
Expand All @@ -282,7 +295,11 @@ describe('json reporter', () => {
const journeyEnd = (await readAndCloseStreamJson()).find(
json => json.type == 'journey/end'
);
expect(journeyEnd.journey).toEqual({ ...journeyOpts, status: 'skipped' });
expect(journeyEnd.journey).toEqual({
...journeyOpts,
duration: { us: 1 * 1e6 },
status: 'skipped',
});
});

it('captures number of journeys as metadata event', async () => {
Expand Down Expand Up @@ -331,6 +348,7 @@ describe('json reporter', () => {
reporter.onJourneyEnd(j1, {
timestamp,
start: 0,
browserDelay: 0,
end: 2,
status,
options,
Expand Down
2 changes: 2 additions & 0 deletions __tests__/reporters/junit.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -70,6 +70,7 @@ describe('junit reporter', () => {
timestamp,
start: 0,
end: 2,
browserDelay: 0,
status: 'failed',
options: {},
});
Expand Down Expand Up @@ -98,6 +99,7 @@ describe('junit reporter', () => {
timestamp,
start: 0,
end: 2,
browserDelay: 0,
status: 'failed',
options: {},
});
Expand Down
1 change: 1 addition & 0 deletions src/common_types.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -323,6 +323,7 @@ export type JourneyEndResult = JourneyStartResult &
JourneyResult & {
start: number;
end: number;
browserDelay: number;
options: RunOptions;
timestamp: number;
};
Expand Down
7 changes: 6 additions & 1 deletion src/core/runner.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -60,6 +60,7 @@ export type SuiteHooks = Record<HookType, Array<HooksCallback>>;

type JourneyContext = {
params?: Params;
browserDelay: number;
start: number;
driver: Driver;
pluginManager: PluginManager;
Expand All @@ -78,6 +79,7 @@ export default class Runner {
static screenshotPath = join(CACHE_PATH, 'screenshots');

static async createContext(options: RunOptions): Promise<JourneyContext> {
const browserStart = monotonicTimeInSeconds();
const driver = await Gatherer.setupDriver(options);
/**
* Do not include browser launch/context creation duration
Expand All @@ -92,6 +94,7 @@ export default class Runner {
await mkdir(this.screenshotPath, { recursive: true });
return {
start,
browserDelay: start - browserStart,
params: options.params,
driver,
pluginManager,
Expand Down Expand Up @@ -314,13 +317,14 @@ export default class Runner {
options: RunOptions
) {
const end = monotonicTimeInSeconds();
const { pluginManager, start, status, error } = result;
const { pluginManager, start, status, error, browserDelay } = result;
const pluginOutput = await pluginManager.output();
await this.#reporter?.onJourneyEnd?.(journey, {
status,
error,
start,
end,
browserDelay,
timestamp: getTimestamp(),
options,
...pluginOutput,
Expand Down Expand Up @@ -350,6 +354,7 @@ export default class Runner {
timestamp: getTimestamp(),
start,
options,
browserDelay: 0,
end: monotonicTimeInSeconds(),
...result,
});
Expand Down
2 changes: 1 addition & 1 deletion src/helpers.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -95,7 +95,7 @@ export function microSecsToSeconds(ts: number) {
/**
* Timestamp at which the current node process began.
*/
const processStart = performance.timeOrigin;
export const processStart = performance.timeOrigin;
export function getTimestamp() {
return (processStart + now()) * 1000;
}
Expand Down
38 changes: 25 additions & 13 deletions src/reporters/json.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@ import {
totalist,
isDirectory,
getDurationInUs,
processStart,
} from '../helpers';
import { Journey, Step } from '../dsl';
import snakeCaseKeys from 'snakecase-keys';
Expand Down Expand Up @@ -73,9 +74,9 @@ type OutputType =

type Payload = {
source?: string;
start?: number;
end?: number;
url?: string;
browser_delay_us?: number;
process_startup_epoch_us?: number;
status?: StatusValue;
pagemetrics?: PageMetrics;
type?: OutputType;
Expand All @@ -84,17 +85,19 @@ type Payload = {
network_conditions?: NetworkConditions;
};

type Duration = {
duration?: {
us: number;
};
};

type OutputFields = {
type: OutputType;
_id?: string;
journey?: Journey;
journey?: Partial<Journey> & Duration;
timestamp?: number;
url?: string;
step?: Partial<Step> & {
duration?: {
us: number;
};
};
step?: Partial<Step> & Duration;
error?: Error;
root_fields?: Record<string, unknown>;
payload?: Payload;
Expand Down Expand Up @@ -260,6 +263,7 @@ function journeyInfo(
id: journey.id,
tags: journey.tags,
status: type === 'journey/end' ? status : undefined,
duration: journey.duration,
};
}

Expand Down Expand Up @@ -369,8 +373,8 @@ export default class JSONReporter extends BaseReporter {
},
payload: event.networkConditions
? {
network_conditions: event.networkConditions,
}
network_conditions: event.networkConditions,
}
: undefined,
});
}
Expand Down Expand Up @@ -451,6 +455,7 @@ export default class JSONReporter extends BaseReporter {
timestamp,
start,
end,
browserDelay,
networkinfo,
browserconsole,
status,
Expand Down Expand Up @@ -517,13 +522,20 @@ export default class JSONReporter extends BaseReporter {

this.writeJSON({
type: 'journey/end',
journey,
journey: {
...journey,
duration: {
us: getDurationInUs(end - start),
},
},
timestamp,
error,
payload: {
start,
end,
status,
// convert from monotonic seconds time to microseconds
browser_delay_us: getDurationInUs(browserDelay),
// timestamp in microseconds at which the current node process began, measured in Unix time.
process_startup_epoch_us: Math.trunc(processStart * 1000),
},
});
}
Expand Down
Loading