Skip to content

Commit

Permalink
fix: match client step and server action by explicit stepId
Browse files Browse the repository at this point in the history
  • Loading branch information
yury-s committed May 11, 2024
1 parent 64b4ac1 commit 0af856e
Show file tree
Hide file tree
Showing 17 changed files with 75 additions and 16 deletions.
16 changes: 11 additions & 5 deletions packages/playwright-core/src/client/channelOwner.ts
Original file line number Diff line number Diff line change
Expand Up @@ -143,11 +143,15 @@ export abstract class ChannelOwner<T extends channels.Channel = channels.Channel
if (validator) {
return async (params: any) => {
return await this._wrapApiCall(async apiZone => {
const { apiName, frames, csi, callCookie, wallTime } = apiZone.reported ? { apiName: undefined, csi: undefined, callCookie: undefined, frames: [], wallTime: undefined } : apiZone;
const { apiName, frames, csi, callCookie, wallTime, stepId } = apiZone.reported ? { apiName: undefined, csi: undefined, callCookie: undefined, frames: [], wallTime: undefined, stepId: undefined } : apiZone;
apiZone.reported = true;
if (csi && apiName)
csi.onApiCallBegin(apiName, params, frames, wallTime, callCookie);
return await this._connection.sendMessageToServer(this, prop, validator(params, '', { tChannelImpl: tChannelImplToWire, binary: this._connection.rawBuffers() ? 'buffer' : 'toBase64' }), apiName, frames, wallTime);
let currentStepId = stepId;
if (csi && apiName) {
const out: { stepId?: string } = {};
csi.onApiCallBegin(apiName, params, frames, wallTime, callCookie, out);
currentStepId = out.stepId;
}
return await this._connection.sendMessageToServer(this, prop, validator(params, '', { tChannelImpl: tChannelImplToWire, binary: this._connection.rawBuffers() ? 'buffer' : 'toBase64' }), apiName, frames, wallTime, currentStepId);
});
};
}
Expand Down Expand Up @@ -176,6 +180,7 @@ export abstract class ChannelOwner<T extends channels.Channel = channels.Channel
// Enclosing zone could have provided the apiName and wallTime.
const expectZone = zones.zoneData<ExpectZone>('expectZone');
const wallTime = expectZone ? expectZone.wallTime : Date.now();
const stepId = expectZone?.stepId;
if (!isInternal && expectZone)
apiName = expectZone.title;

Expand All @@ -186,7 +191,7 @@ export abstract class ChannelOwner<T extends channels.Channel = channels.Channel

