From 65349a3ccfccadcceb0d78a0c415f38ba37ed684 Mon Sep 17 00:00:00 2001
From: Vance Ingalls <vance@heygen.com>
Date: Tue, 7 Jul 2026 21:12:34 -0700
Subject: [PATCH] fix(engine): fail-fast the sub-composition timeline wait when
 a script 404s
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

pollSubCompositionTimelines waits for every [data-composition-id] host to
register window.__timelines[id]. When the script carrying that registration
fails to load (404 / request failure), the registration can never arrive —
but the poll still burned the full playerReadyTimeout (45s), then warned and
shipped a silently animation-less render. Wild scale: the capture-setup
histogram over 30 days of local renders decays smoothly (402/503/364/282/191
per 5s bucket) then spikes to 705 at the 45s bucket — ~1,000 renders/month
across 402 distinct users, ~15 user-hours of pure waiting.

- Sessions now record failed SCRIPT resources (requestfailed + HTTP>=400
  response, listeners that already existed for diagnostics) in
  session.scriptLoadFailures.
- pollSubCompositionTimelines takes a failure getter and cuts the wait to a
  2s grace once any script failed, with a loud warning naming the URL(s).
  Late-registering fetch-async comps are unaffected: no script failure means
  the full timeout still applies, and a registration landing inside the
  grace window still wins (tested).
- Outcome telemetry: session.subTimelineWaitOutcome ("ready" | "timeout" |
  "script_failure") -> CapturePerfSummary -> RenderPerfSummary.subTimelineWait
  (worst across sessions) -> render_complete sub_timeline_wait, so the wild
  rate becomes directly trackable instead of setup-histogram forensics.

Validation: the discovery comp (0768f038, its animations.js unreachable)
drops from ~72s to 23.1s total — poll cut at 2.1s with the script named;
healthy comp reports "ready". Canary suite 7/7 (PSNRs identical). 4 new
poll unit tests; engine suite 907 passed (14 failures are PRE-EXISTING on
main at v0.7.42 — 18 fail on a clean checkout, stash A/B verified).
tsc/oxlint/oxfmt clean.

Corpus note: 258/1,762 corpus comps (14%) reference local scripts missing
from the corpus fetch — their historical eval INIT timings measured this
timeout, not the engine. Capture-stage ratios remain valid (both paths paid
it equally).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
---
 packages/cli/src/commands/render.ts           |  1 +
 packages/cli/src/telemetry/events.ts          |  2 +
 .../frameCapture-subTimelinePoll.test.ts      | 66 ++++++++++++++
 packages/engine/src/services/frameCapture.ts  | 90 ++++++++++++++-----
 packages/engine/src/types.ts                  |  2 +
 .../src/services/render/perfSummary.ts        | 10 +++
 .../src/services/renderOrchestrator.ts        |  2 +
 7 files changed, 150 insertions(+), 23 deletions(-)
 create mode 100644 packages/engine/src/services/frameCapture-subTimelinePoll.test.ts

