diff --git a/packages/engine/src/index.ts b/packages/engine/src/index.ts index 0339841e8c..e5e575c65c 100644 --- a/packages/engine/src/index.ts +++ b/packages/engine/src/index.ts @@ -133,8 +133,11 @@ export { CaptureFailure, classifyCaptureFailure, isFatalCaptureFailure, + isLoopbackConnectionLoss, + type CaptureEndpointDiagnostic, type CaptureFailureKind, type CaptureWorkerDiagnostic, + type LoopbackConnectionLoss, } from "./services/captureFailure.js"; // ── Screenshot (BeginFrame) ───────────────────────────────────────────────────── diff --git a/packages/engine/src/services/audioMixer.test.ts b/packages/engine/src/services/audioMixer.test.ts index e7b1fb5ac7..82e5ee0875 100644 --- a/packages/engine/src/services/audioMixer.test.ts +++ b/packages/engine/src/services/audioMixer.test.ts @@ -1,6 +1,6 @@ // fallow-ignore-file code-duplication import { afterEach, describe, expect, it, vi } from "vitest"; -import { mkdirSync, mkdtempSync, rmSync, writeFileSync } from "node:fs"; +import { existsSync, mkdirSync, mkdtempSync, rmSync, writeFileSync } from "node:fs"; import { join } from "node:path"; import { tmpdir } from "node:os"; @@ -861,6 +861,355 @@ describe("processCompositionAudio", () => { ]); }); + it("preserves an external interruption from a group sub-mix", async () => { + const baseDir = mkdtempSync(join(tmpdir(), "hf-audio-base-")); + const workDir = mkdtempSync(join(tmpdir(), "hf-audio-work-")); + tempDirs.push(baseDir, workDir); + writeFileSync(join(baseDir, "voice-a.wav"), "stub"); + writeFileSync(join(baseDir, "voice-b.wav"), "stub"); + + runFfmpegMock.mockImplementation(async (args: string[]) => { + if (String(args.at(-1)).includes("group-voiceover")) { + return { + success: false, + durationMs: 1, + stderr: "normalize: Option not found\nffmpeg exited after signal 15", + exitCode: 0, + terminationReason: "signal" as const, + failureReason: "external_interruption" as const, + }; + } + return { success: true, durationMs: 1, stderr: "", exitCode: 0 }; + }); + + const result = await processCompositionAudio( + [ + { + id: "voice-a", + src: "voice-a.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 0, + volume: 1, + volumeKeyframes: [ + { time: 0, volume: 1 }, + { time: 2, volume: 0.5 }, + ], + groupId: "voiceover", + type: "audio", + }, + { + id: "voice-b", + src: "voice-b.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 1, + volume: 1, + groupId: "voiceover", + type: "audio", + }, + ], + baseDir, + workDir, + join(baseDir, "out.m4a"), + 2, + ); + + expect(result.success).toBe(false); + expect(result.failures).toEqual([ + expect.objectContaining({ + stage: "mix", + reason: "external_interruption", + owner: "system", + retryable: true, + elementId: "voiceover", + }), + ]); + expect( + runFfmpegMock.mock.calls.filter(([args]) => String(args.at(-1)).includes("group-voiceover")), + ).toHaveLength(1); + expect(existsSync(workDir)).toBe(false); + }); + + it("reports a cancelled group sub-mix with the canonical cancellation classification", async () => { + const baseDir = mkdtempSync(join(tmpdir(), "hf-audio-base-")); + const workDir = mkdtempSync(join(tmpdir(), "hf-audio-work-")); + tempDirs.push(baseDir, workDir); + writeFileSync(join(baseDir, "voice-a.wav"), "stub"); + writeFileSync(join(baseDir, "voice-b.wav"), "stub"); + const controller = new AbortController(); + + runFfmpegMock.mockImplementation(async (args: string[]) => { + if (String(args.at(-1)).includes("group-voiceover")) { + // The user cancels while the sub-mix is running. + controller.abort(); + return { + success: false, + durationMs: 1, + stderr: "", + exitCode: null, + terminationReason: "abort" as const, + }; + } + return { success: true, durationMs: 1, stderr: "", exitCode: 0 }; + }); + + const result = await processCompositionAudio( + [ + { + id: "voice-a", + src: "voice-a.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 0, + volume: 1, + groupId: "voiceover", + type: "audio", + }, + { + id: "voice-b", + src: "voice-b.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 1, + volume: 1, + groupId: "voiceover", + type: "audio", + }, + ], + baseDir, + workDir, + join(baseDir, "out.m4a"), + 2, + controller.signal, + ); + + expect(result.success).toBe(false); + expect(result.failures).toContainEqual( + expect.objectContaining({ + stage: "cancelled", + reason: "cancelled", + owner: "user", + retryable: false, + elementId: "voiceover", + }), + ); + expect(result.failures.map((failure) => failure.reason)).not.toContain("ffmpeg_failed"); + expect(result.failures.map((failure) => failure.owner)).not.toContain("system"); + }); + + it("surfaces an external interruption that lands on the group automation rerun", async () => { + const baseDir = mkdtempSync(join(tmpdir(), "hf-audio-base-")); + const workDir = mkdtempSync(join(tmpdir(), "hf-audio-work-")); + tempDirs.push(baseDir, workDir); + writeFileSync(join(baseDir, "voice-a.wav"), "stub"); + writeFileSync(join(baseDir, "voice-b.wav"), "stub"); + + let groupMixCalls = 0; + runFfmpegMock.mockImplementation(async (args: string[]) => { + if (String(args.at(-1)).includes("group-voiceover")) { + groupMixCalls += 1; + // First run: the automation expression is rejected (a local fallback + // is allowed). Second run, without automation: SIGTERM arrives. + return groupMixCalls === 1 + ? { + success: false, + durationMs: 1, + stderr: "Error initializing filters", + exitCode: 234, + terminationReason: "exit" as const, + } + : { + success: false, + durationMs: 1, + stderr: "ffmpeg exited after signal 15", + exitCode: null, + terminationReason: "signal" as const, + failureReason: "external_interruption" as const, + }; + } + return { success: true, durationMs: 1, stderr: "", exitCode: 0 }; + }); + + const result = await processCompositionAudio( + [ + { + id: "voice-a", + src: "voice-a.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 0, + volume: 1, + volumeKeyframes: [ + { time: 0, volume: 1 }, + { time: 2, volume: 0.5 }, + ], + groupId: "voiceover", + type: "audio", + }, + { + id: "voice-b", + src: "voice-b.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 1, + volume: 1, + groupId: "voiceover", + type: "audio", + }, + ], + baseDir, + workDir, + join(baseDir, "out.m4a"), + 2, + ); + + expect(groupMixCalls).toBe(2); + expect(result.success).toBe(false); + // The interruption that ended the rerun is what the caller retries on — + // not the automation error the rerun was trying to work around. + expect(result.failures).toEqual([ + expect.objectContaining({ + stage: "mix", + reason: "external_interruption", + owner: "system", + retryable: true, + elementId: "voiceover", + }), + ]); + }); + + it("does not rerun an ungrouped automated mix after a managed deadline", async () => { + const baseDir = mkdtempSync(join(tmpdir(), "hf-audio-base-")); + const workDir = mkdtempSync(join(tmpdir(), "hf-audio-work-")); + tempDirs.push(baseDir, workDir); + writeFileSync(join(baseDir, "bgm.wav"), "stub"); + + // prepare = call 0, automated mix = call 1 (hits its deadline). A + // static-volume rerun would spend a second full ffmpegProcessTimeout on a + // failure the caller is going to retry anyway. + runFfmpegMock + .mockImplementationOnce(async () => ({ + success: true, + durationMs: 1, + stderr: "", + exitCode: 0, + })) + .mockImplementationOnce(async () => ({ + success: false, + durationMs: 300_000, + stderr: "managed deadline reached", + exitCode: null, + terminationReason: "deadline" as const, + })); + + const result = await processCompositionAudio( + [ + { + id: "bgm", + src: "bgm.wav", + start: 0, + end: 5, + mediaStart: 0, + layer: 0, + volume: 0.8, + volumeKeyframes: [ + { time: 0, volume: 0.8 }, + { time: 5, volume: 0 }, + ], + type: "audio", + }, + ], + baseDir, + workDir, + join(baseDir, "out.m4a"), + 5, + ); + + expect(result.success).toBe(false); + expect(runFfmpegMock).toHaveBeenCalledTimes(2); + expect(result.failures).toEqual([ + expect.objectContaining({ stage: "mix", reason: "ffmpeg_timeout", retryable: true }), + ]); + }); + + it("preserves a managed deadline from a group sub-mix without degradation retries", async () => { + const baseDir = mkdtempSync(join(tmpdir(), "hf-audio-base-")); + const workDir = mkdtempSync(join(tmpdir(), "hf-audio-work-")); + tempDirs.push(baseDir, workDir); + writeFileSync(join(baseDir, "sfx-a.wav"), "stub"); + writeFileSync(join(baseDir, "sfx-b.wav"), "stub"); + + runFfmpegMock.mockImplementation(async (args: string[]) => { + if (String(args.at(-1)).includes("group-sfx")) { + return { + success: false, + durationMs: 300_000, + stderr: "managed deadline reached", + exitCode: null, + terminationReason: "deadline" as const, + }; + } + return { success: true, durationMs: 1, stderr: "", exitCode: 0 }; + }); + + const result = await processCompositionAudio( + [ + { + id: "sfx-a", + src: "sfx-a.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 0, + volume: 1, + volumeKeyframes: [ + { time: 0, volume: 1 }, + { time: 2, volume: 0.5 }, + ], + groupId: "sfx", + type: "audio", + }, + { + id: "sfx-b", + src: "sfx-b.wav", + start: 0, + end: 2, + mediaStart: 0, + layer: 1, + volume: 1, + groupId: "sfx", + type: "audio", + }, + ], + baseDir, + workDir, + join(baseDir, "out.m4a"), + 2, + ); + + expect(result.success).toBe(false); + expect(result.failures).toEqual([ + expect.objectContaining({ + stage: "mix", + reason: "ffmpeg_timeout", + owner: "system", + retryable: true, + elementId: "sfx", + }), + ]); + expect( + runFfmpegMock.mock.calls.filter(([args]) => String(args.at(-1)).includes("group-sfx")), + ).toHaveLength(1); + expect(existsSync(workDir)).toBe(false); + }); + it("bounds per-cause details and the aggregate error across many authored IDs", async () => { const baseDir = mkdtempSync(join(tmpdir(), "hf-audio-base-")); const workDir = mkdtempSync(join(tmpdir(), "hf-audio-work-")); diff --git a/packages/engine/src/services/audioMixer.ts b/packages/engine/src/services/audioMixer.ts index 2c2b8c6884..c556c851a5 100644 --- a/packages/engine/src/services/audioMixer.ts +++ b/packages/engine/src/services/audioMixer.ts @@ -373,6 +373,32 @@ function downloadFailure(error: unknown, elementId: string): AudioProcessingFail }; } +/** + * Whether a failed mix may try a local fallback (drop volume automation, drop + * `normalize=0`). A retryable failure — external interruption, managed + * deadline/inactivity, missing FFmpeg — is the caller's to retry; rerunning it + * here would burn a second full timeout and report the fallback's failure in + * place of the first one. Cancellation is never retried locally. + */ +function canRetryMixLocally(result: RunFfmpegResult, signal: AbortSignal | undefined): boolean { + return !result.success && !signal?.aborted && !ffmpegFailure("mix", result).retryable; +} + +/** + * Which of a failed mix and its automation-dropping rerun the caller reports. + * A successful rerun degrades the automation away; a rerun that was itself + * interrupted or hit its deadline is the failure the caller must see (and + * retry), not the automation error it was trying to work around. + */ +function resolveAutomationRerun( + original: RunFfmpegResult, + rerun: RunFfmpegResult, +): { result: RunFfmpegResult; degradedAutomation: boolean } { + if (rerun.success) return { result: rerun, degradedAutomation: true }; + const keepRerun = ffmpegFailure("mix", rerun).retryable; + return { result: keepRerun ? rerun : original, degradedAutomation: false }; +} + function ffmpegFailure( stage: Extract, result: RunFfmpegResult, @@ -865,17 +891,10 @@ async function mixAudioTracks( // dropped from the output entirely — a missing fade beats missing audio. let degradedAutomation = false; const hasAutomation = tracks.some((track) => (track.volumeKeyframes?.length ?? 0) > 0); - if ( - !result.success && - result.failureReason !== "external_interruption" && - !signal?.aborted && - hasAutomation - ) { - const retry = await runMix(true); - if (retry.success) { - result = retry; - degradedAutomation = true; - } + if (canRetryMixLocally(result, signal) && hasAutomation) { + const rerun = resolveAutomationRerun(result, await runMix(true)); + result = rerun.result; + degradedAutomation = rerun.degradedAutomation; } if (signal?.aborted) { @@ -955,7 +974,10 @@ async function mixGroupMembers( totalDuration: number, signal?: AbortSignal, config?: Partial>, -): Promise<{ success: boolean; error?: string; degradedAutomation?: boolean }> { +): Promise< + | { success: true; degradedAutomation: boolean } + | { success: false; error: string; failure: AudioProcessingFailure } +> { const ffmpegProcessTimeout = config?.ffmpegProcessTimeout ?? DEFAULT_CONFIG.ffmpegProcessTimeout; const outputDir = dirname(outputPath); if (!existsSync(outputDir)) mkdirSync(outputDir, { recursive: true }); @@ -1034,7 +1056,7 @@ async function mixGroupMembers( let useNormalize = true; let result = await runOnce(useNormalize); - if (!result.success && groupNormalizeOptionUnsupported(result.stderr)) { + if (canRetryMixLocally(result, signal) && groupNormalizeOptionUnsupported(result.stderr)) { useNormalize = false; result = await runOnce(useNormalize); } @@ -1046,17 +1068,34 @@ async function mixGroupMembers( // grouped, it took the entire composition's audio down with it. let degradedAutomation = false; const hasAutomation = memberTracks.some((track) => (track.volumeKeyframes?.length ?? 0) > 0); - if (!result.success && !signal?.aborted && hasAutomation) { - const retry = await runOnce(useNormalize, true); - if (retry.success) { - result = retry; - degradedAutomation = true; - } + if (canRetryMixLocally(result, signal) && hasAutomation) { + const rerun = resolveAutomationRerun(result, await runOnce(useNormalize, true)); + result = rerun.result; + degradedAutomation = rerun.degradedAutomation; } - if (signal?.aborted) return { success: false, error: "Group sub-mix cancelled" }; + if (signal?.aborted) { + // Same canonical shape as every other cancelled audio stage: a user + // cancel is not a system FFmpeg fault. + const cancelledDetail = "Group sub-mix cancelled"; + return { + success: false, + error: cancelledDetail, + failure: { + stage: "cancelled", + reason: "cancelled", + owner: "user", + retryable: false, + detail: cancelledDetail, + }, + }; + } if (!result.success) - return { success: false, error: formatFfmpegError(result.exitCode, result.stderr) }; + return { + success: false, + error: formatFfmpegError(result.exitCode, result.stderr), + failure: ffmpegFailure("mix", result), + }; return { success: true, degradedAutomation }; } @@ -1436,14 +1475,9 @@ export async function processCompositionAudio( ); if (!subMix.success) { failures.push({ - stage: "mix", - reason: "ffmpeg_failed", - owner: "system", - retryable: false, + ...subMix.failure, elementId: groupId, - detail: boundedDetail( - `Group sub-mix failed for group ${groupId}: ${subMix.error ?? "unknown"}`, - ), + detail: boundedDetail(`Group sub-mix failed for group ${groupId}: ${subMix.error}`), }); continue; } diff --git a/packages/engine/src/services/captureFailure.test.ts b/packages/engine/src/services/captureFailure.test.ts index b326374dcd..1aac22e8d2 100644 --- a/packages/engine/src/services/captureFailure.test.ts +++ b/packages/engine/src/services/captureFailure.test.ts @@ -1,9 +1,24 @@ import { describe, expect, it } from "vitest"; -import { CaptureFailure, classifyCaptureFailure, isFatalCaptureFailure } from "./captureFailure.js"; +import { + CaptureFailure, + classifyCaptureFailure, + isFatalCaptureFailure, + isLoopbackConnectionLoss, +} from "./captureFailure.js"; describe("classifyCaptureFailure", () => { it.each([ ["Target closed", "transient_browser"], + ["connect ETIMEDOUT 127.0.0.1:49152", "transient_browser"], + ["connect ETIMEDOUT ::1:49152", "transient_browser"], + ["connect ETIMEDOUT [::1]:49152", "transient_browser"], + ["connect ECONNREFUSED ::1:49152", "transient_browser"], + ["net::ERR_TIMED_OUT at http://localhost:49152/index.html", "transient_browser"], + ["net::ERR_CONNECTION_TIMED_OUT at http://localhost:49152/index.html", "transient_browser"], + ["net::ERR_CONNECTION_REFUSED at http://localhost:49152/index.html", "transient_browser"], + ["net::ERR_CONNECTION_REFUSED at http://[::1]:49152/index.html", "transient_browser"], + ["net::ERR_CONNECTION_CLOSED at http://localhost:49152/index.html", "transient_browser"], + ["net::ERR_EMPTY_RESPONSE at http://127.0.0.1:49152/index.html", "transient_browser"], ["Runtime.callFunctionOn timed out after 30000ms", "protocol_timeout"], ["Runtime.evaluate timed out", "protocol_timeout"], ["Network.enable timed out. Increase the protocolTimeout setting.", "protocol_timeout"], @@ -24,6 +39,7 @@ describe("classifyCaptureFailure", () => { ], // The timed-out variant of the same call stays protocol_timeout (checked first). ["Protocol error (Page.captureScreenshot): waiting for debugger timed out", "protocol_timeout"], + ["connect ETIMEDOUT 203.0.113.10:443", "authoring"], ] as const)("classifies %s as %s", (message, kind) => { expect(classifyCaptureFailure(new Error(message)).kind).toBe(kind); }); @@ -69,6 +85,97 @@ describe("classifyCaptureFailure", () => { expect(Object.isFrozen(failure.workerDiagnostics[0]?.lines)).toBe(true); }); + it.each([ + ["connect ETIMEDOUT 127.0.0.1:49152", { host: "127.0.0.1", port: 49152 }], + ["connect ETIMEDOUT ::1:49152", { host: "::1", port: 49152 }], + ["connect ETIMEDOUT [::1]:49152", { host: "::1", port: 49152 }], + ["connect ECONNREFUSED 127.0.0.1:49152", { host: "127.0.0.1", port: 49152 }], + ["net::ERR_TIMED_OUT at http://localhost:4173/index.html", { host: "localhost", port: 4173 }], + [ + "net::ERR_CONNECTION_TIMED_OUT at http://localhost:4173/index.html", + { host: "localhost", port: 4173 }, + ], + [ + "net::ERR_CONNECTION_REFUSED at http://127.0.0.1:4173/index.html", + { host: "127.0.0.1", port: 4173 }, + ], + ["net::ERR_CONNECTION_REFUSED at http://[::1]:4173/", { host: "::1", port: 4173 }], + // Chrome's spelling when the file server destroys live sockets mid-request. + [ + "net::ERR_CONNECTION_CLOSED at http://localhost:4173/index.html", + { host: "localhost", port: 4173 }, + ], + [ + "net::ERR_EMPTY_RESPONSE at http://localhost:4173/index.html", + { host: "localhost", port: 4173 }, + ], + ] as const)("retains loopback endpoint provenance for %s", (message, endpoint) => { + const failure = classifyCaptureFailure(new Error(message)); + expect(failure).toMatchObject({ kind: "transient_browser", endpoint }); + expect(isLoopbackConnectionLoss(failure)).toBe(true); + }); + + it("reads the loopback endpoint through a Node fetch wrapper's cause chain", () => { + const wrapped = new TypeError("fetch failed", { + cause: Object.assign(new Error("connect ETIMEDOUT ::1:49152"), { + code: "ETIMEDOUT", + address: "::1", + port: 49152, + }), + }); + + const failure = classifyCaptureFailure(wrapped); + + expect(failure.kind).toBe("transient_browser"); + expect(failure.endpoint).toEqual({ host: "::1", port: 49152 }); + expect(failure.message).toBe("fetch failed"); + expect(failure.cause).toBe(wrapped); + }); + + it("reads the loopback endpoint out of a dual-stack AggregateError with an empty message", () => { + const aggregate = new AggregateError( + [ + new Error("connect ECONNREFUSED ::1:49152"), + new Error("connect ECONNREFUSED 127.0.0.1:49152"), + ], + "", + ); + const wrapped = new TypeError("fetch failed", { cause: aggregate }); + + expect(classifyCaptureFailure(wrapped)).toMatchObject({ + kind: "transient_browser", + endpoint: { host: "::1", port: 49152 }, + }); + }); + + it("stops walking a cause chain deeper than five levels", () => { + let error: Error = new Error("connect ETIMEDOUT ::1:49152"); + for (let depth = 0; depth < 5; depth++) error = new Error(`wrapper ${depth}`, { cause: error }); + + expect(classifyCaptureFailure(error).endpoint).toBeUndefined(); + }); + + it("keeps remote connection losses and bare target losses outside loopback recovery", () => { + for (const message of [ + "connect ETIMEDOUT 203.0.113.10:443", + "net::ERR_CONNECTION_REFUSED at https://example.com/", + "Target closed", + "Failed to launch the browser process! spawn ENOENT", + ]) { + const failure = classifyCaptureFailure(new Error(message)); + expect(failure.endpoint).toBeUndefined(); + expect(isLoopbackConnectionLoss(failure)).toBe(false); + } + }); + + it("does not let a loopback host inside a protocol timeout override the timeout kind", () => { + expect( + classifyCaptureFailure( + new Error("Page.captureScreenshot timed out\nconnect ETIMEDOUT 127.0.0.1:49152"), + ).kind, + ).toBe("protocol_timeout"); + }); + it("classifies repeated operation text in linear time", () => { const repeatedCopy = "copy".repeat(25_000); diff --git a/packages/engine/src/services/captureFailure.ts b/packages/engine/src/services/captureFailure.ts index c47153b215..cbf1374dcb 100644 --- a/packages/engine/src/services/captureFailure.ts +++ b/packages/engine/src/services/captureFailure.ts @@ -15,16 +15,23 @@ export interface CaptureWorkerDiagnostic { lines: readonly string[]; } +export interface CaptureEndpointDiagnostic { + host: string; + port: number; +} + export class CaptureFailure extends Error { readonly kind: CaptureFailureKind; readonly cause: unknown; readonly workerDiagnostics: readonly CaptureWorkerDiagnostic[]; + readonly endpoint?: Readonly; constructor(input: { kind: CaptureFailureKind; message: string; cause?: unknown; workerDiagnostics?: readonly CaptureWorkerDiagnostic[]; + endpoint?: CaptureEndpointDiagnostic; }) { super(input.message); this.name = "CaptureFailure"; @@ -35,6 +42,7 @@ export class CaptureFailure extends Error { Object.freeze({ ...diagnostic, lines: Object.freeze([...diagnostic.lines]) }), ), ); + this.endpoint = input.endpoint ? Object.freeze({ ...input.endpoint }) : undefined; if (input.cause instanceof Error && input.cause.stack) this.stack = input.cause.stack; } } @@ -107,6 +115,65 @@ function messageOf(error: unknown): string { return error instanceof Error ? error.message : String(error); } +const CAUSE_CHAIN_DEPTH = 5; + +/** + * Every message reachable from `error` through `.cause` (and the members of + * an `AggregateError`), top-level first. undici flattens a failed connect to + * a top-level `"fetch failed"` whose `.cause` carries the errno message, and a + * `localhost` connect that tried both address families surfaces as an + * `AggregateError` with an empty own message, so classification must read the + * whole chain — the same walk `isDrawElementVerificationError` performs. + */ +function collectMessages(error: unknown): string[] { + const messages: string[] = []; + let current: unknown = error; + for ( + let depth = 0; + depth < CAUSE_CHAIN_DEPTH && current !== undefined && current !== null; + depth++ + ) { + const message = messageOf(current); + if (message) messages.push(message); + if (current instanceof AggregateError) { + for (const member of current.errors) { + const memberMessage = messageOf(member); + if (memberMessage) messages.push(memberMessage); + } + } + current = typeof current === "object" ? (current as { cause?: unknown }).cause : undefined; + } + return messages; +} + +// Node/Bun errno text is unbracketed (`connect ETIMEDOUT ::1:49152`); Chrome +// URLs bracket IPv6 (`http://[::1]:49152/`). Both name the same loopback. +const LOOPBACK_HOST = String.raw`(127\.0\.0\.1|localhost|\[::1\]|::1)`; +const LOOPBACK_CONNECTION_LOSS_PATTERNS = [ + new RegExp(String.raw`connect (?:ETIMEDOUT|ECONNREFUSED|ECONNRESET) ${LOOPBACK_HOST}:(\d+)`, "i"), + new RegExp( + String.raw`net::ERR_(?:TIMED_OUT|CONNECTION_TIMED_OUT|CONNECTION_REFUSED|CONNECTION_RESET|CONNECTION_CLOSED|EMPTY_RESPONSE) at https?://${LOOPBACK_HOST}:(\d+)`, + "i", + ), +]; + +/** + * The loopback endpoint a connection-loss error names, when it names one. + * Only loopback hosts qualify: the render's file server and Chrome's DevTools + * endpoint both live there, so a lost loopback connection is the signal the + * pre-frame recovery acts on. A remote host that times out stays fatal. + */ +function loopbackConnectionLossEndpoint(text: string): CaptureEndpointDiagnostic | undefined { + for (const pattern of LOOPBACK_CONNECTION_LOSS_PATTERNS) { + const match = pattern.exec(text); + if (!match?.[1] || !match[2]) continue; + const port = Number(match[2]); + if (!Number.isInteger(port) || port <= 0 || port > 65_535) continue; + return { host: match[1] === "[::1]" ? "::1" : match[1], port }; + } + return undefined; +} + function matchesAny(message: string, patterns: readonly RegExp[]): boolean { return patterns.some((pattern) => pattern.test(message)); } @@ -133,6 +200,47 @@ function ioError(error: unknown, message: string): boolean { ); } +function isMemoryExhaustionText(message: string, chainText: string): boolean { + return ( + BUN_MEMORY_EXHAUSTION_EXACT_MESSAGE.test(message.trim()) || + BUN_MEMORY_EXHAUSTION_WRAPPED_WORKER_MESSAGE.test(chainText) || + matchesAny(chainText, MEMORY_EXHAUSTION_ERROR_PATTERNS) + ); +} + +interface CaptureFailureKindInput { + error: unknown; + message: string; + chainText: string; + aborted: boolean; + loopbackLoss: boolean; +} + +const CANCELLATION_PATTERN = /(?:render|capture)?_?cancelled|AbortError/i; + +// Order matters: cancellation and memory exhaustion outrank everything, a +// protocol timeout outranks a loopback host mentioned in the same text, and +// authoring/io are the fall-through. +const ORDERED_KIND_MATCHERS: ReadonlyArray< + readonly [CaptureFailureKind, (input: CaptureFailureKindInput) => boolean] +> = [ + ["cancelled", (input) => input.aborted || CANCELLATION_PATTERN.test(input.chainText)], + ["memory_exhaustion", (input) => isMemoryExhaustionText(input.message, input.chainText)], + ["verification", (input) => matchesAny(input.chainText, VERIFICATION_ERROR_PATTERNS)], + ["protocol_timeout", (input) => matchesAny(input.chainText, PROTOCOL_TIMEOUT_PATTERNS)], + [ + "transient_browser", + (input) => input.loopbackLoss || matchesAny(input.chainText, TRANSIENT_BROWSER_ERROR_PATTERNS), + ], + ["authoring", (input) => matchesAny(input.chainText, AUTHORING_ERROR_PATTERNS)], +]; + +function resolveCaptureFailureKind(input: CaptureFailureKindInput): CaptureFailureKind { + const matched = ORDERED_KIND_MATCHERS.find(([, matches]) => matches(input)); + if (matched) return matched[0]; + return ioError(input.error, input.chainText) ? "io" : "authoring"; +} + export function classifyCaptureFailure( error: unknown, options: { @@ -143,34 +251,27 @@ export function classifyCaptureFailure( if (error instanceof CaptureFailure && !options.workerDiagnostics && !options.signal?.aborted) { return error; } - const message = messageOf(error); - let kind: CaptureFailureKind; - if (options.signal?.aborted || /(?:render|capture)?_?cancelled|AbortError/i.test(message)) { - kind = "cancelled"; - } else if ( - BUN_MEMORY_EXHAUSTION_EXACT_MESSAGE.test(message.trim()) || - BUN_MEMORY_EXHAUSTION_WRAPPED_WORKER_MESSAGE.test(message) || - matchesAny(message, MEMORY_EXHAUSTION_ERROR_PATTERNS) - ) { - kind = "memory_exhaustion"; - } else if (matchesAny(message, VERIFICATION_ERROR_PATTERNS)) { - kind = "verification"; - } else if (matchesAny(message, PROTOCOL_TIMEOUT_PATTERNS)) { - kind = "protocol_timeout"; - } else if (matchesAny(message, TRANSIENT_BROWSER_ERROR_PATTERNS)) { - kind = "transient_browser"; - } else if (matchesAny(message, AUTHORING_ERROR_PATTERNS)) { - kind = "authoring"; - } else { - kind = ioError(error, message) ? "io" : "authoring"; - } + const messages = collectMessages(error); + const message = messages[0] ?? messageOf(error); + // Patterns match against the whole cause chain so a wrapped connect failure + // classifies by the errno it carries, not by the wrapper's generic text. + const chainText = messages.join("\n"); + const lossEndpoint = loopbackConnectionLossEndpoint(chainText); + const endpoint = error instanceof CaptureFailure ? error.endpoint : lossEndpoint; return new CaptureFailure({ - kind, + kind: resolveCaptureFailureKind({ + error, + message, + chainText, + aborted: options.signal?.aborted === true, + loopbackLoss: lossEndpoint !== undefined, + }), message, cause: error, workerDiagnostics: options.workerDiagnostics ?? (error instanceof CaptureFailure ? error.workerDiagnostics : undefined), + endpoint, }); } @@ -178,6 +279,23 @@ export function isTransientBrowserError(error: unknown): boolean { return classifyCaptureFailure(error).kind === "transient_browser"; } +/** + * A transient failure that names the loopback endpoint whose connection was + * lost — the file server or Chrome's DevTools port. This is the only + * transient shape the producer's pre-frame recovery retries on an ordinary + * one-worker stream; a bare `Target closed` (Chrome killed by SIGTERM) carries + * no endpoint and stays outside it. + */ +export type LoopbackConnectionLoss = CaptureFailure & { + endpoint: Readonly; +}; + +export function isLoopbackConnectionLoss( + failure: CaptureFailure, +): failure is LoopbackConnectionLoss { + return failure.kind === "transient_browser" && failure.endpoint !== undefined; +} + export function isMemoryExhaustionError(error: unknown): boolean { return classifyCaptureFailure(error).kind === "memory_exhaustion"; } diff --git a/packages/producer/src/services/fileServer.test.ts b/packages/producer/src/services/fileServer.test.ts index 6101bd1ba0..a6436d0e04 100644 --- a/packages/producer/src/services/fileServer.test.ts +++ b/packages/producer/src/services/fileServer.test.ts @@ -1,16 +1,19 @@ import { describe, expect, it } from "bun:test"; import { mkdirSync, mkdtempSync, rmSync, symlinkSync, writeFileSync } from "node:fs"; +import { createServer } from "node:http"; import path, { join } from "node:path"; import { tmpdir } from "node:os"; import { closeFileServerSafely, createFileServer, + FILE_SERVER_HEALTH_PATH, RENDER_CAPTURE_MODE_SHIM, HF_BRIDGE_SCRIPT, HF_EARLY_STUB, injectScriptsAtHeadStart, isPathInside, parseRangeHeader, + probeFileServerHealth, VIRTUAL_TIME_SHIM, } from "./fileServer.js"; @@ -74,6 +77,84 @@ function writeEmptyIndex(projectDir: string): void { writeFileSync(join(projectDir, "index.html"), ""); } +describe("file server health", () => { + it("serves a dedicated loopback health endpoint", async () => { + const projectDir = mkdtempSync(join(tmpdir(), "hf-file-server-health-")); + try { + writeEmptyIndex(projectDir); + await withFileServer(projectDir, async (server) => { + const response = await fetch(`${server.url}${FILE_SERVER_HEALTH_PATH}`); + + expect(response.status).toBe(200); + expect(await response.text()).toBe("ok"); + expect(await probeFileServerHealth(server)).toMatchObject({ + healthy: true, + status: 200, + }); + }); + } finally { + rmSync(projectDir, { recursive: true, force: true }); + } + }); + + it("reports an unreachable endpoint without throwing", async () => { + const health = await probeFileServerHealth({ url: "http://127.0.0.1:1" }, 100); + + expect(health.healthy).toBe(false); + expect(health.error).toBeTruthy(); + expect(health.durationMs).toBeLessThan(1_000); + }); + + it("rejects a foreign listener that answers 200 without the identity header", async () => { + // A stale port can be re-bound by an unrelated process between the probe + // and the restart decision; a bare 200 must not read as "our server". + const foreign = createServer((_request, response) => response.end("ok")); + await new Promise((resolve) => foreign.listen(0, "127.0.0.1", resolve)); + const address = foreign.address(); + if (!address || typeof address === "string") throw new Error("foreign server has no port"); + try { + const health = await probeFileServerHealth({ url: `http://127.0.0.1:${address.port}` }, 500); + + expect(health).toMatchObject({ healthy: false, status: 200 }); + expect(health.error).toBeUndefined(); + } finally { + await new Promise((resolve) => foreign.close(() => resolve())); + } + }); + + it("names the connection-refused code of a probe against a closed port", async () => { + const vacated = createServer(); + await new Promise((resolve) => vacated.listen(0, "127.0.0.1", resolve)); + const address = vacated.address(); + if (!address || typeof address === "string") throw new Error("server has no port"); + await new Promise((resolve) => vacated.close(() => resolve())); + + const health = await probeFileServerHealth({ url: `http://127.0.0.1:${address.port}` }, 500); + + expect(health.healthy).toBe(false); + // Bun reports `ConnectionRefused` on the error itself; Node buries + // `ECONNREFUSED` in `.cause`. Either must surface in the diagnostic. + expect(health.error).toMatch(/ConnectionRefused|ECONNREFUSED/); + }); + + it("bounds a health endpoint that never responds", async () => { + const server = Bun.serve({ + hostname: "127.0.0.1", + port: 0, + fetch: () => new Promise(() => {}), + }); + try { + const health = await probeFileServerHealth({ url: `http://127.0.0.1:${server.port}` }, 25); + + expect(health.healthy).toBe(false); + expect(health.error).toBeTruthy(); + expect(health.durationMs).toBeLessThan(500); + } finally { + server.stop(true); + } + }); +}); + async function expectTextResponse( url: string, options: { contentType?: string; bodyIncludes: string }, diff --git a/packages/producer/src/services/fileServer.ts b/packages/producer/src/services/fileServer.ts index 24d4136952..3501b155db 100644 --- a/packages/producer/src/services/fileServer.ts +++ b/packages/producer/src/services/fileServer.ts @@ -695,6 +695,92 @@ export interface FileServerHandle { addPreHeadScript: (script: string) => void; } +export interface FileServerHealth { + healthy: boolean; + status?: number; + durationMs: number; + error?: string; +} + +export const FILE_SERVER_HEALTH_PATH = "/__hyperframes_health"; +const FILE_SERVER_HEALTH_HEADER = "x-hyperframes-file-server"; + +export async function probeFileServerHealth( + fileServer: Pick, + timeoutMs = 1_000, +): Promise { + const startedAt = Date.now(); + const controller = new AbortController(); + const timer = setTimeout(() => controller.abort(), timeoutMs); + if (typeof timer.unref === "function") timer.unref(); + try { + const response = await fetch(`${fileServer.url}${FILE_SERVER_HEALTH_PATH}`, { + signal: controller.signal, + cache: "no-store", + }); + // A coincidental foreign listener on the same port can answer 200; only + // the identity header proves the responder is this render's file server. + const healthy = response.ok && response.headers.get(FILE_SERVER_HEALTH_HEADER) === "healthy"; + // Release the connection, but never let a rejected cancel() turn a + // healthy server into a restart. + await response.body?.cancel().catch(() => undefined); + return { + healthy, + status: response.status, + durationMs: Date.now() - startedAt, + }; + } catch (error) { + return { + healthy: false, + durationMs: Date.now() - startedAt, + error: describeHealthProbeError(error), + }; + } finally { + clearTimeout(timer); + } +} + +/** + * The probe's failure text with the code that names it. Node's `fetch` reports + * every connect failure as "fetch failed" and buries `ECONNREFUSED` / + * `ETIMEDOUT` in `.cause`; Bun's carries `ConnectionRefused` on the error + * itself. Either way the code is what a restart decision gets read against. + */ +function describeHealthProbeError(error: unknown): string { + const message = error instanceof Error ? error.message : String(error); + let current: unknown = error; + for (let depth = 0; depth < 5 && current instanceof Error; depth++) { + const code = (current as NodeJS.ErrnoException).code; + if (typeof code === "string" && code.length > 0) { + return message.includes(code) ? message : `${message} (${code})`; + } + current = current.cause; + } + return message; +} + +/** + * The one shape every render-path file server takes: the compiled tree under + * `workDir`, an ephemeral port, the virtual-time shim first in ``, and + * the job's fps. Probe discovery, frame capture, and the pre-frame capture + * retry all construct through here so the three sites cannot drift. + */ +export function createRenderFileServer(input: { + projectDir: string; + workDir: string; + fps: Fps; + /** Injected after the virtual-time shim (e.g. the page-side compositing stub). */ + preHeadScripts?: readonly string[]; +}): Promise { + return createFileServer({ + projectDir: input.projectDir, + compiledDir: join(input.workDir, "compiled"), + port: 0, + preHeadScripts: [VIRTUAL_TIME_SHIM, ...(input.preHeadScripts ?? [])], + fps: input.fps, + }); +} + /** * Set before the Hyperframes runtime executes so render/probe pages can avoid * preview-only initialization work that mutates the live visual timeline. @@ -775,6 +861,11 @@ export function createFileServer(options: FileServerOptions): Promise { + c.header(FILE_SERVER_HEALTH_HEADER, "healthy"); + return c.text("ok"); + }); + app.get("/*", async (c) => { let requestPath = c.req.path; if (requestPath === "/") requestPath = "/index.html"; diff --git a/packages/producer/src/services/render/capturePlan.test.ts b/packages/producer/src/services/render/capturePlan.test.ts index b9e09cb787..4ff0ae2eb2 100644 --- a/packages/producer/src/services/render/capturePlan.test.ts +++ b/packages/producer/src/services/render/capturePlan.test.ts @@ -75,6 +75,17 @@ describe("CapturePlan", () => { }); }); + it("replans an ordinary one-worker capture failure onto a fresh screenshot stream", () => { + expect( + replanAfterFailure(streaming(), { kind: "capture_failure", memoryExhaustion: false }), + ).toMatchObject({ + kind: "sdr_streaming", + workerCount: 1, + forceScreenshot: true, + routing: { kind: "default" }, + }); + }); + it("atomically restores the pre-inversion disk route after verification failure", () => { const initial = streaming({ kind: "worker_inversion", diff --git a/packages/producer/src/services/render/captureStageError.test.ts b/packages/producer/src/services/render/captureStageError.test.ts new file mode 100644 index 0000000000..ebd22ebbee --- /dev/null +++ b/packages/producer/src/services/render/captureStageError.test.ts @@ -0,0 +1,46 @@ +import { describe, expect, it } from "vitest"; +import { classifyCaptureFailure, isLoopbackConnectionLoss } from "@hyperframes/engine"; +import { CaptureStageError, wrapCaptureStageError } from "./captureStageError.js"; +import { EncoderInterruptedError } from "./encoderInterruption.js"; + +describe("CaptureStageError", () => { + it("carries the classified loopback endpoint through the streaming-stage wrapper", () => { + const wrapped = wrapCaptureStageError(new Error("connect ETIMEDOUT ::1:49152"), ["console"]); + + expect(wrapped).toBeInstanceOf(CaptureStageError); + expect(wrapped).toMatchObject({ + kind: "transient_browser", + endpoint: { host: "::1", port: 49152 }, + browserConsole: ["console"], + }); + }); + + it("keeps the endpoint when the orchestrator re-classifies the stage error", () => { + // Production path: captureStreamingStage throws wrapCaptureStageError(err) + // and the orchestrator's catch calls classifyCaptureFailure on that result, + // which early-returns the CaptureFailure it was handed. + const wrapped = wrapCaptureStageError( + new TypeError("fetch failed", { cause: new Error("connect ECONNREFUSED 127.0.0.1:4173") }), + [], + ); + const controller = new AbortController(); + + const reclassified = classifyCaptureFailure(wrapped, { signal: controller.signal }); + + expect(reclassified).toBe(wrapped); + expect(isLoopbackConnectionLoss(reclassified)).toBe(true); + expect(reclassified.endpoint).toEqual({ host: "127.0.0.1", port: 4173 }); + }); + + it("leaves a bare target loss without an endpoint", () => { + const wrapped = wrapCaptureStageError(new Error("Target closed"), []); + + expect(wrapped).toMatchObject({ kind: "transient_browser" }); + expect((wrapped as CaptureStageError).endpoint).toBeUndefined(); + }); + + it("passes encoder interruptions through unchanged", () => { + const interrupted = new EncoderInterruptedError("Encoder interrupted", "SIGTERM"); + expect(wrapCaptureStageError(interrupted, [])).toBe(interrupted); + }); +}); diff --git a/packages/producer/src/services/render/captureStageError.ts b/packages/producer/src/services/render/captureStageError.ts index a45a6829a7..5497f0df68 100644 --- a/packages/producer/src/services/render/captureStageError.ts +++ b/packages/producer/src/services/render/captureStageError.ts @@ -12,6 +12,7 @@ export class CaptureStageError extends CaptureFailure { message: normalizeErrorMessage(input.cause), cause: input.cause, workerDiagnostics: classified.workerDiagnostics, + endpoint: classified.endpoint, }); this.name = "CaptureStageError"; this.browserConsole = input.browserConsole.slice(); diff --git a/packages/producer/src/services/render/preFrameRecovery.test.ts b/packages/producer/src/services/render/preFrameRecovery.test.ts new file mode 100644 index 0000000000..a74b5b1895 --- /dev/null +++ b/packages/producer/src/services/render/preFrameRecovery.test.ts @@ -0,0 +1,183 @@ +import { describe, expect, it, vi } from "vitest"; +import { classifyCaptureFailure, CaptureFailure } from "@hyperframes/engine"; +import { + type LoopbackConnectionLoss, + resolvePreFrameLoopbackLoss, + recoverPreFrameFileServer, +} from "./preFrameRecovery.js"; +import { wrapCaptureStageError } from "./captureStageError.js"; + +const lossFrom = (message: string) => + classifyCaptureFailure(new Error(message)) as LoopbackConnectionLoss; +const loopbackLoss = () => lossFrom("connect ETIMEDOUT ::1:49152"); + +describe("resolvePreFrameLoopbackLoss", () => { + it("qualifies a loopback connection loss on a one-worker stream before the first frame", () => { + expect( + resolvePreFrameLoopbackLoss({ + failure: loopbackLoss(), + workerCount: 1, + framesRendered: 0, + }), + ).toBeDefined(); + }); + + it("qualifies a stage-wrapped Node fetch failure with the errno in its cause", () => { + const failure = wrapCaptureStageError( + new TypeError("fetch failed", { cause: new Error("connect ECONNREFUSED 127.0.0.1:49152") }), + [], + ); + expect( + resolvePreFrameLoopbackLoss({ + failure: failure as CaptureFailure, + workerCount: 1, + framesRendered: 0, + }), + ).toBeDefined(); + }); + + it.each([ + ["Target closed", "a SIGTERM-killed Chrome target"], + ["Failed to launch the browser process! spawn ENOENT", "a browser that cannot launch"], + ["Page crashed!", "a page crash"], + ["Composition has zero duration. Runtime ready: false", "a runtime that never became ready"], + ["Navigation timeout of 30000 ms exceeded", "a navigation timeout"], + ["connect ETIMEDOUT 203.0.113.10:443", "a remote connect timeout"], + ])("does not qualify %s (%s)", (message) => { + const failure = classifyCaptureFailure(new Error(message)); + expect( + resolvePreFrameLoopbackLoss({ failure, workerCount: 1, framesRendered: 0 }), + ).toBeUndefined(); + }); + + it("requires exactly one worker", () => { + for (const workerCount of [0, 2, 4]) { + expect( + resolvePreFrameLoopbackLoss({ + failure: loopbackLoss(), + workerCount, + framesRendered: 0, + }), + ).toBeUndefined(); + } + }); + + it("requires that no frame has been written yet", () => { + expect( + resolvePreFrameLoopbackLoss({ + failure: loopbackLoss(), + workerCount: 1, + framesRendered: 1, + }), + ).toBeUndefined(); + expect( + resolvePreFrameLoopbackLoss({ + failure: loopbackLoss(), + workerCount: 1, + framesRendered: 9_500, + }), + ).toBeUndefined(); + }); + + it("does not qualify a cancelled failure even when it names a loopback endpoint", () => { + const controller = new AbortController(); + controller.abort(); + const cancelled = classifyCaptureFailure(new Error("connect ETIMEDOUT ::1:49152"), { + signal: controller.signal, + }); + expect(cancelled.kind).toBe("cancelled"); + expect( + resolvePreFrameLoopbackLoss({ failure: cancelled, workerCount: 1, framesRendered: 0 }), + ).toBeUndefined(); + }); +}); + +describe("recoverPreFrameFileServer", () => { + const server = { url: "http://localhost:49152", port: 49152 }; + const replacement = { url: "http://localhost:50001", port: 50001 }; + + it("restarts the file server when the probe reports it unhealthy", async () => { + const restart = vi.fn(async () => replacement); + const warn = vi.fn(); + + await recoverPreFrameFileServer({ + failure: loopbackLoss(), + fileServer: server, + health: Promise.resolve({ + healthy: false, + durationMs: 12, + error: "fetch failed (ECONNREFUSED)", + }), + restart, + log: { warn }, + }); + + expect(restart).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "[Render] Pre-frame capture endpoint health", + expect.objectContaining({ + reportedEndpoint: "::1:49152", + endpointOwner: "file_server", + fileServerEndpoint: server.url, + fileServerHealthy: false, + healthProbeError: "fetch failed (ECONNREFUSED)", + }), + ); + expect(warn).toHaveBeenCalledWith( + "[Render] Recreated unhealthy file server before bounded capture retry", + { fileServerEndpoint: replacement.url }, + ); + }); + + it("keeps a healthy file server and never calls restart", async () => { + const restart = vi.fn(async () => replacement); + + await recoverPreFrameFileServer({ + failure: loopbackLoss(), + fileServer: server, + health: Promise.resolve({ healthy: true, status: 200, durationMs: 3 }), + restart, + log: { warn: vi.fn() }, + }); + + expect(restart).not.toHaveBeenCalled(); + }); + + it("reports a foreign port as browser_or_unknown while still restarting on an unhealthy probe", async () => { + const failure = lossFrom("net::ERR_CONNECTION_TIMED_OUT at http://localhost:9222/json/version"); + const restart = vi.fn(async () => replacement); + const warn = vi.fn(); + + await recoverPreFrameFileServer({ + failure, + fileServer: server, + health: Promise.resolve({ + healthy: false, + durationMs: 1_008, + error: "This operation was aborted", + }), + restart, + log: { warn }, + }); + + expect(warn).toHaveBeenCalledWith( + "[Render] Pre-frame capture endpoint health", + expect.objectContaining({ endpointOwner: "browser_or_unknown" }), + ); + expect(restart).toHaveBeenCalledTimes(1); + }); + + it("propagates a failed restart instead of retrying against a dead server", async () => { + await expect( + recoverPreFrameFileServer({ + failure: loopbackLoss(), + fileServer: server, + health: Promise.resolve({ healthy: false, durationMs: 1 }), + restart: async () => { + throw new Error("EADDRINUSE"); + }, + log: { warn: vi.fn() }, + }), + ).rejects.toThrow("EADDRINUSE"); + }); +}); diff --git a/packages/producer/src/services/render/preFrameRecovery.ts b/packages/producer/src/services/render/preFrameRecovery.ts new file mode 100644 index 0000000000..1ccc2ad338 --- /dev/null +++ b/packages/producer/src/services/render/preFrameRecovery.ts @@ -0,0 +1,65 @@ +import { + type CaptureFailure, + isLoopbackConnectionLoss, + type LoopbackConnectionLoss, +} from "@hyperframes/engine"; +import type { ProducerLogger } from "../../logger.js"; +import type { FileServerHandle, FileServerHealth } from "../fileServer.js"; + +/** + * Pre-frame loopback recovery for an ordinary one-worker screenshot stream. + * + * The streaming stage can lose its loopback connection — to the file server or + * to Chrome's DevTools port — before the first frame is captured. That is the + * only transient shape this path retries, and this function is its single + * owner: the failure must name a loopback endpoint (`isLoopbackConnectionLoss`), + * the stream must be single-worker (a multi-worker stream has its own adaptive + * retry), and no frame may have been written yet (a later loss is a different + * failure and would restart the whole render from frame 0 on the slower + * path). A bare `Target closed` — Chrome killed by SIGTERM on a host that is + * going away — carries no endpoint and is deliberately excluded, matching + * the encoder-interruption rule in `shouldRetryViaPinnedFallback`. + */ +export function resolvePreFrameLoopbackLoss(input: { + failure: CaptureFailure; + workerCount: number; + framesRendered: number; +}): LoopbackConnectionLoss | undefined { + if (input.workerCount !== 1 || input.framesRendered !== 0) return undefined; + return isLoopbackConnectionLoss(input.failure) ? input.failure : undefined; +} + +/** + * Decide whether the retry needs a fresh file server and perform the restart. + * The restart rebinds the caller's active server; nothing is returned. + * + * The probe result is passed in (not taken here) so the caller can start it + * while the failed browser session is still closing. The restart keys on the + * probe, not on the reported endpoint: a bare loopback timeout cannot prove + * which listener was gone, so the file server's own health is the evidence. + */ +export async function recoverPreFrameFileServer(input: { + failure: LoopbackConnectionLoss; + fileServer: Pick; + health: Promise; + restart: () => Promise>; + log: Pick; +}): Promise { + const health = await input.health; + const endpointOwner = + input.failure.endpoint.port === input.fileServer.port ? "file_server" : "browser_or_unknown"; + input.log.warn("[Render] Pre-frame capture endpoint health", { + reportedEndpoint: `${input.failure.endpoint.host}:${input.failure.endpoint.port}`, + endpointOwner, + fileServerEndpoint: input.fileServer.url, + fileServerHealthy: health.healthy, + fileServerStatus: health.status, + healthProbeMs: health.durationMs, + healthProbeError: health.error, + }); + if (health.healthy) return; + const fileServer = await input.restart(); + input.log.warn("[Render] Recreated unhealthy file server before bounded capture retry", { + fileServerEndpoint: fileServer.url, + }); +} diff --git a/packages/producer/src/services/render/stages/probeStage.ts b/packages/producer/src/services/render/stages/probeStage.ts index 429c915872..76f169e96d 100644 --- a/packages/producer/src/services/render/stages/probeStage.ts +++ b/packages/producer/src/services/render/stages/probeStage.ts @@ -54,9 +54,8 @@ import { } from "../../htmlCompiler.js"; import { closeFileServerSafely, - createFileServer, + createRenderFileServer, type FileServerHandle, - VIRTUAL_TIME_SHIM, } from "../../fileServer.js"; import type { ProducerLogger } from "../../../logger.js"; import { @@ -319,13 +318,7 @@ export async function runProbeStage(input: ProbeStageInput): Promise { + expect( + shouldRetryViaPinnedFallback({ + isVerifyError: false, + isCancellation: false, + isPreFrameLoopbackConnectionLoss: true, + deWorkerInversion: undefined, + deParallelRouter: undefined, + }), + ).toBe(true); + }); + + it("does not widen the loopback retry to an unpinned route that did not qualify", () => { + expect( + shouldRetryViaPinnedFallback({ + isVerifyError: false, + isCancellation: false, + isPreFrameLoopbackConnectionLoss: false, + deWorkerInversion: undefined, + deParallelRouter: undefined, + }), + ).toBe(false); + }); + + it("never qualifies a SIGTERM-killed Chrome (`Target closed`) for the loopback recovery path", () => { + // Host shutdown: Chrome dies before the encoder notices, so the error is a + // plain `Target closed`, not an EncoderInterruptedError. It names no + // loopback endpoint, so the pre-frame gate alone never retries it; only + // isTransientCaptureError (routing-independent transient retry) can. + const failure = classifyCaptureFailure(wrapCaptureStageError(new Error("Target closed"), [])); + const preFrameLoopbackLoss = resolvePreFrameLoopbackLoss({ + failure, + workerCount: 1, + framesRendered: 0, + }); + expect(failure.kind).toBe("transient_browser"); + expect(preFrameLoopbackLoss).toBeUndefined(); + expect( + shouldRetryViaPinnedFallback({ + isVerifyError: false, + isCancellation: false, + isEncoderInterrupted: false, + isPreFrameLoopbackConnectionLoss: preFrameLoopbackLoss !== undefined, + deWorkerInversion: undefined, + deParallelRouter: undefined, + }), + ).toBe(false); + }); + + it("keeps a pre-frame loopback loss non-retryable once cancellation or an encoder interruption is present", () => { + for (const overrides of [{ isCancellation: true }, { isEncoderInterrupted: true }]) { + expect( + shouldRetryViaPinnedFallback({ + isVerifyError: false, + isCancellation: false, + isPreFrameLoopbackConnectionLoss: true, + deWorkerInversion: undefined, + deParallelRouter: undefined, + ...overrides, + }), + ).toBe(false); + } + }); + it("retries OOM too when the router pinned the worker count (fallback's Chrome processes are already dead by the time this runs, and the fallback is pooled/lighter than the pinned path)", () => { expect( shouldRetryViaPinnedFallback({ @@ -2751,6 +2818,15 @@ describe("shouldRetryViaPinnedFallback (widen the self-verify retry to generic c deParallelRouter: undefined, }), ).toBe(false); + expect( + shouldRetryViaPinnedFallback({ + isVerifyError: false, + isCancellation: true, + isPreFrameLoopbackConnectionLoss: true, + deWorkerInversion: undefined, + deParallelRouter: undefined, + }), + ).toBe(false); }); it("never hides an encoder host interruption behind the same-host pinned fallback", () => { diff --git a/packages/producer/src/services/renderOrchestrator.ts b/packages/producer/src/services/renderOrchestrator.ts index 1d8a4b8562..c8f505fb5a 100644 --- a/packages/producer/src/services/renderOrchestrator.ts +++ b/packages/producer/src/services/renderOrchestrator.ts @@ -100,10 +100,10 @@ import { randomUUID } from "crypto"; import { fileURLToPath } from "url"; import { closeFileServerSafely, - createFileServer, + createRenderFileServer, + probeFileServerHealth, type FileServerHandle, HF_PAGE_SIDE_COMPOSITING_STUB, - VIRTUAL_TIME_SHIM, } from "./fileServer.js"; import { defaultLogger, type ProducerLogger } from "../logger.js"; import { @@ -135,6 +135,10 @@ import { worstSubTimelineWaitOutcome, } from "./render/perfSummary.js"; import { getCaptureStageBrowserConsole } from "./render/captureStageError.js"; +import { + recoverPreFrameFileServer, + resolvePreFrameLoopbackLoss, +} from "./render/preFrameRecovery.js"; import { resolveVideoCaptureBeyondViewport } from "./render/captureBeyondViewport.js"; import { type CaptureCalibrationSample, @@ -1845,10 +1849,8 @@ export function resolveParallelRouterRetryPlan(args: { } /** - * Should a capture-stage error retry via the pinned-worker-count fallback - * (the same "well-tested parallel-disk / single-worker screenshot" path - * `resolveInversionRetryPlan`/`resolveParallelRouterRetryPlan` reroute to) - * instead of failing the render outright? + * Should a streaming capture-stage error use the bounded screenshot recovery + * path instead of failing the render outright? * * True for the drawElement self-verify failures this retry path was * originally built for (blank frame / PSNR breach), AND for any OTHER @@ -1857,6 +1859,17 @@ export function resolveParallelRouterRetryPlan(args: { * of calibration, so a generic capture failure on that pinned count is * exactly the scenario the pin itself introduced risk for. * + * An ordinary one-worker stream also gets one retry when it loses its loopback + * connection (file server or DevTools port) before the first frame — see + * resolvePreFrameLoopbackLoss for the exact shape. There is no worker + * count to reduce, but the failed stage has already closed its session and + * encoder; replanning forces screenshot capture and the second invoke creates + * fresh resources, recreating the file server first when its health probe + * fails. The loopback gate is deliberately narrow — a Chrome killed by a host + * shutdown looks exactly like `Target closed`, so it never qualifies here; + * whether such a shape retries at all is decided by `isTransientCaptureError` + * below, which covers every transient browser failure routing-independently. + * * Includes OOM (previously excluded — see PR history): every worker's * `executeWorkerTask` closes its capture session in a `finally` that awaits * `closeCaptureSession` → `releaseBrowser`, which SIGKILLs the Chrome process @@ -1890,6 +1903,8 @@ export function shouldRetryViaPinnedFallback(args: { isDeCaptureError?: boolean; isCancellation: boolean; isEncoderInterrupted?: boolean; + /** Pre-frame loopback connection loss on an ordinary one-worker stream. */ + isPreFrameLoopbackConnectionLoss?: boolean; deWorkerInversion: "inverted" | "reverted" | undefined; deParallelRouter: "routed" | "reverted" | undefined; /** @@ -1918,6 +1933,7 @@ export function shouldRetryViaPinnedFallback(args: { if (args.isVerifyError || args.isDeCaptureError) return true; if (args.isDeRendererStall === true || args.isSequentialCaptureStall === true) return true; if (args.isTransientCaptureError === true) return true; + if (args.isPreFrameLoopbackConnectionLoss) return true; return args.deWorkerInversion === "inverted" || args.deParallelRouter === "routed"; } @@ -1948,7 +1964,7 @@ export function isSequentialCaptureStallError(err: unknown): boolean { } /** - * When a self-verify (or pinned-fallback) retry is triggered mid-capture, the + * When a self-verify or capture retry is triggered mid-capture, the * caller may still hold a live probe session that the failed stage was passed * but did not (or could not) close in its own `finally` before it threw. Left * behind, that session's Chrome process orphans until the containing render @@ -2739,13 +2755,7 @@ async function executeRenderPipeline(input: { if (!fileServer) { const fileServerStart = observability.stageStart("file_server", { reused: false }); try { - fileServer = await createFileServer({ - projectDir, - compiledDir: join(workDir, "compiled"), - port: 0, - preHeadScripts: [VIRTUAL_TIME_SHIM], - fps: job.config.fps, - }); + fileServer = await createRenderFileServer({ projectDir, workDir, fps: job.config.fps }); assertNotAborted(); observability.stageEnd("file_server", fileServerStart); } catch (error) { @@ -2755,11 +2765,10 @@ async function executeRenderPipeline(input: { } else { observability.checkpoint("file_server", "reused probe file server"); } - const activeFileServer = fileServer; + let activeFileServer = fileServer; if (!activeFileServer) { throw new Error("File server failed to initialize before frame capture"); } - const framesDir = join(workDir, "captured-frames"); if (!existsSync(framesDir)) mkdirSync(framesDir, { recursive: true }); @@ -3453,6 +3462,21 @@ async function executeRenderPipeline(input: { "screenshot per output frame.", ); } + // `invokeStreaming` reads `activeFileServer` when called, so rebinding it + // here is what the bounded retry picks up. The same factory as the first + // construction, plus the compositing stub that addPreHeadScript added. + const restartCaptureFileServer = async (): Promise => { + closeFileServerSafely(activeFileServer, "capture retry", log); + fileServer = null; + activeFileServer = await createRenderFileServer({ + projectDir, + workDir, + fps: job.config.fps, + preHeadScripts: usePageSideCompositingForTransitions ? [HF_PAGE_SIDE_COMPOSITING_STUB] : [], + }); + fileServer = activeFileServer; + return activeFileServer; + }; const useLayeredComposite = !usePageSideCompositingForTransitions && shouldUseLayeredComposite({ @@ -3730,25 +3754,32 @@ async function executeRenderPipeline(input: { try { streamingRes = await invokeStreaming(); } catch (err) { - // drawElement self-verification or a sequential no-progress deadline - // restarts the whole render from a fresh screenshot session. When an - // inversion/router pinned the worker count, other capture-stage - // failures (host timeout, worker crash, OOM) can use that same tested - // baseline. The stage closes the failed session before throwing; - // probeSession (if any) was consumed by it. See - // shouldRetryViaPinnedFallback for exactly which errors qualify. + // drawElement self-verification, a sequential no-progress deadline, + // or an ordinary single-worker stream losing its loopback connection + // before the first frame restarts the whole render from a fresh + // screenshot session. When an inversion/router pinned the worker + // count, other capture-stage failures (host timeout, worker crash, + // OOM) can use that same tested baseline. The stage closes the failed + // session before throwing; probeSession (if any) was consumed by it. + // See shouldRetryViaPinnedFallback for exactly which errors qualify. const isVerifyError = isDrawElementVerificationError(err); const isDeCaptureError = isDrawElementCaptureError(err); const isDeStall = isDeRendererStallError(err); const isSequentialStall = isSequentialCaptureStallError(err); const isCancellation = err instanceof RenderCancelledError || executionSignal?.aborted === true; + const preFrameLoopbackLoss = resolvePreFrameLoopbackLoss({ + failure: classifyCaptureFailure(err, { signal: executionSignal }), + workerCount: capturePlan.workerCount, + framesRendered: job.framesRendered ?? 0, + }); if ( !shouldRetryViaPinnedFallback({ isVerifyError, isDeCaptureError, isCancellation, isEncoderInterrupted: err instanceof EncoderInterruptedError, + isPreFrameLoopbackConnectionLoss: preFrameLoopbackLoss !== undefined, deWorkerInversion, deParallelRouter, isDeRendererStall: isDeStall, @@ -3779,7 +3810,9 @@ async function executeRenderPipeline(input: { ? "[Render] drawElement renderer stalled; re-rendering via screenshot" : isSequentialStall ? "[Render] sequential capture stalled; retrying on a fresh screenshot session" - : "[Render] capture failed; re-rendering via a fresh screenshot session", + : preFrameLoopbackLoss + ? "[Render] pre-frame loopback connection loss; retrying with a fresh screenshot session" + : "[Render] capture failed; re-rendering via a fresh screenshot session", { error: err instanceof Error ? err.message : String(err) }, ); observability.checkpoint( @@ -3790,7 +3823,9 @@ async function executeRenderPipeline(input: { ? "drawElement renderer stalled; retrying with forceScreenshot" : isSequentialStall ? "sequential capture stalled; retrying with a fresh screenshot session" - : "capture failed; retrying with a fresh screenshot session", + : preFrameLoopbackLoss + ? "pre-frame loopback connection loss; retrying with a fresh screenshot session" + : "capture failed; retrying with a fresh screenshot session", ); const failedRouting = capturePlan.routing.kind; const failure = streamingCaptureFailure( @@ -3813,6 +3848,11 @@ async function executeRenderPipeline(input: { deWorkerInversion, deParallelRouter, }); + // Probe the file server while the failed session closes below; the + // recovery decision awaits the result once the session is gone. + const preFrameRecovery = preFrameLoopbackLoss + ? { failure: preFrameLoopbackLoss, health: probeFileServerHealth(activeFileServer) } + : null; // Streaming stage aims to close the probe in its own finally; if it // threw before doing so, the Chrome process would orphan through the // pinned-fallback retry. Close defensively before we release the @@ -3823,6 +3863,14 @@ async function executeRenderPipeline(input: { probeSession = null; await closeOrphanedProbeForRetry(orphaned, closeCaptureSession, log, "streaming"); } + if (preFrameRecovery) { + await recoverPreFrameFileServer({ + ...preFrameRecovery, + fileServer: activeFileServer, + restart: restartCaptureFileServer, + log, + }); + } if (failedRouting !== "default") { // The inversion's / router's bet on the pinned path lost. Prefer // the pre-routing parallel screenshot route; a verification