fix: match client step and server action by explicit stepId
This commit is contained in:
parent
b06c1dfff1
commit
2f540d8ca4
|
|
@ -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);
|
||||
});
|
||||
};
|
||||
}
|
||||
|
|
@ -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;
|
||||
|
||||
|
|
@ -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);
|
||||
|
|
@ -244,4 +249,5 @@ type ApiZone = {
|
|||
csi: ClientInstrumentation | undefined;
|
||||
callCookie: any;
|
||||
wallTime: number;
|
||||
stepId?: string;
|
||||
};
|
||||
|
|
|
|||
|
|
@ -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>;
|
||||
|
|
@ -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>;
|
||||
|
|
|
|||
|
|
@ -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)
|
||||
|
|
@ -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
|
||||
|
|
|
|||
|
|
@ -35,6 +35,7 @@ scheme.Metadata = tObject({
|
|||
apiName: tOptional(tString),
|
||||
internal: tOptional(tBoolean),
|
||||
wallTime: tOptional(tNumber),
|
||||
stepId: tOptional(tString),
|
||||
});
|
||||
scheme.ClientSideCallMetadata = tObject({
|
||||
id: tNumber,
|
||||
|
|
|
|||
|
|
@ -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,
|
||||
|
|
|
|||
|
|
@ -543,6 +543,7 @@ function createBeforeActionTraceEvent(metadata: CallMetadata): trace.BeforeActio
|
|||
method: metadata.method,
|
||||
params: metadata.params,
|
||||
wallTime: metadata.wallTime,
|
||||
stepId: metadata.stepId,
|
||||
pageId: metadata.pageId,
|
||||
};
|
||||
}
|
||||
|
|
|
|||
|
|
@ -141,4 +141,5 @@ Call log:
|
|||
export type ExpectZone = {
|
||||
title: string;
|
||||
wallTime: number;
|
||||
stepId: string;
|
||||
};
|
||||
|
|
|
|||
|
|
@ -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 };
|
||||
|
|
@ -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;
|
||||
|
|
|
|||
|
|
@ -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();
|
||||
|
|
|
|||
|
|
@ -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[];
|
||||
|
|
|
|||
|
|
@ -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;
|
||||
|
|
|
|||
|
|
@ -150,6 +150,7 @@ export type Metadata = {
|
|||
apiName?: string,
|
||||
internal?: boolean,
|
||||
wallTime?: number,
|
||||
stepId?: string,
|
||||
};
|
||||
|
||||
export type ClientSideCallMetadata = {
|
||||
|
|
|
|||
|
|
@ -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
|
||||
|
|
|
|||
|
|
@ -72,6 +72,6 @@ export function createEmptyContext(): ContextEntry {
|
|||
events: [],
|
||||
errors: [],
|
||||
stdio: [],
|
||||
hasSource: false
|
||||
hasSource: false,
|
||||
};
|
||||
}
|
||||
|
|
|
|||
|
|
@ -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.
|
||||
|
|
@ -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);
|
||||
|
|
|
|||
|
|
@ -63,6 +63,7 @@ export type BeforeActionTraceEvent = {
|
|||
method: string;
|
||||
params: Record<string, any>;
|
||||
wallTime: number;
|
||||
stepId?: string;
|
||||
beforeSnapshot?: string;
|
||||
stack?: StackFrame[];
|
||||
pageId?: string;
|
||||
|
|
|
|||
|
|
@ -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': `
|
||||
|
|
|
|||
Loading…
Reference in a new issue