From 26d3bab0e9e6223ff2cc193bf8ff6d386f147bb1 Mon Sep 17 00:00:00 2001 From: Sebastien Tardif Date: Tue, 16 Jun 2026 14:41:06 -0700 Subject: [PATCH] fix(trace): align library and runner clocks by wall time When APIRequestContext runs in a different process (e.g. remote run-server in Docker), its monotonic clock is unrelated to the test runner's. Align each library context by the wallTime/monotonicTime pair recorded at chunk start, falling back to stepId matching for older traces. Fixes https://github.com/microsoft/playwright/issues/40068 --- packages/isomorphic/trace/traceModel.ts | 40 +++++++--- tests/library/trace-model.spec.ts | 99 +++++++++++++++++++++++++ 2 files changed, 127 insertions(+), 12 deletions(-) create mode 100644 tests/library/trace-model.spec.ts diff --git a/packages/isomorphic/trace/traceModel.ts b/packages/isomorphic/trace/traceModel.ts index ea8381f910c26..96b3e5ad82745 100644 --- a/packages/isomorphic/trace/traceModel.ts +++ b/packages/isomorphic/trace/traceModel.ts @@ -260,11 +260,16 @@ function mergeActionsAndUpdateTimingSameTrace(contexts: ContextEntry[]): ActionT // Protocol call aka library contexts have startTime/endTime as server-side times. // 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); - if (delta) - adjustMonotonicTime(libraryContexts, delta); + // Adjust startTime/endTime on each library context to align it with the test + // runner steps. Each library context can come from a different process (e.g. + // a remote run-server in Docker), so its monotonic clock can be unrelated to + // the runner's. Align by wall time, falling back to a stepId match if wall + // times are not available. + for (const libraryContext of libraryContexts) { + const delta = monotonicTimeDeltaBetweenLibraryAndRunner(libraryContext, testRunnerContexts, map); + if (delta) + adjustMonotonicTime([libraryContext], delta); + } const nonPrimaryIdToPrimaryId = new Map(); for (const context of testRunnerContexts) { @@ -321,13 +326,24 @@ function adjustMonotonicTime(contexts: ContextEntry[], monotonicTimeDelta: numbe } } -function monotonicTimeDeltaBetweenLibraryAndRunner(nonPrimaryContexts: ContextEntry[], libraryActions: Map) { - // 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 - // to calculate the time delta, assuming the two events happened at the - // same instant. - for (const context of nonPrimaryContexts) { +function monotonicTimeDeltaBetweenLibraryAndRunner(libraryContext: ContextEntry, testRunnerContexts: ContextEntry[], libraryActions: Map) { + // Library and test runner contexts can run in different processes (e.g. a + // remote run-server in Docker), so their monotonic clocks are unrelated. + // Both contexts record both wallTime and monotonicTime at chunk start, so + // align by wall time: the per-context offset (monotonicTime - wallTime) is + // the constant that maps the wall clock onto the local monotonic clock, and + // the difference between the two offsets is the delta we need to apply to + // library timestamps to express them in the runner's monotonic clock. + if (libraryContext.wallTime && libraryContext.startTime) { + const runnerContext = testRunnerContexts.find(c => c.wallTime && c.startTime); + if (runnerContext) + return (runnerContext.startTime - runnerContext.wallTime) - (libraryContext.startTime - libraryContext.wallTime); + } + + // Fall back to matching the first action shared via stepId, assuming the + // two events happened at the same instant. Used when wall times are missing + // (older trace formats). + for (const context of testRunnerContexts) { for (const action of context.actions) { if (!action.startTime) continue; diff --git a/tests/library/trace-model.spec.ts b/tests/library/trace-model.spec.ts new file mode 100644 index 0000000000000..6cb7b935bc4d9 --- /dev/null +++ b/tests/library/trace-model.spec.ts @@ -0,0 +1,99 @@ +/** + * Copyright (c) Microsoft Corporation. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import { test, expect } from '@playwright/test'; +import { TraceModel } from '../../packages/isomorphic/trace/traceModel'; +import type { ActionEntry, ContextEntry } from '../../packages/isomorphic/trace/entries'; + +function createContext(overrides: Partial): ContextEntry { + return { + origin: 'testRunner', + startTime: 0, + endTime: 0, + browserName: '', + wallTime: 0, + options: { + deviceScaleFactor: 1, + isMobile: false, + viewport: { width: 1280, height: 800 }, + }, + pages: [], + resources: [], + actions: [], + events: [], + errors: [], + stdio: [], + hasSource: false, + contextId: '', + ...overrides, + }; +} + +function createAction(overrides: Partial): ActionEntry { + return { + type: 'action', + callId: 'call', + startTime: 0, + endTime: 0, + class: 'APIRequestContext', + method: 'get', + params: {}, + log: [], + ...overrides, + }; +} + +test('should align library and test runner clocks by wall time', () => { + const wallTimeRunner = 1_700_000_000_000; + const wallTimeLibrary = wallTimeRunner + 100; + + const runnerContext = createContext({ + origin: 'testRunner', + startTime: 5000, + endTime: 6000, + wallTime: wallTimeRunner, + contextId: 'runner', + actions: [ + createAction({ + callId: 'runner-action', + startTime: 5100, + endTime: 5200, + stepId: 'runner-step', + }), + ], + }); + + const libraryContext = createContext({ + origin: 'library', + startTime: 5_000_000, + endTime: 5_001_000, + wallTime: wallTimeLibrary, + contextId: 'library', + actions: [ + createAction({ + callId: 'library-action', + startTime: 5_000_100, + endTime: 5_000_200, + }), + ], + }); + + const model = new TraceModel('trace', [runnerContext, libraryContext]); + + expect(model.startTime).toBe(5000); + expect(model.endTime).toBe(6100); + expect(model.endTime - model.startTime).toBe(1100); +});