diff --git a/packages/playwright-core/src/client/channelOwner.ts b/packages/playwright-core/src/client/channelOwner.ts index 8670ebbea2..466c84bed7 100644 --- a/packages/playwright-core/src/client/channelOwner.ts +++ b/packages/playwright-core/src/client/channelOwner.ts @@ -143,11 +143,15 @@ export abstract class ChannelOwner { 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('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 ${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; }; diff --git a/packages/playwright-core/src/client/clientInstrumentation.ts b/packages/playwright-core/src/client/clientInstrumentation.ts index 2b5dd00970..80334ddd44 100644 --- a/packages/playwright-core/src/client/clientInstrumentation.ts +++ b/packages/playwright-core/src/client/clientInstrumentation.ts @@ -22,7 +22,7 @@ export interface ClientInstrumentation { addListener(listener: ClientInstrumentationListener): void; removeListener(listener: ClientInstrumentationListener): void; removeAllListeners(): void; - onApiCallBegin(apiCall: string, params: Record, frames: StackFrame[], wallTime: number, userData: any): void; + onApiCallBegin(apiCall: string, params: Record, frames: StackFrame[], wallTime: number, userData: any, out: { stepId?: string }): void; onApiCallEnd(userData: any, error?: Error): void; onDidCreateBrowserContext(context: BrowserContext): Promise; onDidCreateRequestContext(context: APIRequestContext): Promise; @@ -32,7 +32,7 @@ export interface ClientInstrumentation { } export interface ClientInstrumentationListener { - onApiCallBegin?(apiName: string, params: Record, frames: StackFrame[], wallTime: number, userData: any): void; + onApiCallBegin?(apiName: string, params: Record, frames: StackFrame[], wallTime: number, userData: any, out: { stepId?: string }): void; onApiCallEnd?(userData: any, error?: Error): void; onDidCreateBrowserContext?(context: BrowserContext): Promise; onDidCreateRequestContext?(context: APIRequestContext): Promise; diff --git a/packages/playwright-core/src/client/connection.ts b/packages/playwright-core/src/client/connection.ts index 611a8c9f6a..539fd9fc07 100644 --- a/packages/playwright-core/src/client/connection.ts +++ b/packages/playwright-core/src/client/connection.ts @@ -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 { + async sendMessageToServer(object: ChannelOwner, method: string, params: any, apiName: string | undefined, frames: channels.StackFrame[], wallTime: number | undefined, stepId?: string): Promise { 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 diff --git a/packages/playwright-core/src/protocol/validator.ts b/packages/playwright-core/src/protocol/validator.ts index 83cfc633ab..b8e08f87d4 100644 --- a/packages/playwright-core/src/protocol/validator.ts +++ b/packages/playwright-core/src/protocol/validator.ts @@ -35,6 +35,7 @@ scheme.Metadata = tObject({ apiName: tOptional(tString), internal: tOptional(tBoolean), wallTime: tOptional(tNumber), + stepId: tOptional(tString), }); scheme.ClientSideCallMetadata = tObject({ id: tNumber, diff --git a/packages/playwright-core/src/server/dispatchers/dispatcher.ts b/packages/playwright-core/src/server/dispatchers/dispatcher.ts index 837a634e09..a447ca6268 100644 --- a/packages/playwright-core/src/server/dispatchers/dispatcher.ts +++ b/packages/playwright-core/src/server/dispatchers/dispatcher.ts @@ -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, diff --git a/packages/playwright-core/src/server/trace/recorder/tracing.ts b/packages/playwright-core/src/server/trace/recorder/tracing.ts index 2639aff91d..c3d9dc9e1d 100644 --- a/packages/playwright-core/src/server/trace/recorder/tracing.ts +++ b/packages/playwright-core/src/server/trace/recorder/tracing.ts @@ -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, }; } diff --git a/packages/playwright-core/src/utils/stackTrace.ts b/packages/playwright-core/src/utils/stackTrace.ts index 2864d1ec81..547a026912 100644 --- a/packages/playwright-core/src/utils/stackTrace.ts +++ b/packages/playwright-core/src/utils/stackTrace.ts @@ -141,4 +141,5 @@ Call log: export type ExpectZone = { title: string; wallTime: number; + stepId: string; }; diff --git a/packages/playwright/src/index.ts b/packages/playwright/src/index.ts index 6cf690ad50..7fed646b45 100644 --- a/packages/playwright/src/index.ts +++ b/packages/playwright/src/index.ts @@ -247,7 +247,7 @@ const playwrightFixtures: Fixtures = ({ const artifactsRecorder = new ArtifactsRecorder(playwright, tracing().artifactsDir(), screenshot); await artifactsRecorder.willStartTest(testInfo as TestInfoImpl); const csiListener: ClientInstrumentationListener = { - onApiCallBegin: (apiName: string, params: Record, frames: StackFrame[], wallTime: number, userData: any) => { + onApiCallBegin: (apiName: string, params: Record, 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 = ({ wallTime, }); userData.userObject = step; + out.stepId = step.stepId; }, onApiCallEnd: (userData: any, error?: Error) => { const step = userData.userObject; diff --git a/packages/playwright/src/matchers/expect.ts b/packages/playwright/src/matchers/expect.ts index 5d51a20b5e..78e829a5c6 100644 --- a/packages/playwright/src/matchers/expect.ts +++ b/packages/playwright/src/matchers/expect.ts @@ -295,7 +295,7 @@ class ExpectMetaInfoProxyHandler implements ProxyHandler { // so they behave like a retriable step. const result = (matcherName === 'toPass' || this._info.isPoll) ? zones.run('stepZone', step, callback) : - zones.run('expectZone', { title, wallTime }, callback); + zones.run('expectZone', { title, wallTime, stepId: step.stepId }, callback); if (result instanceof Promise) return result.then(finalizer).catch(reportStepError); finalizer(); diff --git a/packages/playwright/src/worker/testInfo.ts b/packages/playwright/src/worker/testInfo.ts index 6e55f68dac..6f2eb6eb52 100644 --- a/packages/playwright/src/worker/testInfo.ts +++ b/packages/playwright/src/worker/testInfo.ts @@ -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[]; diff --git a/packages/protocol/src/callMetadata.ts b/packages/protocol/src/callMetadata.ts index b011e9bf61..9d9e050438 100644 --- a/packages/protocol/src/callMetadata.ts +++ b/packages/protocol/src/callMetadata.ts @@ -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; diff --git a/packages/protocol/src/channels.ts b/packages/protocol/src/channels.ts index d80152d8f0..4ad2b9be95 100644 --- a/packages/protocol/src/channels.ts +++ b/packages/protocol/src/channels.ts @@ -150,6 +150,7 @@ export type Metadata = { apiName?: string, internal?: boolean, wallTime?: number, + stepId?: string, }; export type ClientSideCallMetadata = { diff --git a/packages/protocol/src/protocol.yml b/packages/protocol/src/protocol.yml index 8f1fb99cf3..3ad04d331e 100644 --- a/packages/protocol/src/protocol.yml +++ b/packages/protocol/src/protocol.yml @@ -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 diff --git a/packages/trace-viewer/src/entries.ts b/packages/trace-viewer/src/entries.ts index a53fd0314b..bca5751ab2 100644 --- a/packages/trace-viewer/src/entries.ts +++ b/packages/trace-viewer/src/entries.ts @@ -72,6 +72,6 @@ export function createEmptyContext(): ContextEntry { events: [], errors: [], stdio: [], - hasSource: false + hasSource: false, }; } diff --git a/packages/trace-viewer/src/ui/modelUtil.ts b/packages/trace-viewer/src/ui/modelUtil.ts index 8a24c89430..ac4cf2f757 100644 --- a/packages/trace-viewer/src/ui/modelUtil.ts +++ b/packages/trace-viewer/src/ui/modelUtil.ts @@ -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(); 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); diff --git a/packages/trace/src/trace.ts b/packages/trace/src/trace.ts index 7387f612aa..5eb060f9d7 100644 --- a/packages/trace/src/trace.ts +++ b/packages/trace/src/trace.ts @@ -63,6 +63,7 @@ export type BeforeActionTraceEvent = { method: string; params: Record; wallTime: number; + stepId?: string; beforeSnapshot?: string; stack?: StackFrame[]; pageId?: string; diff --git a/tests/playwright-test/reporter-html.spec.ts b/tests/playwright-test/reporter-html.spec.ts index 9d0c6e84fc..47f67a7bb9 100644 --- a/tests/playwright-test/reporter-html.spec.ts +++ b/tests/playwright-test/reporter-html.spec.ts @@ -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': `