fix(telemetry): expose stalled render stages

packages/cli/src/commands/render.test.ts

@@ -41,6 +41,7 @@ const trackingState = vi.hoisted(() => ({
   // `.ts` source under vitest — mocked here so the CLI-trial tests can
   // control it directly instead of inheriting that environment quirk.
   shouldTrack: true,
+  renderObservations: [] as Array<Record<string, unknown>>,
 }));
 
 const preflightState = vi.hoisted(() => ({
@@ -110,6 +111,9 @@ vi.mock("../telemetry/client.js", () => ({
 vi.mock("../telemetry/events.js", () => ({
   trackRenderComplete: vi.fn(),
   trackRenderError: vi.fn(),
+  trackRenderObservation: vi.fn((props: Record<string, unknown>) => {
+    trackingState.renderObservations.push(props);
+  }),
 }));
 
 vi.mock("../browser/ffmpeg.js", () => ({
@@ -154,6 +158,7 @@ describe("renderLocal browser GPU config", () => {
     configState.failWrites = 0;
     configState.writeConfigCalls = [];
     trackingState.shouldTrack = true;
+    trackingState.renderObservations = [];
     resetTrialState();
     savedEnv.clear();
     savedEnv.set("HYPERFRAMES_FFMPEG_PATH", process.env.HYPERFRAMES_FFMPEG_PATH);
@@ -199,6 +204,59 @@ describe("renderLocal browser GPU config", () => {
     });
   }, 15_000);
 
+  it("forwards render stage start and end lifecycle events to telemetry", async () => {
+    producerState.executeImpl = async (job) => {
+      const logger = (job.config as { logger: { info: (message: string, meta: object) => void } })
+        .logger;
+      logger.info("[Render:trace]", {
+        renderJobId: "render-lifecycle",
+        phase: "capture_streaming",
+        status: "start",
+        elapsedMs: 100,
+        workerCount: 1,
+        captureMode: "screenshot",
+        captureOperation: "captureScreenshot",
+        framesCompleted: 12,
+        totalFrames: 900,
+      });
+      logger.info("[Render:trace]", {
+        renderJobId: "render-lifecycle",
+        phase: "capture_streaming",
+        status: "end",
+        elapsedMs: 250,
+        durationMs: 150,
+      });
+    };
+
+    await renderLocal("/tmp/project", "/tmp/out.mp4", {
+      fps: { num: 30, den: 1 },
+      quality: "standard",
+      format: "mp4",
+      gpu: false,
+      browserGpuMode: "software",
+      hdrMode: "auto",
+      quiet: true,
+      skipFeedback: true,
+    });
+
+    expect(trackingState.renderObservations).toEqual([
+      expect.objectContaining({
+        renderJobId: "render-lifecycle",
+        phase: "capture_streaming",
+        status: "start",
+        captureOperation: "captureScreenshot",
+        framesCompleted: 12,
+        totalFrames: 900,
+      }),
+      expect.objectContaining({
+        renderJobId: "render-lifecycle",
+        phase: "capture_streaming",
+        status: "end",
+        durationMs: 150,
+      }),
+    ]);
+  });
+
   it("forwards browserGpuMode='auto' into producer config (probe-then-choose)", async () => {
     await renderLocal("/tmp/project", "/tmp/out.mp4", {
       fps: { num: 30, den: 1 },

packages/cli/src/commands/render.ts

@@ -1572,7 +1572,9 @@ function metaBoolean(meta: Record<string, unknown> | undefined, key: string): bo
 function trackRenderTraceFromLog(message: string, meta: Record<string, unknown> | undefined): void {
   if (message !== "[Render:trace]") return;
   const status = metaString(meta, "status");
-  if (status !== "checkpoint" && status !== "error") return;
+  if (status !== "start" && status !== "end" && status !== "checkpoint" && status !== "error") {
+    return;
+  }
   trackRenderObservation({
     source: "cli",
     renderJobId: metaString(meta, "renderJobId"),
@@ -1589,6 +1591,11 @@ function trackRenderTraceFromLog(message: string, meta: Record<string, unknown>
     usePageSideCompositing: metaBoolean(meta, "usePageSideCompositing"),
     hasHdrContent: metaBoolean(meta, "hasHdrContent"),
     captureMode: metaString(meta, "captureMode"),
+    captureOperation: metaString(meta, "captureOperation"),
+    framesCompleted: metaNumber(meta, "framesCompleted"),
+    totalFrames: metaNumber(meta, "totalFrames"),
+    heartbeatIndex: metaNumber(meta, "heartbeatIndex"),
+    stageElapsedMs: metaNumber(meta, "stageElapsedMs"),
     videoCount: metaNumber(meta, "videoCount"),
     extractedVideoCount: metaNumber(meta, "extractedVideoCount"),
     totalFramesExtracted: metaNumber(meta, "totalFramesExtracted"),

packages/cli/src/telemetry/events.test.ts

@@ -316,6 +316,12 @@ describe("render telemetry events", () => {
       phase: "capture_hdr_layered",
       status: "error",
       compositionHash: "abc123",
+      captureMode: "screenshot",
+      captureOperation: "captureScreenshot",
+      framesCompleted: 12,
+      totalFrames: 900,
+      heartbeatIndex: 1,
+      stageElapsedMs: 30_000,
       message: "Navigation failed for C:\\Users\\Alice\\project\\video.mov?not-a-query",
     });
 
@@ -324,6 +330,12 @@ describe("render telemetry events", () => {
       expect.objectContaining({
         render_job_id: "render-123",
         composition_hash: "abc123",
+        capture_mode: "screenshot",
+        capture_operation: "captureScreenshot",
+        frames_completed: 12,
+        total_frames: 900,
+        heartbeat_index: 1,
+        stage_elapsed_ms: 30_000,
         message: "Navigation failed for [path]",
       }),
     );

packages/cli/src/telemetry/events.ts

@@ -347,6 +347,11 @@ export function trackRenderObservation(props: {
   usePageSideCompositing?: boolean;
   hasHdrContent?: boolean;
   captureMode?: string;
+  captureOperation?: string;
+  framesCompleted?: number;
+  totalFrames?: number;
+  heartbeatIndex?: number;
+  stageElapsedMs?: number;
   videoCount?: number;
   extractedVideoCount?: number;
   totalFramesExtracted?: number;
@@ -373,6 +378,11 @@ export function trackRenderObservation(props: {
     use_page_side_compositing: props.usePageSideCompositing,
     has_hdr_content: props.hasHdrContent,
     capture_mode: props.captureMode,
+    capture_operation: props.captureOperation,
+    frames_completed: props.framesCompleted,
+    total_frames: props.totalFrames,
+    heartbeat_index: props.heartbeatIndex,
+    stage_elapsed_ms: props.stageElapsedMs,
     video_count: props.videoCount,
     extracted_video_count: props.extractedVideoCount,
     total_frames_extracted: props.totalFramesExtracted,

packages/producer/src/services/render/observability.test.ts

@@ -2,6 +2,7 @@ import { describe, expect, it, vi } from "vitest";
 import { CaptureStageError, getCaptureStageBrowserConsole } from "./captureStageError.js";
 import {
   computeCompositionObservabilityHash,
+  observeRenderStage,
   RenderObservabilityRecorder,
   sanitizeObservationMessage,
   summarizeBrowserDiagnostics,
@@ -95,6 +96,94 @@ describe("CaptureStageError", () => {
 });
 
 describe("RenderObservabilityRecorder", () => {
+  it("emits capped heartbeats while a stage is still running and stops after settlement", async () => {
+    vi.useFakeTimers();
+    const log = makeLog();
+    const recorder = new RenderObservabilityRecorder({
+      pipelineStartMs: Date.now(),
+      log,
+      renderJobId: "render-hang",
+    });
+    let resolveStage: (() => void) | undefined;
+    let framesCompleted = 0;
+    const stage = observeRenderStage(
+      recorder,
+      "capture_streaming",
+      {
+        workerCount: 1,
+        captureMode: "screenshot",
+        captureOperation: "captureScreenshot",
+        totalFrames: 900,
+        get framesCompleted() {
+          return framesCompleted;
+        },
+      },
+      () =>
+        new Promise<void>((resolve) => {
+          resolveStage = resolve;
+        }),
+    );
+
+    framesCompleted = 12;
+    await vi.advanceTimersByTimeAsync(30_000);
+    expect(log.info).toHaveBeenCalledWith(
+      "[Render:trace]",
+      expect.objectContaining({
+        phase: "capture_streaming",
+        status: "checkpoint",
+        message: "stage still running",
+        heartbeatIndex: 1,
+        stageElapsedMs: 30_000,
+        captureMode: "screenshot",
+        captureOperation: "captureScreenshot",
+        framesCompleted: 12,
+        totalFrames: 900,
+      }),
+    );
+
+    await vi.advanceTimersByTimeAsync(90_000);
+    const heartbeatCalls = log.info.mock.calls.filter(
+      ([message, meta]) => message === "[Render:trace]" && meta?.message === "stage still running",
+    );
+    expect(heartbeatCalls).toHaveLength(3);
+
+    resolveStage?.();
+    await stage;
+    await vi.advanceTimersByTimeAsync(240_000);
+    expect(
+      log.info.mock.calls.filter(
+        ([message, meta]) =>
+          message === "[Render:trace]" && meta?.message === "stage still running",
+      ),
+    ).toHaveLength(3);
+    vi.useRealTimers();
+  });
+
+  it("clears pending heartbeats when a stage rejects", async () => {
+    vi.useFakeTimers();
+    const log = makeLog();
+    const recorder = new RenderObservabilityRecorder({
+      pipelineStartMs: Date.now(),
+      log,
+      renderJobId: "render-error",
+    });
+
+    await expect(
+      observeRenderStage(recorder, "capture_disk", { workerCount: 2 }, async () => {
+        throw new Error("capture failed");
+      }),
+    ).rejects.toThrow("capture failed");
+    await vi.advanceTimersByTimeAsync(240_000);
+
+    expect(
+      log.info.mock.calls.some(
+        ([message, meta]) =>
+          message === "[Render:trace]" && meta?.message === "stage still running",
+      ),
+    ).toBe(false);
+    vi.useRealTimers();
+  });
+
   // fallow-ignore-next-line complexity
   it("records bounded phase events and summarizes browser diagnostics", () => {
     const log = makeLog();

packages/producer/src/services/render/observability.ts

@@ -118,6 +118,7 @@ const MAX_EVENTS = 160;
 const ALLOWED_STRING_DATA_KEYS = new Set([
   "browserGpuMode",
   "captureMode",
+  "captureOperation",
   "compositionHash",
   "effectiveHdr",
   "format",
@@ -370,11 +371,27 @@ export async function observeRenderStage<T>(
   fn: () => Promise<T>,
 ): Promise<T> {
   const startedAt = recorder.stageStart(phase, data);
+  const heartbeatTimers = [30_000, 60_000, 120_000].map((delayMs, index) => {
+    const timer = setTimeout(() => {
+      recorder.checkpoint(phase, "stage still running", {
+        ...data,
+        heartbeatIndex: index + 1,
+        stageElapsedMs: Date.now() - startedAt,
+      });
+    }, delayMs);
+    timer.unref?.();
+    return timer;
+  });
+  const clearHeartbeats = () => {
+    for (const timer of heartbeatTimers) clearTimeout(timer);
+  };
   try {
     const result = await fn();
+    clearHeartbeats();
     recorder.stageEnd(phase, startedAt);
     return result;
   } catch (error) {
+    clearHeartbeats();
     recorder.stageError(phase, startedAt, error);
     throw error;
   }

packages/producer/src/services/renderOrchestrator.test.ts

@@ -30,6 +30,7 @@ import {
   shouldDiscardProbeSessionForPageSideCompositing,
   resolveInversionRetryPlan,
   resolveParallelRouterRetryPlan,
+  resetCaptureAttemptProgress,
   shouldRetryViaPinnedFallback,
   shouldPreferParallelDrawElement,
   shouldPreferSingleWorkerDrawElement,
@@ -115,6 +116,14 @@ describe("extractStandaloneEntryFromIndex", () => {
 });
 
 describe("captureAttemptMadeProgress", () => {
+  it("resets completed frames before a fallback attempt starts", () => {
+    const job = { framesRendered: 900 };
+
+    resetCaptureAttemptProgress(job);
+
+    expect(job.framesRendered).toBe(0);
+  });
+
   it("retries when the attempt captured at least one frame toward its target", () => {
     // targeted 100 frames, 40 still missing -> 60 captured -> worth retrying the rest
     expect(captureAttemptMadeProgress(100, 40)).toBe(true);