fix(engine): bound drawElement frames so a wedged renderer falls back instead of failing

A single drawElement frame could kill an entire render. On one comp
(caption-editorial-emphasis) drawElementImage returns normally and the renderer
then stops draining its task queue: the setTimeout(…, 0) that schedules
toDataURL never fires, the capture page.evaluate never settles, and 60s later
the stage watchdog fails the whole render. Deterministic on 152.0.7977.30,
always the same frame. Root-cause detail in PRINFRA-488.

Two gaps, both closed here.

1. Nothing below the 60s stage watchdog bounded a frame. Adds a per-frame
   deadline (HF_DE_FRAME_TIMEOUT_MS, default 15000, 0 disables) around the WHOLE
   frame operation, not just the drawElementImage call — the stall surfaces at
   whichever page round-trip comes next, and was observed at both the capture
   and the seek's background-image decode. Bounding one call missed it.

   Deliberately NO per-frame screenshot fallback for this error: once the
   renderer stops scheduling it is wedged for every subsequent round-trip on
   that page. Measured — the screenshot fallback blew the same deadline. The
   frame fails fast instead, so the recovery that actually works can run.

2. That recovery was ineligible. shouldRetryViaPinnedFallback only retried a
   generic capture failure when the worker count was PINNED by the inversion or
   the router; a comp that engaged drawElement on the ordinary single-worker
   path had no whole-render fallback at all. A renderer stall is now retryable
   on any routing — the failure is a property of drawElement itself, and the
   retry re-renders on a fresh page via screenshot. Reported as
   de_fallback_reason "de_renderer_stall" so it is distinguishable from
   capture_error in telemetry, and counted per-session as deFrameTimeouts.

Verified end to end on the repro: previously exit 1 with "stalled: no frame
progress for 60000ms"; now the deadline fires, the render retries via
screenshot, and RENDER_OK with a valid 1920x1080 / 240-frame / 8.0s MP4.

Tests cover the predicate both ways plus the cross-package error match. Engine
1,481 and producer 587 green (audioPadTrim.integration flakes only under
full-suite parallel load — passes in isolation, and on clean HEAD it is green
too, so it is not from this change).

