diff --git a/packages/playwright-core/src/client/channelOwner.ts b/packages/playwright-core/src/client/channelOwner.ts index 466c84bed7..4ebe32595c 100644 --- a/packages/playwright-core/src/client/channelOwner.ts +++ b/packages/playwright-core/src/client/channelOwner.ts @@ -143,15 +143,15 @@ export abstract class ChannelOwner { return await this._wrapApiCall(async apiZone => { - const { apiName, frames, csi, callCookie, wallTime, stepId } = apiZone.reported ? { apiName: undefined, csi: undefined, callCookie: undefined, frames: [], wallTime: undefined, stepId: undefined } : apiZone; + const { apiName, frames, csi, callCookie, stepId } = apiZone.reported ? { apiName: undefined, csi: undefined, callCookie: undefined, frames: [], stepId: undefined } : apiZone; apiZone.reported = true; let currentStepId = stepId; if (csi && apiName) { const out: { stepId?: string } = {}; - csi.onApiCallBegin(apiName, params, frames, wallTime, callCookie, out); + csi.onApiCallBegin(apiName, params, frames, 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); + return await this._connection.sendMessageToServer(this, prop, validator(params, '', { tChannelImpl: tChannelImplToWire, binary: this._connection.rawBuffers() ? 'buffer' : 'toBase64' }), apiName, frames, currentStepId); }); }; } @@ -179,7 +179,6 @@ export abstract class ChannelOwner('expectZone'); - const wallTime = expectZone ? expectZone.wallTime : Date.now(); const stepId = expectZone?.stepId; if (!isInternal && expectZone) apiName = expectZone.title; @@ -191,7 +190,7 @@ export abstract class ChannelOwner ${apiName} started`, isInternal); - const apiZone: ApiZone = { apiName, frames, isInternal, reported: false, csi, callCookie, wallTime, stepId }; + const apiZone: ApiZone = { apiName, frames, isInternal, reported: false, csi, callCookie, stepId }; const result = await zones.run('apiZone', apiZone, async () => await func(apiZone)); csi?.onApiCallEnd(callCookie); logApiCall(logger, `<= ${apiName} succeeded`, isInternal); @@ -248,6 +247,5 @@ type ApiZone = { reported: boolean; 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 80334ddd44..dd73299420 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, out: { stepId?: string }): void; + onApiCallBegin(apiCall: string, params: Record, frames: StackFrame[], 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, out: { stepId?: string }): void; + onApiCallBegin?(apiName: string, params: Record, frames: StackFrame[], 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 539fd9fc07..294b5d9f6e 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, stepId?: string): Promise { + async sendMessageToServer(object: ChannelOwner, method: string, params: any, apiName: string | undefined, frames: channels.StackFrame[], 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, stepId }; + const metadata: channels.Metadata = { 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 b8e08f87d4..1cc57fb5a7 100644 --- a/packages/playwright-core/src/protocol/validator.ts +++ b/packages/playwright-core/src/protocol/validator.ts @@ -34,7 +34,6 @@ scheme.Metadata = tObject({ })), apiName: tOptional(tString), internal: tOptional(tBoolean), - wallTime: tOptional(tNumber), stepId: tOptional(tString), }); scheme.ClientSideCallMetadata = tObject({ diff --git a/packages/playwright-core/src/server/dispatchers/dispatcher.ts b/packages/playwright-core/src/server/dispatchers/dispatcher.ts index a447ca6268..e14960b495 100644 --- a/packages/playwright-core/src/server/dispatchers/dispatcher.ts +++ b/packages/playwright-core/src/server/dispatchers/dispatcher.ts @@ -286,7 +286,6 @@ export class DispatcherConnection { const sdkObject = dispatcher._object instanceof SdkObject ? dispatcher._object : undefined; const callMetadata: CallMetadata = { id: `call@${id}`, - wallTime: validMetadata.wallTime || Date.now(), location: validMetadata.location, apiName: validMetadata.apiName, internal: validMetadata.internal, diff --git a/packages/playwright-core/src/server/instrumentation.ts b/packages/playwright-core/src/server/instrumentation.ts index 5d212279e3..fbaa3345d6 100644 --- a/packages/playwright-core/src/server/instrumentation.ts +++ b/packages/playwright-core/src/server/instrumentation.ts @@ -106,7 +106,6 @@ export function serverSideCallMetadata(): CallMetadata { id: '', startTime: 0, endTime: 0, - wallTime: Date.now(), type: 'Internal', method: '', params: {}, diff --git a/packages/playwright-core/src/server/recorder.ts b/packages/playwright-core/src/server/recorder.ts index d5f84ba625..3a770741ae 100644 --- a/packages/playwright-core/src/server/recorder.ts +++ b/packages/playwright-core/src/server/recorder.ts @@ -605,7 +605,6 @@ class ContextRecorder extends EventEmitter { frameId: frame.guid, startTime: monotonicTime(), endTime: 0, - wallTime: Date.now(), type: 'Frame', method: action, params, diff --git a/packages/playwright-core/src/server/trace/recorder/tracing.ts b/packages/playwright-core/src/server/trace/recorder/tracing.ts index c3d9dc9e1d..85c783118d 100644 --- a/packages/playwright-core/src/server/trace/recorder/tracing.ts +++ b/packages/playwright-core/src/server/trace/recorder/tracing.ts @@ -542,7 +542,6 @@ function createBeforeActionTraceEvent(metadata: CallMetadata): trace.BeforeActio class: metadata.type, 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 547a026912..77e1365b3f 100644 --- a/packages/playwright-core/src/utils/stackTrace.ts +++ b/packages/playwright-core/src/utils/stackTrace.ts @@ -140,6 +140,5 @@ Call log: export type ExpectZone = { title: string; - wallTime: number; stepId: string; }; diff --git a/packages/playwright/src/common/testType.ts b/packages/playwright/src/common/testType.ts index 35e2a4668c..5c7850a3df 100644 --- a/packages/playwright/src/common/testType.ts +++ b/packages/playwright/src/common/testType.ts @@ -263,7 +263,7 @@ export class TestTypeImpl { const testInfo = currentTestInfo(); if (!testInfo) throw new Error(`test.step() can only be called from a test`); - const step = testInfo._addStep({ wallTime: Date.now(), category: 'test.step', title, box: options.box }); + const step = testInfo._addStep({ category: 'test.step', title, box: options.box }); return await zones.run('stepZone', step, async () => { try { const result = await body(); diff --git a/packages/playwright/src/index.ts b/packages/playwright/src/index.ts index 7fed646b45..9b8b4bc55b 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, out: { stepId?: string }) => { + onApiCallBegin: (apiName: string, params: Record, frames: StackFrame[], userData: any, out: { stepId?: string }) => { const testInfo = currentTestInfo(); if (!testInfo || apiName.includes('setTestIdAttribute')) return { userObject: null }; @@ -257,7 +257,6 @@ const playwrightFixtures: Fixtures = ({ title: renderApiCall(apiName, params), apiName, params, - wallTime, }); userData.userObject = step; out.stepId = step.stepId; diff --git a/packages/playwright/src/matchers/expect.ts b/packages/playwright/src/matchers/expect.ts index 78e829a5c6..0d5d226039 100644 --- a/packages/playwright/src/matchers/expect.ts +++ b/packages/playwright/src/matchers/expect.ts @@ -259,7 +259,6 @@ class ExpectMetaInfoProxyHandler implements ProxyHandler { const defaultTitle = `expect${this._info.isPoll ? '.poll' : ''}${this._info.isSoft ? '.soft' : ''}${this._info.isNot ? '.not' : ''}.${matcherName}${argsSuffix}`; const title = customMessage || defaultTitle; - const wallTime = Date.now(); // This looks like it is unnecessary, but it isn't - we need to filter // out all the frames that belong to the test runner from caught runtime errors. @@ -270,7 +269,6 @@ class ExpectMetaInfoProxyHandler implements ProxyHandler { category: 'expect', title: trimLongString(title, 1024), params: args[0] ? { expected: args[0] } : undefined, - wallTime, infectParentStepsWithError: this._info.isSoft, }; @@ -295,7 +293,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, stepId: step.stepId }, callback); + zones.run('expectZone', { title, 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 6f2eb6eb52..1e9e1f9c46 100644 --- a/packages/playwright/src/worker/testInfo.ts +++ b/packages/playwright/src/worker/testInfo.ts @@ -34,7 +34,6 @@ export interface TestStepInternal { stepId: string; title: string; category: 'hook' | 'fixture' | 'test.step' | 'expect' | string; - wallTime: number; location?: Location; boxedStack?: StackFrame[]; steps: TestStepInternal[]; @@ -322,11 +321,11 @@ export class TestInfoImpl implements TestInfo { parentStepId: parentStep ? parentStep.stepId : undefined, title: data.title, category: data.category, - wallTime: data.wallTime, + wallTime: Date.now(), location: data.location, }; this._onStepBegin(payload); - this._tracing.appendBeforeActionForStep(stepId, parentStep?.stepId, data.apiName || data.title, data.params, data.wallTime, data.location ? [data.location] : []); + this._tracing.appendBeforeActionForStep(stepId, parentStep?.stepId, data.apiName || data.title, data.params, data.location ? [data.location] : []); return step; } @@ -355,7 +354,7 @@ export class TestInfoImpl implements TestInfo { const location = stage.runnable?.location ? ` at "${formatLocation(stage.runnable.location)}"` : ``; debugTest(`started stage "${stage.title}"${location}`); } - stage.step = stage.stepInfo ? this._addStep({ ...stage.stepInfo, title: stage.title, wallTime: Date.now(), isStage: true }) : undefined; + stage.step = stage.stepInfo ? this._addStep({ ...stage.stepInfo, title: stage.title, isStage: true }) : undefined; this._stages.push(stage); try { @@ -420,7 +419,6 @@ export class TestInfoImpl implements TestInfo { const step = this._addStep({ title: `attach "${name}"`, category: 'attach', - wallTime: Date.now(), }); this._attachmentsPush(attachment); this._onAttach({ diff --git a/packages/playwright/src/worker/testTracing.ts b/packages/playwright/src/worker/testTracing.ts index 5462564c49..87eeca3ebb 100644 --- a/packages/playwright/src/worker/testTracing.ts +++ b/packages/playwright/src/worker/testTracing.ts @@ -234,12 +234,11 @@ export class TestTracing { }); } - appendBeforeActionForStep(callId: string, parentId: string | undefined, apiName: string, params: Record | undefined, wallTime: number, stack: StackFrame[]) { + appendBeforeActionForStep(callId: string, parentId: string | undefined, apiName: string, params: Record | undefined, stack: StackFrame[]) { this._appendTraceEvent({ type: 'before', callId, parentId, - wallTime, startTime: monotonicTime(), class: 'Test', method: 'step', diff --git a/packages/protocol/src/callMetadata.ts b/packages/protocol/src/callMetadata.ts index 9d9e050438..36e8b828c0 100644 --- a/packages/protocol/src/callMetadata.ts +++ b/packages/protocol/src/callMetadata.ts @@ -32,8 +32,6 @@ export type CallMetadata = { // Service-side is making a call to itself, this metadata does not go // through the dispatcher, so is always excluded from inspector / tracing. isServerSide?: boolean; - // Client wall time. - wallTime: number; // Test runner step id. stepId?: string; location?: { file: string, line?: number, column?: number }; diff --git a/packages/protocol/src/channels.ts b/packages/protocol/src/channels.ts index 4ad2b9be95..986fb3a8dd 100644 --- a/packages/protocol/src/channels.ts +++ b/packages/protocol/src/channels.ts @@ -149,7 +149,6 @@ export type Metadata = { }, apiName?: string, internal?: boolean, - wallTime?: number, stepId?: string, }; diff --git a/packages/protocol/src/protocol.yml b/packages/protocol/src/protocol.yml index 3ad04d331e..14c6e73052 100644 --- a/packages/protocol/src/protocol.yml +++ b/packages/protocol/src/protocol.yml @@ -33,8 +33,6 @@ Metadata: column: number? apiName: string? internal: boolean? - # The number of milliseconds elapsed since midnight, January 1, 1970 UTC. - wallTime: number? # Test runner step id. stepId: string? diff --git a/packages/trace-viewer/src/ui/callTab.tsx b/packages/trace-viewer/src/ui/callTab.tsx index 463ba5056c..8e56fabb7d 100644 --- a/packages/trace-viewer/src/ui/callTab.tsx +++ b/packages/trace-viewer/src/ui/callTab.tsx @@ -23,9 +23,10 @@ import { CopyToClipboard } from './copyToClipboard'; import { asLocator } from '@isomorphic/locatorGenerators'; import type { Language } from '@isomorphic/locatorGenerators'; import { PlaceholderPanel } from './placeholderPanel'; +import type { ActionTraceEventInContext } from './modelUtil'; export const CallTab: React.FunctionComponent<{ - action: ActionTraceEvent | undefined, + action: ActionTraceEventInContext | undefined, sdkLanguage: Language | undefined, }> = ({ action, sdkLanguage }) => { if (!action) @@ -34,7 +35,11 @@ export const CallTab: React.FunctionComponent<{ // Strip down the waitForEventInfo data, we never need it. delete params.info; const paramKeys = Object.keys(params); - const wallTime = action.wallTime ? new Date(action.wallTime).toLocaleString() : null; + let wallTime = null; + if (action.context.wallTime) { + const timeMillis = action.startTime + (action.context.wallTime - action.context.startTime); + wallTime = new Date(timeMillis).toLocaleString(); + } const duration = action.endTime ? msToString(action.endTime - action.startTime) : 'Timed Out'; return
diff --git a/packages/trace-viewer/src/ui/logTab.tsx b/packages/trace-viewer/src/ui/logTab.tsx index 9e4995984f..be189ad314 100644 --- a/packages/trace-viewer/src/ui/logTab.tsx +++ b/packages/trace-viewer/src/ui/logTab.tsx @@ -31,7 +31,8 @@ export const LogTab: React.FunctionComponent<{ if (!action || !action.log.length) return []; const log = action.log; - const wallTimeOffset = action.wallTime - action.startTime; + // TODO: store context metadata for test runner context. + const wallTimeOffset = (action.context.wallTime || action.context.startTime) - action.context.startTime; const entries: { message: string, time: string }[] = []; for (let i = 0; i < log.length; ++i) { let time = ''; diff --git a/packages/trace-viewer/src/ui/modelUtil.ts b/packages/trace-viewer/src/ui/modelUtil.ts index ac4cf2f757..6385f577c8 100644 --- a/packages/trace-viewer/src/ui/modelUtil.ts +++ b/packages/trace-viewer/src/ui/modelUtil.ts @@ -225,7 +225,7 @@ function mergeActionsAndUpdateTimingSameTrace(contexts: ContextEntry[]) { for (const context of libraryContexts) { for (const action of context.actions) { - const key = matchByStepId ? action.stepId! : `${action.apiName}@${action.wallTime}`; + const key = matchByStepId ? action.stepId! : `${action.apiName}@${(action as any).wallTime}`; map.set(key, { ...action, context }); } } @@ -234,14 +234,14 @@ function mergeActionsAndUpdateTimingSameTrace(contexts: ContextEntry[]) { // Step aka test runner contexts have startTime/endTime as client-side times. // Adjust startTime/endTime on the library contexts to align them with the test // runner steps. - const delta = monotonicTimeDeltaBetweenLibraryAndRunner(testRunnerContexts, map); + const delta = monotonicTimeDeltaBetweenLibraryAndRunner(testRunnerContexts, map, matchByStepId); if (delta) adjustMonotonicTime(libraryContexts, delta); const nonPrimaryIdToPrimaryId = new Map(); for (const context of testRunnerContexts) { for (const action of context.actions) { - const key = matchByStepId ? action.callId : `${action.apiName}@${action.wallTime}`; + const key = matchByStepId ? action.callId : `${action.apiName}@${(action as any).wallTime}`; const existing = map.get(key); if (existing) { nonPrimaryIdToPrimaryId.set(action.callId, existing.callId); @@ -286,7 +286,7 @@ function adjustMonotonicTime(contexts: ContextEntry[], monotonicTimeDelta: numbe } } -function monotonicTimeDeltaBetweenLibraryAndRunner(nonPrimaryContexts: ContextEntry[], libraryActions: Map) { +function monotonicTimeDeltaBetweenLibraryAndRunner(nonPrimaryContexts: ContextEntry[], libraryActions: Map, matchByStepId: boolean) { // We cannot rely on wall time or monotonic time to be the in sync // between library and test runner contexts. So we find first action // that is present in both runner and library contexts and use it @@ -296,7 +296,7 @@ function monotonicTimeDeltaBetweenLibraryAndRunner(nonPrimaryContexts: ContextEn for (const action of context.actions) { if (!action.startTime) continue; - const key = `${action.apiName}@${action.wallTime}`; + const key = matchByStepId ? action.stepId! : `${action.apiName}@${(action as any).wallTime}`; const libraryAction = libraryActions.get(key); if (libraryAction) return action.startTime - libraryAction.startTime; diff --git a/packages/trace/src/trace.ts b/packages/trace/src/trace.ts index 5eb060f9d7..ebd3466fd8 100644 --- a/packages/trace/src/trace.ts +++ b/packages/trace/src/trace.ts @@ -62,7 +62,6 @@ export type BeforeActionTraceEvent = { class: string; method: string; params: Record; - wallTime: number; stepId?: string; beforeSnapshot?: string; stack?: StackFrame[];