diff --git a/packages/cli/src/commands/render.ts b/packages/cli/src/commands/render.ts
index a07e1c988..08904c67c 100644
--- a/packages/cli/src/commands/render.ts
+++ b/packages/cli/src/commands/render.ts
@@ -1700,6 +1700,7 @@ function trackRenderMetrics(
     speedRatio,
     captureAvgMs: perf?.captureAvgMs,
     captureP50Ms: perf?.captureP50Ms,
+    subTimelineWait: perf?.subTimelineWait,
     videoCount: perf?.videoCount,
     capturePeakMs: perf?.capturePeakMs,
     tmpPeakBytes: perf?.tmpPeakBytes,
diff --git a/packages/cli/src/telemetry/events.ts b/packages/cli/src/telemetry/events.ts
index a6d017676..db4f30feb 100644
--- a/packages/cli/src/telemetry/events.ts
+++ b/packages/cli/src/telemetry/events.ts
@@ -148,6 +148,7 @@ export function trackRenderComplete(
     captureAvgMs?: number;
     /** Warmup-robust per-frame capture median (basis for speedup estimates). */
     captureP50Ms?: number;
+    subTimelineWait?: string;
     /** <video> element count (speedup segmentation: injection comps read lower). */
     videoCount?: number;
     capturePeakMs?: number;
@@ -221,6 +222,7 @@ export function trackRenderComplete(
       speed_ratio: props.speedRatio,
       capture_avg_ms: props.captureAvgMs,
       capture_p50_ms: props.captureP50Ms,
+      sub_timeline_wait: props.subTimelineWait,
       video_count: props.videoCount,
       capture_peak_ms: props.capturePeakMs,
       peak_memory_mb: props.peakMemoryMb,
diff --git a/packages/engine/src/services/frameCapture-subTimelinePoll.test.ts b/packages/engine/src/services/frameCapture-subTimelinePoll.test.ts
new file mode 100644
index 000000000..76efad4fe
--- /dev/null
+++ b/packages/engine/src/services/frameCapture-subTimelinePoll.test.ts
@@ -0,0 +1,66 @@
+/**
+ * pollSubCompositionTimelines fail-fast contract: a script resource that
+ * failed to load can never register its `window.__timelines[id]`, so the
+ * poll must cut to the short grace window instead of burning the full
+ * playerReadyTimeout (measured wild: a 705-render spike at the 45s setup
+ * bucket over 30 days — ~1% of local renders).
+ */
+
+import { describe, expect, it, vi } from "vitest";
+import type { Page } from "puppeteer-core";
+import { pollSubCompositionTimelines } from "./frameCapture.js";
+
+function makeMockPage(evaluateResults: (expr: string) => unknown): Page {
+  return {
+    evaluate: vi.fn(async (expr: string) => evaluateResults(expr)),
+  } as unknown as Page;
+}
+
+describe("pollSubCompositionTimelines fail-fast", () => {
+  it("returns ready and forces a timeline rebind when timelines register", async () => {
+    const page = makeMockPage(() => true);
+    const outcome = await pollSubCompositionTimelines(page, 1_000, 10);
+    expect(outcome).toBe("ready");
+    // Second evaluate is the __hfForceTimelineRebind call.
+    expect((page.evaluate as ReturnType<typeof vi.fn>).mock.calls.length).toBe(2);
+  });
+
+  it("bails after the grace window when a script resource failed to load", async () => {
+    const page = makeMockPage((expr) =>
+      expr.includes("__hfForceTimelineRebind") ? undefined : false,
+    );
+    const started = Date.now();
+    const outcome = await pollSubCompositionTimelines(
+      page,
+      60_000, // full timeout must NOT be waited
+      10,
+      () => ["http://localhost/animations.js"],
+      50, // grace
+    );
+    expect(outcome).toBe("script_failure");
+    expect(Date.now() - started).toBeLessThan(5_000);
+  });
+
+  it("waits the full timeout when timelines are missing but no script failed", async () => {
+    const page = makeMockPage(() => false);
+    const outcome = await pollSubCompositionTimelines(page, 120, 10, () => []);
+    expect(outcome).toBe("timeout");
+  });
+
+  it("keeps waiting through the grace window when failures appear but timelines register late", async () => {
+    let calls = 0;
+    const page = makeMockPage((expr) => {
+      if (expr.includes("__hfForceTimelineRebind")) return undefined;
+      calls++;
+      return calls >= 3; // registers on the 3rd poll tick, inside the grace window
+    });
+    const outcome = await pollSubCompositionTimelines(
+      page,
+      60_000,
+      10,
+      () => ["http://localhost/late.js"],
+      10_000, // generous grace — registration lands first
+    );
+    expect(outcome).toBe("ready");
+  });
+});
diff --git a/packages/engine/src/services/frameCapture.ts b/packages/engine/src/services/frameCapture.ts
index d017ea920..d23acdab2 100644
--- a/packages/engine/src/services/frameCapture.ts
+++ b/packages/engine/src/services/frameCapture.ts
@@ -95,6 +95,16 @@ export interface CaptureSession {
   pageReleased?: boolean;
   browserReleased?: boolean;
   browserConsoleBuffer: string[];
+  /**
+   * Script resources that failed to load (request failure or HTTP >= 400).
+   * pollSubCompositionTimelines fail-fasts on these: a comp whose timeline
+   * script 404'd can never register window.__timelines[id], so waiting the
+   * full playerReadyTimeout (45s) buys nothing (~1% of wild local renders
+   * were hitting that wall — a 705-render spike at the 45s setup bucket).
+   */
+  scriptLoadFailures: string[];
+  /** Outcome of the sub-composition timeline wait: ready | timeout | script_failure. */
+  subTimelineWaitOutcome?: "ready" | "timeout" | "script_failure";
   initTelemetry?: {
     initDurationMs: number;
     tweenCount: number;
@@ -899,6 +909,7 @@ export async function createCaptureSession(
     onBeforeCapture,
     isInitialized: false,
     browserConsoleBuffer: [],
+    scriptLoadFailures: [],
     capturePerf: {
       frames: 0,
       seekMs: 0,
@@ -971,21 +982,6 @@ export function formatConsoleDiagnostic(
   return { text: `${prefix} ${text}`, suppressHostLog: false };
 }
 
-async function pollPageExpression(
-  page: Page,
-  expression: string,
-  timeoutMs: number,
-  intervalMs: number = 100,
-): Promise<boolean> {
-  const deadline = Date.now() + timeoutMs;
-  while (Date.now() < deadline) {
-    const ready = Boolean(await page.evaluate(expression));
-    if (ready) return true;
-    await new Promise((resolve) => setTimeout(resolve, intervalMs));
-  }
-  return Boolean(await page.evaluate(expression));
-}
-
 const HF_READY_DIAGNOSTIC_EXPR = `(function() {
   var hf = window.__hf;
   var player = window.__player;
@@ -1121,11 +1117,19 @@ async function pollHfReady(page: Page, timeoutMs: number, intervalMs: number = 1
   );
 }
 
-async function pollSubCompositionTimelines(
+export async function pollSubCompositionTimelines(
   page: Page,
   timeoutMs: number,
   intervalMs: number = 150,
-): Promise<void> {
+  // Fail-fast hook: when a SCRIPT resource failed to load (404 / request
+  // failure), the timeline registration it carried can never arrive — the
+  // full-timeout wait buys nothing (measured: a 705-render spike at the 45s
+  // setup bucket in 30 days of wild local renders, ~1% of renders, each also
+  // shipping silently-broken animations). Once failures are present the poll
+  // is cut to `scriptFailureGraceMs` from its start.
+  getScriptLoadFailures?: () => readonly string[],
+  scriptFailureGraceMs: number = 2_000,
+): Promise<"ready" | "timeout" | "script_failure"> {
   // Hosts may opt out of the timeline wait with `data-no-timeline` —
   // compositions driven purely by CSS animations / rAF (the render-compat
   // contract) never register window.__timelines[id], and without the opt-out
@@ -1142,7 +1146,28 @@ async function pollSubCompositionTimelines(
     }
     return true;
   })()`;
-  const ready = await pollPageExpression(page, expression, timeoutMs, intervalMs);
+  const start = Date.now();
+  const deadline = start + timeoutMs;
+  let ready = false;
+  let scriptFailureBail = false;
+  for (;;) {
+    ready = Boolean(await page.evaluate(expression));
+    if (ready) break;
+    const now = Date.now();
+    if (now >= deadline) break;
+    const failures = getScriptLoadFailures?.() ?? [];
+    if (failures.length > 0 && now - start >= scriptFailureGraceMs) {
+      scriptFailureBail = true;
+      console.warn(
+        `[FrameCapture] Sub-composition timeline wait cut short after ${now - start}ms: ` +
+          `script resource(s) failed to load (${failures.join(", ")}) — ` +
+          `the timeline registration they carry can never arrive. ` +
+          `Fix the script reference; the render proceeds without those animations.`,
+      );
+      break;
+    }
+    await new Promise((resolve) => setTimeout(resolve, intervalMs));
+  }
   // Always force a timeline rebind once sub-composition timelines are
   // confirmed present. The previous implementation only called rebind
   // when the timeline count grew during the poll, which missed the case
@@ -1156,8 +1181,9 @@ async function pollSubCompositionTimelines(
         window.__hfForceTimelineRebind();
       }
     })()`);
+    return "ready";
   }
-  if (!ready) {
+  if (!scriptFailureBail) {
     const missing = await page.evaluate(`(function() {
       var hosts = document.querySelectorAll("[data-composition-id]");
       var timelines = window.__timelines || {};
@@ -1175,6 +1201,7 @@ async function pollSubCompositionTimelines(
         `Compositions intentionally driven without GSAP timelines (CSS animations / rAF) can mark the host with data-no-timeline to skip this wait.`,
     );
   }
+  return scriptFailureBail ? "script_failure" : "timeout";
 }
 
 async function pollVideosReady(
@@ -1381,6 +1408,9 @@ export async function initializeSession(session: CaptureSession): Promise<void>
   });
 
   page.on("requestfailed", (request) => {
+    if (request.resourceType() === "script") {
+      session.scriptLoadFailures.push(request.url());
+    }
     appendBrowserDiagnostic(
       session,
       formatRequestFailureDiagnostic({
@@ -1397,6 +1427,9 @@ export async function initializeSession(session: CaptureSession): Promise<void>
     if (status < 400) return;
 
     const request = response.request();
+    if (request.resourceType() === "script") {
+      session.scriptLoadFailures.push(response.url());
+    }
     appendBrowserDiagnostic(
       session,
       formatHttpErrorDiagnostic({
@@ -1461,8 +1494,13 @@ export async function initializeSession(session: CaptureSession): Promise<void>
     await pollHfReady(page, pageReadyTimeout);
     logInitPhase("pollHfReady complete");
 
-    await pollSubCompositionTimelines(page, pageReadyTimeout);
-    logInitPhase("pollSubCompositionTimelines complete");
+    session.subTimelineWaitOutcome = await pollSubCompositionTimelines(
+      page,
+      pageReadyTimeout,
+      undefined,
+      () => session.scriptLoadFailures,
+    );
+    logInitPhase(`pollSubCompositionTimelines complete (${session.subTimelineWaitOutcome})`);
 
     await applyVideoMetadataHints(page, session.options.videoMetadataHints);
     logInitPhase("applyVideoMetadataHints complete");
@@ -1596,8 +1634,13 @@ export async function initializeSession(session: CaptureSession): Promise<void>
     throw err;
   }
 
-  await pollSubCompositionTimelines(page, pageReadyTimeout);
-  logInitPhase("pollSubCompositionTimelines complete");
+  session.subTimelineWaitOutcome = await pollSubCompositionTimelines(
+    page,
+    pageReadyTimeout,
+    undefined,
+    () => session.scriptLoadFailures,
+  );
+  logInitPhase(`pollSubCompositionTimelines complete (${session.subTimelineWaitOutcome})`);
 
   await applyVideoMetadataHints(page, session.options.videoMetadataHints);
   logInitPhase("applyVideoMetadataHints complete");
@@ -3041,6 +3084,7 @@ export function getCapturePerfSummary(session: CaptureSession): CapturePerfSumma
     avgBeforeCaptureMs: Math.round(session.capturePerf.beforeCaptureMs / frames),
     avgScreenshotMs: Math.round(session.capturePerf.screenshotMs / frames),
     p50TotalMs: medianOf(session.capturePerf.frameMs),
+    subTimelineWaitOutcome: session.subTimelineWaitOutcome,
     staticDedupReused: session.staticDedupCount ?? 0,
     staticDedupEnabled: session.staticDedupEnabled ?? false,
     // armed ⟺ a non-empty static set survived verification; predicted === its size.
diff --git a/packages/engine/src/types.ts b/packages/engine/src/types.ts
index f2faa0651..204ea9bb1 100644
--- a/packages/engine/src/types.ts
+++ b/packages/engine/src/types.ts
@@ -183,6 +183,8 @@ export interface CapturePerfSummary {
    * averages). Basis for in-the-wild speedup estimates. 0 when no frames.
    */
   p50TotalMs: number;
+  /** Sub-composition timeline wait outcome: ready | timeout | script_failure (absent pre-init). */
+  subTimelineWaitOutcome?: string;
   /**
    * Frames served from the static-dedup cache instead of a real seek+screenshot
    * (opt-out HF_STATIC_DEDUP=false). 0 when dedup was off or never armed. NOT counted
diff --git a/packages/producer/src/services/render/perfSummary.ts b/packages/producer/src/services/render/perfSummary.ts
index 5dab95d24..1791129a9 100644
--- a/packages/producer/src/services/render/perfSummary.ts
+++ b/packages/producer/src/services/render/perfSummary.ts
@@ -189,6 +189,16 @@ export function buildRenderPerfSummary(input: {
               input.totalFrames,
           )
         : undefined,
+    subTimelineWait: (() => {
+      const outcomes = input.dedupPerfs
+        .map((p) => p.subTimelineWaitOutcome)
+        .filter((o): o is string => !!o);
+      if (outcomes.length === 0) return undefined;
+      // Worst outcome wins: script_failure > timeout > ready.
+      if (outcomes.includes("script_failure")) return "script_failure";
+      if (outcomes.includes("timeout")) return "timeout";
+      return "ready";
+    })(),
     captureP50Ms: (() => {
       // Per-frame median from the engine's samples; when parallel workers
       // report separately, take the busiest session's median.
diff --git a/packages/producer/src/services/renderOrchestrator.ts b/packages/producer/src/services/renderOrchestrator.ts
index ce3a95c9a..2e83ca497 100644
--- a/packages/producer/src/services/renderOrchestrator.ts
+++ b/packages/producer/src/services/renderOrchestrator.ts
@@ -322,6 +322,8 @@ export interface RenderPerfSummary {
    * captured the most frames when parallel workers report separately.
    */
   captureP50Ms?: number;
+  /** Worst sub-composition timeline wait outcome across sessions: ready | timeout | script_failure. */
+  subTimelineWait?: string;
   capturePeakMs?: number;
   captureCalibration?: {
     sampledFrames: number[];