Refs PRINFRA-488
This commit is contained in:
Vance Ingalls
2026-08-11 15:24:54 -07:00
parent 564caa57c2
commit f7a297b35b
4 changed files with 173 additions and 2 deletions
+81 -1
View File
@@ -212,6 +212,13 @@ export interface CaptureSession {
deVerifyInitMs?: number;
/** Count of per-frame "No cached paint record" screenshot fallbacks (telemetry). */
deNcprFallbacks?: number;
/**
* Count of drawElement frame captures that blew `HF_DE_FRAME_TIMEOUT_MS`
* because the renderer stopped scheduling after drawElementImage returned
* (PRINFRA-488). Each one aborts the drawElement attempt so the whole render
* retries via screenshot.
*/
deFrameTimeouts?: number;
/**
* drawElement init passed every gate but stopped before verification +
* canvas injection: the session has no video-frame injector yet (probe
@@ -3133,6 +3140,55 @@ function isNoCachedPaintRecordError(err: unknown): boolean {
return msg.includes("No cached paint record");
}
/**
* Per-frame deadline for the drawElement capture round-trip.
*
* drawElementImage can return normally and then leave the renderer not draining
* its task queue: the `setTimeout(…, 0)` that drawAndEncode schedules to run
* `toDataURL` never fires, so the capture `page.evaluate` never settles.
* Reproduced deterministically on Chromium 152.0.7977.30, one comp, always the
* same frame (PRINFRA-488). Nothing below the render-level watchdog bounded
* this, so a single bad frame failed the ENTIRE render after a 60 s stall.
*
* This bounds the round-trip so the frame can take the same per-frame screenshot
* fallback the `No cached paint record` case already takes — one slow frame
* instead of a dead render. Tune with `HF_DE_FRAME_TIMEOUT_MS`; 0 disables.
*/
const DE_FRAME_TIMEOUT_MS = Number(process.env.HF_DE_FRAME_TIMEOUT_MS ?? "15000");
class DeFrameTimeoutError extends Error {
constructor(label: string, ms: number) {
super(`drawElement ${label} exceeded ${ms}ms (renderer stopped scheduling; see PRINFRA-488)`);
this.name = "DeFrameTimeoutError";
}
}
function isDeFrameTimeoutError(err: unknown): boolean {
return err instanceof DeFrameTimeoutError;
}
/**
* Race `work` against a deadline. The losing promise is NOT cancellable —
* puppeteer cannot abort an in-flight `page.evaluate` — so its rejection is
* swallowed to avoid an unhandled rejection when it eventually settles (or
* never does).
*/
async function withFrameDeadline<T>(work: Promise<T>, label: string, ms: number): Promise<T> {
if (!(ms > 0)) return work;
let timer: ReturnType<typeof setTimeout> | undefined;
const guard = new Promise<never>((_resolve, reject) => {
timer = setTimeout(() => reject(new DeFrameTimeoutError(label, ms)), ms);
});
try {
return await Promise.race([work, guard]);
} finally {
if (timer) clearTimeout(timer);
void work.catch(() => {
/* orphaned round-trip — see doc above */
});
}
}
async function captureFrameCore(
session: CaptureSession,
frameIndex: number,
@@ -3260,6 +3316,22 @@ async function captureFrameCore(
// (display toggled / detached / freshly-shown at a clip-cut boundary). This
// is a per-frame condition, not a whole-comp one — fall back to screenshot
// for THIS frame instead of aborting the render. See fast-capture-limitations.md.
if (isDeFrameTimeoutError(err)) {
// Deliberately NO per-frame screenshot fallback here. When the
// renderer stops scheduling, it is wedged for EVERY subsequent
// round-trip on that page — measured: the screenshot fallback blew
// the same deadline. Fail fast instead and let the producer re-render
// the whole comp on a fresh page via the screenshot path, which is
// the only recovery that actually works.
session.deFrameTimeouts = (session.deFrameTimeouts ?? 0) + 1;
console.log(
`[engine] fast capture: frame ${frameIndex} — capture exceeded ` +
`${DE_FRAME_TIMEOUT_MS}ms; renderer stalled after drawElementImage ` +
`(PRINFRA-488). Failing the drawElement attempt so the whole render ` +
`retries via screenshot.`,
);
throw err;
}
if (isNoCachedPaintRecordError(err)) {
session.deNcprFallbacks = (session.deNcprFallbacks ?? 0) + 1;
console.log(
@@ -3344,7 +3416,14 @@ export async function captureFrameToBuffer(
frameIndex: number,
time: number,
): Promise<CaptureBufferResult> {
const { buffer, captureTimeMs } = await captureFrameCore(session, frameIndex, time);
const { buffer, captureTimeMs } =
session.captureMode === "drawelement"
? await withFrameDeadline(
captureFrameCore(session, frameIndex, time),
`frame ${frameIndex}`,
DE_FRAME_TIMEOUT_MS,
)
: await captureFrameCore(session, frameIndex, time);
return { buffer, captureTimeMs };
}
@@ -3951,5 +4030,6 @@ export function getCapturePerfSummary(session: CaptureSession): CapturePerfSumma
deVerifyInitMs: session.deVerifyInitMs ?? 0,
deBoundaryFrames: session.clipBoundaryFrames?.size ?? 0,
deNcprFallbacks: session.deNcprFallbacks ?? 0,
deFrameTimeouts: session.deFrameTimeouts ?? 0,
};
}
+8
View File
@@ -345,6 +345,14 @@ export interface CapturePerfSummary {
deBoundaryFrames: number;
/** Per-frame "No cached paint record" screenshot fallbacks during capture. */
deNcprFallbacks: number;
/**
* Per-frame drawElement captures that blew the `HF_DE_FRAME_TIMEOUT_MS`
* deadline and took the screenshot fallback (renderer stopped scheduling
* after drawElementImage returned — PRINFRA-488). Non-zero means the render
* completed only because the deadline caught a stall that previously failed
* the whole render.
*/
deFrameTimeouts: number;
}
// ── Global Augmentation ────────────────────────────────────────────────────────
@@ -34,6 +34,7 @@ import {
resolveParallelRouterRetryPlan,
resetCaptureAttemptProgress,
shouldRetryViaPinnedFallback,
isDeRendererStallError,
countElementTags,
envInt,
isDeParallelRouterEnabled,
@@ -2457,6 +2458,60 @@ describe("resolveParallelRouterRetryPlan (self-verify retry rollback)", () => {
});
describe("shouldRetryViaPinnedFallback (widen the self-verify retry to generic capture failures, including OOM)", () => {
// PRINFRA-488: a wedged renderer must be retryable on ANY routing. Before this,
// a comp that engaged drawElement on the ordinary single-worker path had no
// whole-render fallback, so one stalled frame failed the entire render.
it("retries a drawElement renderer stall even with no pinned routing", () => {
expect(
shouldRetryViaPinnedFallback({
isVerifyError: false,
isCancellation: false,
deWorkerInversion: undefined,
deParallelRouter: undefined,
isDeRendererStall: true,
}),
).toBe(true);
});
it("still does NOT retry a generic capture failure with no pinned routing", () => {
expect(
shouldRetryViaPinnedFallback({
isVerifyError: false,
isCancellation: false,
deWorkerInversion: undefined,
deParallelRouter: undefined,
isDeRendererStall: false,
}),
).toBe(false);
});
it("never retries a cancellation, even for a renderer stall", () => {
expect(
shouldRetryViaPinnedFallback({
isVerifyError: false,
isCancellation: true,
deWorkerInversion: undefined,
deParallelRouter: undefined,
isDeRendererStall: true,
}),
).toBe(false);
});
it("recognizes the engine's stall error across the package boundary", () => {
const byName = new Error("whatever");
byName.name = "DeFrameTimeoutError";
expect(isDeRendererStallError(byName)).toBe(true);
expect(
isDeRendererStallError(
new Error(
"drawElement frame 50 exceeded 15000ms (renderer stopped scheduling; see PRINFRA-488)",
),
),
).toBe(true);
expect(isDeRendererStallError(new Error("some other capture failure"))).toBe(false);
expect(isDeRendererStallError("not an error")).toBe(false);
});
it("always retries a drawElement self-verify failure, pinned or not", () => {
expect(
shouldRetryViaPinnedFallback({
@@ -1808,12 +1808,34 @@ export function shouldRetryViaPinnedFallback(args: {
isCancellation: boolean;
deWorkerInversion: "inverted" | "reverted" | undefined;
deParallelRouter: "routed" | "reverted" | undefined;
/**
* The drawElement capture wedged the renderer (PRINFRA-488). Retryable on ANY
* routing, not just a pinned one: the failure is a property of drawElement
* itself, and the retry re-renders on a fresh page via screenshot — the only
* recovery that works once the renderer stops scheduling. Without this a comp
* that engaged drawElement on the ordinary single-worker path (neither
* inverted nor routed) had NO whole-render fallback, so one wedged frame
* failed the entire render.
*/
isDeRendererStall?: boolean;
}): boolean {
if (args.isCancellation) return false;
if (args.isVerifyError) return true;
if (args.isDeRendererStall === true) return true;
return args.deWorkerInversion === "inverted" || args.deParallelRouter === "routed";
}
/**
* True for the drawElement per-frame deadline breach raised by the engine when
* the renderer stops scheduling after `drawElementImage` returns (PRINFRA-488).
* Matched on name+message rather than by class because the error crosses the
* engine/producer package boundary.
*/
export function isDeRendererStallError(err: unknown): boolean {
if (!(err instanceof Error)) return false;
return err.name === "DeFrameTimeoutError" || err.message.includes("renderer stopped scheduling");
}
/**
* When a self-verify (or pinned-fallback) retry is triggered mid-capture, the
* caller may still hold a live probe session that the failed stage was passed
@@ -3556,6 +3578,7 @@ async function executeRenderPipeline(input: {
// spawns on retry. See shouldRetryViaPinnedFallback for exactly
// which errors qualify.
const isVerifyError = isDrawElementVerificationError(err);
const isDeStall = isDeRendererStallError(err);
const isCancellation =
err instanceof RenderCancelledError || executionSignal?.aborted === true;
if (
@@ -3564,6 +3587,7 @@ async function executeRenderPipeline(input: {
isCancellation,
deWorkerInversion,
deParallelRouter,
isDeRendererStall: isDeStall,
})
)
throw err;
@@ -3576,7 +3600,11 @@ async function executeRenderPipeline(input: {
deFallbackFrameIndex = t.frameIndex;
deFallbackThresholdDb = t.thresholdDb;
} else {
deFallbackReason = isMemoryExhaustion ? "oom" : "capture_error";
deFallbackReason = isMemoryExhaustion
? "oom"
: isDeStall
? "de_renderer_stall"
: "capture_error";
}
log.warn(
isVerifyError