diff --git a/apps/server/src/mcp/PreviewAutomationBroker.test.ts b/apps/server/src/mcp/PreviewAutomationBroker.test.ts index f9d618f0520e3..47a9319e76567 100644 --- a/apps/server/src/mcp/PreviewAutomationBroker.test.ts +++ b/apps/server/src/mcp/PreviewAutomationBroker.test.ts @@ -351,6 +351,43 @@ it.effect("distinguishes malformed remote failures", () => ), ); +it.effect("reports the capture deadline and pending stage instead of the request timeout", () => + Effect.scoped( + Effect.gen(function* () { + const broker = yield* makeBroker; + const connected = yield* Deferred.make(); + const requests = requestsFrom( + (yield* broker.connect(makeHost())).pipe( + Stream.tap((event) => + event.type === "connected" ? Deferred.succeed(connected, undefined) : Effect.void, + ), + ), + ); + yield* Stream.runForEach(requests, (request) => + broker.respond({ + clientId: "client-1", + connectionId: request.connectionId, + requestId: request.requestId, + ok: false, + error: { + _tag: "PreviewAutomationTimeoutError", + message: "Snapshot capture did not complete.", + detail: { timeoutMs: 10_000, pendingStages: ["screenshot"] }, + }, + }), + ).pipe(Effect.forkScoped); + yield* Deferred.await(connected); + const error = yield* broker + .invoke({ scope, operation: "snapshot", input: {} }) + .pipe(Effect.flip); + expect(error).toMatchObject({ timeoutMs: 10_000, pendingStages: ["screenshot"] }); + expect(error.message).toBe( + "Preview automation snapshot timed out after 10000ms. Waiting for: screenshot.", + ); + }), + ), +); + it.effect("does not create host state from focus updates without a live stream", () => Effect.gen(function* () { const broker = yield* makeBroker; diff --git a/apps/server/src/mcp/PreviewAutomationBroker.ts b/apps/server/src/mcp/PreviewAutomationBroker.ts index 53622f3054775..2bca83bf1c392 100644 --- a/apps/server/src/mcp/PreviewAutomationBroker.ts +++ b/apps/server/src/mcp/PreviewAutomationBroker.ts @@ -18,6 +18,7 @@ import { PreviewAutomationTabNotFoundError, PreviewAutomationTargetNotEditableError, PreviewAutomationTimeoutError, + PreviewAutomationTimeoutDetail, PreviewAutomationUnsupportedClientError, PreviewTabId, type PreviewAutomationError, @@ -206,6 +207,7 @@ const readRemoteTimeoutMs = (detail: unknown): number | undefined => { }; const MAX_REASON_CHARS = 500; +const decodeTimeoutDetail = Schema.decodeUnknownOption(PreviewAutomationTimeoutDetail); const classifyResponseError = ( context: PreviewAutomationRequestErrorContext, @@ -255,12 +257,14 @@ const classifyResponseError = ( }); case "PreviewAutomationTimeoutError": { const remoteTimeoutMs = readRemoteTimeoutMs(error.detail); + const detail = decodeTimeoutDetail(error.detail); return new PreviewAutomationTimeoutError({ ...context, ...remoteDiagnostics, ...(remoteTimeoutMs === undefined ? {} : { timeoutMs: Math.min(context.timeoutMs, remoteTimeoutMs) }), + ...(Option.isSome(detail) ? { pendingStages: detail.value.pendingStages } : {}), }); } case "PreviewAutomationControlInterruptedError": { diff --git a/apps/server/src/preview/ServerBrowserPage.test.ts b/apps/server/src/preview/ServerBrowserPage.test.ts index 31f180bcc923c..37b9f6f45729d 100644 --- a/apps/server/src/preview/ServerBrowserPage.test.ts +++ b/apps/server/src/preview/ServerBrowserPage.test.ts @@ -5,10 +5,163 @@ import { type CDPSession, type Page, } from "playwright-core"; -import { afterAll, afterEach, beforeAll, beforeEach, describe, expect, it } from "vite-plus/test"; +import { + afterAll, + afterEach, + beforeAll, + beforeEach, + describe, + expect, + it, + vi, +} from "vite-plus/test"; import * as ServerBrowserPage from "./ServerBrowserPage.ts"; +describe("snapshot deadline diagnostics", () => { + const never = () => new Promise(() => {}); + const stalledSnapshot = async (options: { + readonly stalled?: "metrics" | "screenshot"; + readonly page?: Partial>; + readonly advanceMs: number; + }) => { + vi.useFakeTimers(); + try { + const frame = {}; + const page = { + viewportSize: () => ({ width: 1280, height: 800 }), + mainFrame: () => frame, + frames: () => [frame], + on: () => {}, + evaluate: async () => ({ + url: "about:blank", + title: "", + loading: false, + visibleText: "", + interactiveElements: [], + }), + ariaSnapshot: async () => "", + ...options.page, + } as unknown as Page; + const cdp = { + send: async (method: string) => { + if (options.stalled === "metrics" || method === "Page.captureScreenshot") return never(); + if (method === "Page.getFrameTree") return { frameTree: { frame: { id: "main" } } }; + if (method === "Page.createIsolatedWorld") return { executionContextId: 1 }; + if (method === "Runtime.evaluate") return { result: { value: [] } }; + throw new Error(`Unexpected command: ${method}`); + }, + } as unknown as CDPSession; + const captured = ServerBrowserPage.snapshot({ + page, + cdp, + renderScale: options.stalled === "metrics" ? "display" : 1, + consoleEntries: [], + networkEntries: [], + actionTimeline: [], + }).catch((error: unknown) => error); + await vi.advanceTimersByTimeAsync(options.advanceMs); + return await captured; + } finally { + vi.useRealTimers(); + } + }; + + it.each(["metrics", "screenshot"] as const)( + "identifies a stalled %s operation", + async (stage) => { + expect(await stalledSnapshot({ stalled: stage, advanceMs: 10_000 })).toMatchObject({ + tag: "PreviewAutomationTimeoutError", + detail: { timeoutMs: 10_000, pendingStages: [stage] }, + }); + }, + ); + + it("keeps an accessibility tree that hit its own timeout", async () => { + const timedOut = Object.assign(new Error("Timeout exceeded"), { name: "TimeoutError" }); + const captured = await stalledSnapshot({ + page: { ariaSnapshot: () => Promise.reject(timedOut) }, + advanceMs: 0, + }); + expect(captured).toMatchObject({ + tag: "PreviewAutomationTimeoutError", + detail: { timeoutMs: 10_000 }, + }); + expect((captured as ServerBrowserPage.ServerBrowserOperationError).detail).toMatchObject({ + pendingStages: expect.arrayContaining(["accessibility tree"]), + }); + }); + + it("omits a timed-out stage after it succeeds on retry", async () => { + let attempts = 0; + const timedOut = Object.assign(new Error("Timeout exceeded"), { name: "TimeoutError" }); + expect( + await stalledSnapshot({ + page: { + ariaSnapshot: async () => { + if (attempts++ === 0) throw timedOut; + return ""; + }, + }, + advanceMs: 10_000, + }), + ).toMatchObject({ detail: { timeoutMs: 10_000, pendingStages: ["screenshot"] } }); + }); + + it.each(["elementHandle", "contentFrame"] as const)( + "identifies stalled iframe %s lookup", + async (stage) => { + const main = {}; + const child = { evaluate: never, parentFrame: () => main }; + const captured = await stalledSnapshot({ + page: { + mainFrame: () => main, + frames: () => [main, child], + context: () => ({ + newCDPSession: () => + Promise.reject(new Error("Only this preview tab's page can be attached")), + }), + ariaSnapshot: async () => "- iframe [ref=f1]:\n - text: inside", + locator: () => ({ + elementHandle: + stage === "elementHandle" ? never : async () => ({ contentFrame: never }), + }), + }, + advanceMs: 10_000, + }); + expect(captured).toMatchObject({ + detail: { timeoutMs: 10_000, pendingStages: expect.arrayContaining(["frames"]) }, + }); + }, + ); + + it("reports a frame that didn't answer as the frame's own timeout", async () => { + const main = {}; + // A desktop tab refuses frame sessions, so the frame is read in its own world. + const child = { evaluate: never, parentFrame: () => main }; + const captured = await stalledSnapshot({ + page: { + mainFrame: () => main, + frames: () => [main, child], + context: () => ({ + newCDPSession: () => + Promise.reject(new Error("Only this preview tab's page can be attached")), + }), + ariaSnapshot: async () => "- iframe [ref=f1]:\n - text: inside", + locator: () => ({ + elementHandle: async () => ({ contentFrame: async () => child, dispose: async () => {} }), + }), + }, + // Both attempts wait out the frame; neither reaches the capture deadline. + advanceMs: 2_000, + }); + expect(captured).toMatchObject({ + tag: "PreviewAutomationTimeoutError", + detail: { timeoutMs: 1_000, pendingStages: ["frames"] }, + }); + }); +}); + describe("server browser element refs", () => { let browser: Browser; let context: BrowserContext; diff --git a/apps/server/src/preview/ServerBrowserPage.ts b/apps/server/src/preview/ServerBrowserPage.ts index 9525ac7c5b579..54a9d33fcfd19 100644 --- a/apps/server/src/preview/ServerBrowserPage.ts +++ b/apps/server/src/preview/ServerBrowserPage.ts @@ -14,6 +14,7 @@ import { type PreviewAutomationSelectInput, type PreviewAutomationSelectResult, type PreviewAutomationSnapshot, + type PreviewAutomationSnapshotStage, type PreviewAutomationTypeInput, type PreviewAutomationUploadInput, type PreviewAutomationWaitForInput, @@ -232,12 +233,36 @@ const pageChanged = () => "The page changed while capturing its snapshot. Take another snapshot.", ); -const tooBusy = () => +type SnapshotStage = typeof PreviewAutomationSnapshotStage.Type; + +/** + * Running stages are counted, since a retry can overlap the previous attempt's unanswered + * screenshot. A stage whose own timeout fired has stopped running but is still the cause. + */ +interface SnapshotStages { + readonly running: Map; + readonly timedOut: Set; +} + +const snapshotTimedOut = (stages?: SnapshotStages) => + new ServerBrowserOperationError( + "PreviewAutomationTimeoutError", + `Snapshot capture timed out after ${SNAPSHOT_TIMEOUT_MS}ms. Try the snapshot again.`, + { + timeoutMs: SNAPSHOT_TIMEOUT_MS, + pendingStages: stages ? [...new Set([...stages.timedOut, ...stages.running.keys()])] : [], + }, + ); + +const frameUnanswered = () => new ServerBrowserOperationError( "PreviewAutomationTimeoutError", - "The page was too busy to capture a snapshot in time. Wait for it to settle and take another snapshot.", + `A frame on the page didn't answer within ${FRAME_ANSWER_MS}ms, so its content couldn't be checked for hidden values. Try the snapshot again.`, + { timeoutMs: FRAME_ANSWER_MS, pendingStages: ["frames"] }, ); +const isTimeout = (cause: unknown) => cause instanceof Error && cause.name === "TimeoutError"; + const VALUE_TOO_LONG = "A password field holds a value too long to hide, so no snapshot was taken."; /** Reuse one CDP session per out-of-process frame across snapshots. */ @@ -524,36 +549,61 @@ const renderingOf = async (input: SnapshotInput) => { const capture = async ( input: SnapshotInput, deadline: number, + stages: SnapshotStages, ): Promise => { - const { renderScale, viewport } = await renderingOf(input); + const { running } = stages; + const track = async (stage: SnapshotStage, operation: () => Promise) => { + running.set(stage, (running.get(stage) ?? 0) + 1); + try { + const result = await operation(); + stages.timedOut.delete(stage); + return result; + } catch (cause) { + if (isTimeout(cause)) stages.timedOut.add(stage); + throw cause; + } finally { + const count = (running.get(stage) ?? 1) - 1; + if (count === 0) running.delete(stage); + else running.set(stage, count); + } + }; + const { renderScale, viewport } = await track("metrics", () => renderingOf(input)); // A late metrics reply must not begin a capture after viewers have resumed. - if (Date.now() >= deadline) throw tooBusy(); + if (Date.now() >= deadline) throw snapshotTimedOut(); const scale = Math.min(1, MAX_SCREENSHOT_WIDTH / (viewport.width * renderScale)); const state = refsFor(input.page); invalidateRefs(input.page); const generation = state.generation; - const { readers, read } = await openReaders(input.page, input.cdp); - const before = await read(); + const { readers, read } = await track("frames", () => openReaders(input.page, input.cdp)); + const before = await track("frames", () => read()); // Bracket the tree with value reads to detect changes; await tree completion before retrying failed captures. const pageAndScreenshot = Promise.all([ - input.page.evaluate(SNAPSHOT_SCRIPT) as Promise< - Pick< - PreviewAutomationSnapshot, - "url" | "title" | "loading" | "visibleText" | "interactiveElements" - > - >, - captureViewport(input.cdp, { format: "png" }).then((png) => - scale < 1 ? shrinkPng(input.cdp, png, scale) : png, + track( + "page state", + () => + input.page.evaluate(SNAPSHOT_SCRIPT) as Promise< + Pick< + PreviewAutomationSnapshot, + "url" | "title" | "loading" | "visibleText" | "interactiveElements" + > + >, + ), + track("screenshot", () => + captureViewport(input.cdp, { format: "png" }).then((png) => + scale < 1 ? shrinkPng(input.cdp, png, scale) : png, + ), ), ]); void pageAndScreenshot.catch(constVoid); // Leaves time for the second read; a frame that never loads holds the tree until then. - const tree = await input.page.ariaSnapshot({ - mode: "ai", - boxes: true, - timeout: Math.max(1, deadline - Date.now() - 2_000), - }); - const after = await read(before); + const tree = await track("accessibility tree", () => + input.page.ariaSnapshot({ + mode: "ai", + boxes: true, + timeout: Math.max(1, deadline - Date.now() - 2_000), + }), + ); + const after = await track("frames", () => read(before)); // A value that changed meanwhile may be in the tree under neither reading. if (after.some((values, i) => values && JSON.stringify(values) !== JSON.stringify(before[i]))) throw pageChanged(); @@ -562,11 +612,13 @@ const capture = async ( const unread = readers.flatMap((reader, i) => (after[i] ? [] : reader.frames)); const filled = /^\s*- iframe (?:\[active\] )?\[ref=(\S+?)\].*:$/gm; for (const [, ref] of unread.length ? tree.matchAll(filled) : []) { - const iframe = await input.page.locator(`aria-ref=${ref}`).elementHandle({ timeout: 2_000 }); + const iframe = await track("frames", () => + input.page.locator(`aria-ref=${ref}`).elementHandle({ timeout: 2_000 }), + ); if (!iframe) throw pageChanged(); - const frame = await iframe.contentFrame(); + const frame = await track("frames", () => iframe.contentFrame()); void iframe.dispose().catch(constVoid); - if (frame && unread.includes(frame)) throw tooBusy(); + if (frame && unread.includes(frame)) throw frameUnanswered(); } const [page, data] = await pageAndScreenshot; if (state.generation !== generation) throw pageChanged(); @@ -602,24 +654,25 @@ const snapshotTurns = new WeakMap(); export const snapshot = async (input: SnapshotInput): Promise => { const deadline = Date.now() + SNAPSHOT_TIMEOUT_MS; + const stages: SnapshotStages = { running: new Map(), timedOut: new Set() }; let timer: ReturnType | undefined; const expired = new Promise((_, reject) => { - timer = setTimeout(() => reject(tooBusy()), SNAPSHOT_TIMEOUT_MS); + timer = setTimeout(() => reject(snapshotTimedOut(stages)), SNAPSHOT_TIMEOUT_MS); }); const turn = (snapshotTurns.get(input.page) ?? 0) + 1; snapshotTurns.set(input.page, turn); // Retry only before the deadline and the next snapshot, whose refs a later retry would revoke. - const captured = capture(input, deadline).catch((cause: unknown) => + const captured = capture(input, deadline, stages).catch((cause: unknown) => Date.now() < deadline && snapshotTurns.get(input.page) === turn && !(cause instanceof Error && cause.message === VALUE_TOO_LONG) - ? capture(input, deadline) + ? capture(input, deadline, stages) : Promise.reject(cause), ); try { return await Promise.race([captured, expired]); } catch (cause) { - throw cause instanceof Error && cause.name === "TimeoutError" ? tooBusy() : cause; + throw isTimeout(cause) ? snapshotTimedOut(stages) : cause; } finally { clearTimeout(timer); } diff --git a/packages/contracts/src/previewAutomation.ts b/packages/contracts/src/previewAutomation.ts index abaa03512d1ce..72f342e36faef 100644 --- a/packages/contracts/src/previewAutomation.ts +++ b/packages/contracts/src/previewAutomation.ts @@ -715,16 +715,32 @@ export class PreviewAutomationTabNotFoundError extends Schema.TaggedError()( "PreviewAutomationTimeoutError", { ...PreviewAutomationRequestErrorFields, ...PreviewAutomationOptionalRemoteDiagnosticFields, + pendingStages: Schema.optional(PreviewAutomationTimeoutDetail.fields.pendingStages), }, ) { override get message(): string { const summary = `Preview automation ${this.operation} timed out after ${this.timeoutMs}ms.`; - return summary; + return this.pendingStages?.length + ? `${summary} Waiting for: ${this.pendingStages.join(", ")}.` + : summary; } }