try {
logApiCall(logger, `=> ${apiName} started`, isInternal);
const apiZone: ApiZone = { apiName, frames, isInternal, reported: false, csi, callCookie, wallTime };
const apiZone: ApiZone = { apiName, frames, isInternal, reported: false, csi, callCookie, wallTime, stepId };
const result = await zones.run('apiZone', apiZone, async () => await func(apiZone));
csi?.onApiCallEnd(callCookie);
logApiCall(logger, `<= ${apiName} succeeded`, isInternal);
Expand Down Expand Up @@ -244,4 +249,5 @@ type ApiZone = {
csi: ClientInstrumentation | undefined;
callCookie: any;
wallTime: number;
stepId?: string;
};
4 changes: 2 additions & 2 deletions packages/playwright-core/src/client/clientInstrumentation.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ export interface ClientInstrumentation {
addListener(listener: ClientInstrumentationListener): void;
removeListener(listener: ClientInstrumentationListener): void;
removeAllListeners(): void;
onApiCallBegin(apiCall: string, params: Record<string, any>, frames: StackFrame[], wallTime: number, userData: any): void;
onApiCallBegin(apiCall: string, params: Record<string, any>, frames: StackFrame[], wallTime: number, userData: any, out: { stepId?: string }): void;
onApiCallEnd(userData: any, error?: Error): void;
onDidCreateBrowserContext(context: BrowserContext): Promise<void>;
onDidCreateRequestContext(context: APIRequestContext): Promise<void>;
Expand All @@ -32,7 +32,7 @@ export interface ClientInstrumentation {
}

export interface ClientInstrumentationListener {
onApiCallBegin?(apiName: string, params: Record<string, any>, frames: StackFrame[], wallTime: number, userData: any): void;
onApiCallBegin?(apiName: string, params: Record<string, any>, frames: StackFrame[], wallTime: number, userData: any, out: { stepId?: string }): void;
onApiCallEnd?(userData: any, error?: Error): void;
onDidCreateBrowserContext?(context: BrowserContext): Promise<void>;
onDidCreateRequestContext?(context: APIRequestContext): Promise<void>;
Expand Down
4 changes: 2 additions & 2 deletions packages/playwright-core/src/client/connection.ts
Original file line number Diff line number Diff line change
Expand Up @@ -118,7 +118,7 @@ export class Connection extends EventEmitter {
this._tracingCount--;
}

async sendMessageToServer(object: ChannelOwner, method: string, params: any, apiName: string | undefined, frames: channels.StackFrame[], wallTime: number | undefined): Promise<any> {
async sendMessageToServer(object: ChannelOwner, method: string, params: any, apiName: string | undefined, frames: channels.StackFrame[], wallTime: number | undefined, stepId?: string): Promise<any> {
if (this._closedError)
throw this._closedError;
if (object._wasCollected)
Expand All @@ -133,7 +133,7 @@ export class Connection extends EventEmitter {
debugLogger.log('channel', 'SEND> ' + JSON.stringify(message));
}
const location = frames[0] ? { file: frames[0].file, line: frames[0].line, column: frames[0].column } : undefined;
const metadata: channels.Metadata = { wallTime, apiName, location, internal: !apiName };
const metadata: channels.Metadata = { wallTime, apiName, location, internal: !apiName, stepId };
if (this._tracingCount && frames && type !== 'LocalUtils')
this._localUtils?._channel.addStackToTracingNoReply({ callData: { stack: frames, id } }).catch(() => {});
// We need to exit zones before calling into the server, otherwise
Expand Down
1 change: 1 addition & 0 deletions packages/playwright-core/src/protocol/validator.ts
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@ scheme.Metadata = tObject({
apiName: tOptional(tString),
internal: tOptional(tBoolean),
wallTime: tOptional(tNumber),
stepId: tOptional(tString),
});
scheme.ClientSideCallMetadata = tObject({
id: tNumber,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -290,6 +290,7 @@ export class DispatcherConnection {
location: validMetadata.location,
apiName: validMetadata.apiName,
internal: validMetadata.internal,
stepId: validMetadata.stepId,
objectId: sdkObject?.guid,
pageId: sdkObject?.attribution?.page?.guid,
frameId: sdkObject?.attribution?.frame?.guid,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -536,6 +536,7 @@ function createBeforeActionTraceEvent(metadata: CallMetadata): trace.BeforeActio
method: metadata.method,
params: metadata.params,
wallTime: metadata.wallTime,
stepId: metadata.stepId,
pageId: metadata.pageId,
};
}
Expand Down
1 change: 1 addition & 0 deletions packages/playwright-core/src/utils/stackTrace.ts
Original file line number Diff line number Diff line change
Expand Up @@ -141,4 +141,5 @@ Call log:
export type ExpectZone = {
title: string;
wallTime: number;
stepId: string;
};
3 changes: 2 additions & 1 deletion packages/playwright/src/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -247,7 +247,7 @@ const playwrightFixtures: Fixtures<TestFixtures, WorkerFixtures> = ({
const artifactsRecorder = new ArtifactsRecorder(playwright, tracing().artifactsDir(), screenshot);
await artifactsRecorder.willStartTest(testInfo as TestInfoImpl);
const csiListener: ClientInstrumentationListener = {
onApiCallBegin: (apiName: string, params: Record<string, any>, frames: StackFrame[], wallTime: number, userData: any) => {
onApiCallBegin: (apiName: string, params: Record<string, any>, frames: StackFrame[], wallTime: number, userData: any, out: { stepId?: string }) => {
const testInfo = currentTestInfo();
if (!testInfo || apiName.includes('setTestIdAttribute'))
return { userObject: null };
Expand All @@ -260,6 +260,7 @@ const playwrightFixtures: Fixtures<TestFixtures, WorkerFixtures> = ({
wallTime,
});
userData.userObject = step;
out.stepId = step.stepId;
},
onApiCallEnd: (userData: any, error?: Error) => {
const step = userData.userObject;
Expand Down
2 changes: 1 addition & 1 deletion packages/playwright/src/matchers/expect.ts
Original file line number Diff line number Diff line change
Expand Up @@ -295,7 +295,7 @@ class ExpectMetaInfoProxyHandler implements ProxyHandler<any> {
// so they behave like a retriable step.
const result = (matcherName === 'toPass' || this._info.isPoll) ?
zones.run('stepZone', step, callback) :
zones.run<ExpectZone, any>('expectZone', { title, wallTime }, callback);
zones.run<ExpectZone, any>('expectZone', { title, wallTime, stepId: step.stepId }, callback);
if (result instanceof Promise)
return result.then(finalizer).catch(reportStepError);
finalizer();
Expand Down
2 changes: 1 addition & 1 deletion packages/playwright/src/worker/testInfo.ts
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ export interface TestStepInternal {
complete(result: { error?: Error, attachments?: Attachment[] }): void;
stepId: string;
title: string;
category: 'hook' | 'fixture' | 'test.step' | string;
category: 'hook' | 'fixture' | 'test.step' | 'expect' | string;
wallTime: number;
location?: Location;
boxedStack?: StackFrame[];
Expand Down
2 changes: 2 additions & 0 deletions packages/protocol/src/callMetadata.ts
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,8 @@ export type CallMetadata = {
isServerSide?: boolean;
// Client wall time.
wallTime: number;
// Test runner step id.
stepId?: string;
location?: { file: string, line?: number, column?: number };
log: string[];
error?: SerializedError;
Expand Down
1 change: 1 addition & 0 deletions packages/protocol/src/channels.ts
Original file line number Diff line number Diff line change
Expand Up @@ -150,6 +150,7 @@ export type Metadata = {
apiName?: string,
internal?: boolean,
wallTime?: number,
stepId?: string,
};

export type ClientSideCallMetadata = {
Expand Down
2 changes: 2 additions & 0 deletions packages/protocol/src/protocol.yml
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,8 @@ Metadata:
internal: boolean?
# The number of milliseconds elapsed since midnight, January 1, 1970 UTC.
wallTime: number?
# Test runner step id.
stepId: string?

ClientSideCallMetadata:
type: object
Expand Down
2 changes: 1 addition & 1 deletion packages/trace-viewer/src/entries.ts
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,6 @@ export function createEmptyContext(): ContextEntry {
events: [],
errors: [],
stdio: [],
hasSource: false
hasSource: false,
};
}
16 changes: 13 additions & 3 deletions packages/trace-viewer/src/ui/modelUtil.ts
Original file line number Diff line number Diff line change
Expand Up @@ -215,9 +215,19 @@ function mergeActionsAndUpdateTimingSameTrace(contexts: ContextEntry[]) {
const libraryContexts = contexts.filter(context => context.origin === 'library');
const testRunnerContexts = contexts.filter(context => context.origin === 'testRunner');

// Library actions are replaced with corresponding test runner steps. Matching with
// the test runner steps enables us to find parent steps.
// - In the newer versions the actions are matched by explicit step id stored in the
// library context actions.
// - In the older versions the step id is not stored and the match is perfomed based on
// action name and wallTime.
const matchByStepId = libraryContexts.some(c => c.actions.some(a => !!a.stepId));

for (const context of libraryContexts) {
for (const action of context.actions)
map.set(`${action.apiName}@${action.wallTime}`, { ...action, context });
for (const action of context.actions) {
const key = matchByStepId ? action.stepId! : `${action.apiName}@${action.wallTime}`;
map.set(key, { ...action, context });
}
}

// Protocol call aka library contexts have startTime/endTime as server-side times.
Expand All @@ -231,7 +241,7 @@ function mergeActionsAndUpdateTimingSameTrace(contexts: ContextEntry[]) {
const nonPrimaryIdToPrimaryId = new Map<string, string>();
for (const context of testRunnerContexts) {
for (const action of context.actions) {
const key = `${action.apiName}@${action.wallTime}`;
const key = matchByStepId ? action.callId : `${action.apiName}@${action.wallTime}`;
const existing = map.get(key);
if (existing) {
nonPrimaryIdToPrimaryId.set(action.callId, existing.callId);
Expand Down
1 change: 1 addition & 0 deletions packages/trace/src/trace.ts
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,7 @@ export type BeforeActionTraceEvent = {
method: string;
params: Record<string, any>;
wallTime: number;
stepId?: string;
beforeSnapshot?: string;
stack?: StackFrame[];
pageId?: string;
Expand Down
32 changes: 32 additions & 0 deletions tests/playwright-test/reporter-html.spec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -582,6 +582,38 @@ for (const useIntermediateMergeReport of [false] as const) {
await expect(page.locator('.source-line-running')).toContainText('request.get');
});

test('trace should not hang when showing parallel api requests', async ({ runInlineTest, page, server, showReport }) => {
const result = await runInlineTest({
'playwright.config.js': `
module.exports = { use: { trace: 'on' } };
`,
'a.test.js': `
import { test, expect, request } from '@playwright/test';
test('log two contexts', async function({ }) {
const api1 = await request.newContext();
const api2 = await request.newContext();
await Promise.all([
api1.get('${server.EMPTY_PAGE}'),
api1.get('${server.CROSS_PROCESS_PREFIX}/empty.html'),
api2.get('${server.EMPTY_PAGE}'),
api2.get('${server.CROSS_PROCESS_PREFIX}/empty.html'),
]);
});
`,
}, { reporter: 'html' }, { PW_TEST_HTML_REPORT_OPEN: 'never' });
expect(result.exitCode).toBe(0);
expect(result.passed).toBe(1);

await showReport();
await page.getByRole('link', { name: 'View trace' }).click();

// Trace viewer should not hang here when displaying parallal requests.
await expect(page.getByTestId('actions-tree')).toContainText('apiRequestContext.get');
await page.getByText('apiRequestContext.get').nth(2).click();
await page.getByText('apiRequestContext.get').nth(1).click();
await page.getByText('apiRequestContext.get').nth(0).click();
});

test('should warn user when viewing via file:// protocol', async ({ runInlineTest, page, showReport }, testInfo) => {
const result = await runInlineTest({
'playwright.config.js': `
Expand Down

0 comments on commit 0af856e

Please sign in to comment.