feat(engine): opt-in per-frame timing on fast-capture fallback path

Field-signal baseline: >=2 fallbacks/hr on darwin/arm64 from filter:blur
and filter:drop-shadow triggers. Fallback path perf is currently untimed,
so we can't know if the overhead is 10% or 10x. This PR adds opt-in
per-frame timing (HF_PROFILE_FALLBACK_CAPTURE=true) that emits p50/p95/p99
+ trigger reason via the observeRenderStage telemetry channel extended in
#2510. Diagnostic surface only -- no perf fix, no behavior change on
healthy paths.

Stack: PR #9 (final) of 9 (base via/escape-hatch-fallback-reproducer).

Signed-off-by: Via

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

@@ -0,0 +1,274 @@
+/**
+ * Tests for the `capture_fallback_profile` observability emission — the
+ * diagnostic surface introduced with the fast-capture fallback profiling
+ * PR.
+ *
+ * Contract we're pinning here:
+ *   1. Env off (default) → no emission, regardless of whether the fallback
+ *      fired. Healthy renders and consumers that don't subscribe to the
+ *      diagnostic pay zero cost.
+ *   2. Env on + fallback fired → one checkpoint per fallback-engaged
+ *      session, with the shape the framing doc promises:
+ *      stagePhase / triggerReason / frameCount / captureTime{P50,P95,P99}Ms /
+ *      captureTimeAvgTotalMs.
+ *   3. Env on + fallback did NOT fire → no emission (drawElement renders
+ *      stay clean).
+ *   4. Multi-worker sessions produce multiple checkpoints (one per
+ *      fallback-engaged perf summary).
+ *   5. Full trigger fidelity (filter:blur vs filter:drop-shadow) is
+ *      preserved into the `triggerReason` field — the whole point of
+ *      the new `deFallbackTrigger` engine field.
+ */
+
+import type { CapturePerfSummary } from "@hyperframes/engine";
+import { describe, expect, it, vi } from "vitest";
+import { FALLBACK_PROFILE_ENV_VAR, emitFallbackCaptureProfile } from "./fallbackCaptureProfile.js";
+import { RenderObservabilityRecorder } from "./observability.js";
+
+function makeLog() {
+  return { error: vi.fn(), warn: vi.fn(), info: vi.fn(), debug: vi.fn() };
+}
+
+function makeRecorder(): {
+  recorder: RenderObservabilityRecorder;
+  log: ReturnType<typeof makeLog>;
+} {
+  const log = makeLog();
+  const recorder = new RenderObservabilityRecorder({
+    pipelineStartMs: Date.now(),
+    log,
+    renderJobId: "render-fallback-profile",
+  });
+  return { recorder, log };
+}
+
+/**
+ * Build a `CapturePerfSummary` with fallback-engaged fields set. The
+ * emitter reads `deFallbackTrigger` (preferred), `deGateReason`, `frames`,
+ * `p50TotalMs`, `p95TotalMs`, `p99TotalMs`, `avgTotalMs` — everything else
+ * can be zeroed out.
+ */
+function fallbackPerf(overrides: Partial<CapturePerfSummary>): CapturePerfSummary {
+  return {
+    frames: 180,
+    avgTotalMs: 45,
+    avgSeekMs: 0,
+    avgBeforeCaptureMs: 0,
+    avgScreenshotMs: 45,
+    p50TotalMs: 42,
+    p95TotalMs: 68,
+    p99TotalMs: 95,
+    staticDedupReused: 0,
+    staticDedupEnabled: false,
+    staticDedupArmed: false,
+    staticDedupPredicted: 0,
+    captureMode: "screenshot",
+    deGateReason: "css_effect:filter",
+    deFallbackTrigger: "filter:blur",
+    deWorkerEncode: false,
+    deVerifyArmed: 0,
+    deVerifyInitMs: 0,
+    deBoundaryFrames: 0,
+    deNcprFallbacks: 0,
+    ...overrides,
+  };
+}
+
+/**
+ * A `CapturePerfSummary` where drawElement ran end-to-end — no fallback
+ * fields set. The emitter should treat this as a no-op regardless of env.
+ */
+function drawElementPerf(overrides: Partial<CapturePerfSummary> = {}): CapturePerfSummary {
+  return {
+    frames: 180,
+    avgTotalMs: 12,
+    avgSeekMs: 0,
+    avgBeforeCaptureMs: 0,
+    avgScreenshotMs: 0,
+    p50TotalMs: 10,
+    p95TotalMs: 20,
+    p99TotalMs: 25,
+    staticDedupReused: 0,
+    staticDedupEnabled: false,
+    staticDedupArmed: false,
+    staticDedupPredicted: 0,
+    captureMode: "drawelement",
+    // deGateReason and deFallbackTrigger intentionally absent — drawElement ran.
+    deWorkerEncode: true,
+    deVerifyArmed: 3,
+    deVerifyInitMs: 400,
+    deBoundaryFrames: 0,
+    deNcprFallbacks: 0,
+    ...overrides,
+  };
+}
+
+function findFallbackCheckpoints(log: ReturnType<typeof makeLog>) {
+  return log.info.mock.calls.filter(
+    ([message, meta]) =>
+      message === "[Render:trace]" &&
+      typeof meta === "object" &&
+      meta !== null &&
+      "phase" in meta &&
+      meta.phase === "capture_fallback_profile",
+  );
+}
+
+describe("emitFallbackCaptureProfile", () => {
+  it("emits nothing when HF_PROFILE_FALLBACK_CAPTURE is unset, even if the fallback fired", () => {
+    const { recorder, log } = makeRecorder();
+    const emitted = emitFallbackCaptureProfile(recorder, [fallbackPerf({})], {});
+    expect(emitted).toBe(0);
+    expect(findFallbackCheckpoints(log)).toHaveLength(0);
+  });
+
+  it("emits nothing when HF_PROFILE_FALLBACK_CAPTURE is anything other than 'true'", () => {
+    const { recorder, log } = makeRecorder();
+    for (const value of ["1", "yes", "on", "false", ""]) {
+      emitFallbackCaptureProfile(recorder, [fallbackPerf({})], {
+        [FALLBACK_PROFILE_ENV_VAR]: value,
+      });
+    }
+    expect(findFallbackCheckpoints(log)).toHaveLength(0);
+  });
+
+  it("emits nothing when env is on but no session engaged the fallback path", () => {
+    const { recorder, log } = makeRecorder();
+    const emitted = emitFallbackCaptureProfile(recorder, [drawElementPerf(), drawElementPerf()], {
+      [FALLBACK_PROFILE_ENV_VAR]: "true",
+    });
+    expect(emitted).toBe(0);
+    expect(findFallbackCheckpoints(log)).toHaveLength(0);
+  });
+
+  it("emits ONE checkpoint per fallback-engaged perf summary when env is on", () => {
+    const { recorder, log } = makeRecorder();
+    const emitted = emitFallbackCaptureProfile(
+      recorder,
+      [
+        fallbackPerf({ deFallbackTrigger: "filter:blur", frames: 180 }),
+        drawElementPerf(),
+        fallbackPerf({ deFallbackTrigger: "filter:drop-shadow", frames: 120 }),
+      ],
+      { [FALLBACK_PROFILE_ENV_VAR]: "true" },
+    );
+    expect(emitted).toBe(2);
+    const checkpoints = findFallbackCheckpoints(log);
+    expect(checkpoints).toHaveLength(2);
+    expect(checkpoints[0]?.[1]).toEqual(
+      expect.objectContaining({
+        phase: "capture_fallback_profile",
+        status: "checkpoint",
+        stagePhase: "fallback-capture",
+        triggerReason: "filter:blur",
+        frameCount: 180,
+      }),
+    );
+    expect(checkpoints[1]?.[1]).toEqual(
+      expect.objectContaining({
+        phase: "capture_fallback_profile",
+        stagePhase: "fallback-capture",
+        triggerReason: "filter:drop-shadow",
+        frameCount: 120,
+      }),
+    );
+  });
+
+  it("emits the full percentile shape (p50/p95/p99 + avg + total)", () => {
+    const { recorder, log } = makeRecorder();
+    emitFallbackCaptureProfile(
+      recorder,
+      [
+        fallbackPerf({
+          frames: 180,
+          p50TotalMs: 42,
+          p95TotalMs: 68,
+          p99TotalMs: 95,
+          avgTotalMs: 45,
+        }),
+      ],
+      { [FALLBACK_PROFILE_ENV_VAR]: "true" },
+    );
+    const checkpoint = findFallbackCheckpoints(log)[0];
+    expect(checkpoint?.[1]).toEqual(
+      expect.objectContaining({
+        frameCount: 180,
+        captureTimeP50Ms: 42,
+        captureTimeP95Ms: 68,
+        captureTimeP99Ms: 95,
+        captureTimeAvgTotalMs: 45,
+      }),
+    );
+  });
+
+  it("prefers deFallbackTrigger over deGateReason for the triggerReason field", () => {
+    const { recorder, log } = makeRecorder();
+    emitFallbackCaptureProfile(
+      recorder,
+      [
+        fallbackPerf({
+          deGateReason: "css_effect:filter", // sanitized low-cardinality bucket
+          deFallbackTrigger: "filter:drop-shadow", // full-fidelity trigger
+        }),
+      ],
+      { [FALLBACK_PROFILE_ENV_VAR]: "true" },
+    );
+    const checkpoint = findFallbackCheckpoints(log)[0];
+    // The full-fidelity trigger wins — the whole point of the new field.
+    expect(checkpoint?.[1]).toEqual(
+      expect.objectContaining({ triggerReason: "filter:drop-shadow" }),
+    );
+  });
+
+  it("falls back to deGateReason when deFallbackTrigger is absent", () => {
+    const { recorder, log } = makeRecorder();
+    emitFallbackCaptureProfile(
+      recorder,
+      [
+        fallbackPerf({
+          deGateReason: "at_risk_timeline",
+          deFallbackTrigger: undefined,
+        }),
+      ],
+      { [FALLBACK_PROFILE_ENV_VAR]: "true" },
+    );
+    const checkpoint = findFallbackCheckpoints(log)[0];
+    expect(checkpoint?.[1]).toEqual(expect.objectContaining({ triggerReason: "at_risk_timeline" }));
+  });
+
+  it("tags the trigger in the human-readable message alongside the structured field", () => {
+    const { recorder, log } = makeRecorder();
+    emitFallbackCaptureProfile(recorder, [fallbackPerf({ deFallbackTrigger: "filter:blur" })], {
+      [FALLBACK_PROFILE_ENV_VAR]: "true",
+    });
+    const checkpoint = findFallbackCheckpoints(log)[0];
+    expect(checkpoint?.[1]).toEqual(
+      expect.objectContaining({
+        message: expect.stringContaining("filter:blur") as unknown as string,
+      }),
+    );
+  });
+
+  it("emits per-render on repeated invocations — each render call yields its own set", () => {
+    // Multi-composition batches share a recorder across compositions? No — each
+    // composition gets its own RenderObservabilityRecorder. Simulate a second
+    // render's recorder to prove there's no shared static state.
+    const first = makeRecorder();
+    emitFallbackCaptureProfile(
+      first.recorder,
+      [fallbackPerf({ deFallbackTrigger: "filter:blur" })],
+      { [FALLBACK_PROFILE_ENV_VAR]: "true" },
+    );
+    expect(findFallbackCheckpoints(first.log)).toHaveLength(1);
+
+    const second = makeRecorder();
+    emitFallbackCaptureProfile(
+      second.recorder,
+      [fallbackPerf({ deFallbackTrigger: "filter:drop-shadow" })],
+      { [FALLBACK_PROFILE_ENV_VAR]: "true" },
+    );
+    expect(findFallbackCheckpoints(second.log)).toHaveLength(1);
+    // The first recorder didn't get the second render's emission bleeding in.
+    expect(findFallbackCheckpoints(first.log)).toHaveLength(1);
+  });
+});

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

@@ -0,0 +1,119 @@
+import type { CapturePerfSummary } from "@hyperframes/engine";
+import type { RenderObservabilityRecorder } from "./observability.js";
+
+/**
+ * Opt-in per-frame timing summary emitted through the observability channel
+ * whenever a render's capture ran on the FAST-CAPTURE FALLBACK path
+ * (drawElement gated off → screenshot capture engaged).
+ *
+ * ── Why this exists ────────────────────────────────────────────────────────
+ * Field-signal baseline from `#hyperframes-cli-feedback` cron sweeps: on
+ * darwin/arm64 alone we see ≥2 fast-capture fallbacks/hr triggered by
+ * `filter:blur` / `filter:drop-shadow`. That is documented and correct
+ * behavior — drawElement can't reproduce those CSS effects and bails to
+ * screenshot per `packages/engine/docs/fast-capture-limitations.md` — but the
+ * fallback path's per-frame perf is currently *untimed* end-to-end. Session
+ * state carries `capturePerf.frameMs` and `getCapturePerfSummary()` emits a
+ * `p50TotalMs`, but no tail (p95/p99) and no per-render summary keyed on the
+ * specific trigger reaches downstream telemetry. Without that we can't
+ * characterize whether the fallback is a 10% tax or a 10× cliff — every
+ * future perf discussion is guesswork.
+ *
+ * ── What this emits ────────────────────────────────────────────────────────
+ * A single `capture_fallback_profile` checkpoint per render, per session that
+ * hit the fallback, containing:
+ *  • `stagePhase: "fallback-capture"` — string tag consumers can match on;
+ *  • `frameCount` — captured frames on this session's fallback path;
+ *  • `captureTimeP50Ms` / `captureTimeP95Ms` / `captureTimeP99Ms` — nearest-rank
+ *    per-frame capture-time percentiles (from `capturePerf.frameMs`);
+ *  • `captureTimeTotalMs` — cumulative session capture time
+ *    (session.capturePerf.totalMs);
+ *  • `message` — human-readable diagnostic prefix incorporating the trigger.
+ *
+ * Uses the SAME `RenderObservabilityRecorder.checkpoint()` primitive that
+ * `observeRenderStage` heartbeats and `stageStart`/`stageEnd` use (introduced
+ * in PR #2510). No new telemetry channel, no new sink.
+ *
+ * ── Why opt-in ────────────────────────────────────────────────────────────
+ * The percentile computation itself is trivially cheap (one sort per
+ * session), but *emitting* structured records into the observability stream
+ * is a downstream-consumer decision — enterprises that don't route
+ * `capture_fallback_profile` events shouldn't see unfamiliar phase names in
+ * their trace pipeline. `HF_PROFILE_FALLBACK_CAPTURE=true` lets operators
+ * opt into the diagnostic surface. Default off preserves current-shape
+ * telemetry for every caller that hasn't asked for the new signal.
+ *
+ * ── What this ISN'T ────────────────────────────────────────────────────────
+ * A perf fix. A behavior change on healthy paths. A new metric pipeline. It
+ * is *diagnostic groundwork*: once operators can collect real-world
+ * p50/p95/p99 keyed on the exact CSS trigger, we can decide whether the
+ * fallback-path perf is a design-decision-to-revisit or an acceptable
+ * trade-off. That decision is out of scope here.
+ */
+
+/** Env var operators set to opt into the diagnostic emission. */
+export const FALLBACK_PROFILE_ENV_VAR = "HF_PROFILE_FALLBACK_CAPTURE";
+
+/**
+ * Fallback path is considered "engaged" when EITHER a specific fallback
+ * trigger was recorded (populated at every fallback-gate branch alongside
+ * `deGateReason`) OR the engine's low-cardinality gate reason is set. Both
+ * conditions cover the same set today; checking both defends against a
+ * future gate that populates one but not the other.
+ */
+function fallbackEngaged(perf: CapturePerfSummary): boolean {
+  return Boolean(perf.deFallbackTrigger) || Boolean(perf.deGateReason);
+}
+
+/**
+ * Resolve the trigger string to emit. Prefers the full-fidelity
+ * {@link CapturePerfSummary.deFallbackTrigger} (e.g. `"filter:blur"`) so
+ * downstream consumers can distinguish `blur` from `drop-shadow`; falls back
+ * to the low-cardinality {@link CapturePerfSummary.deGateReason} when the
+ * fine-grained field is absent (defensive: unreachable in the shipping
+ * engine, but keeps the emitter total).
+ */
+function resolveTrigger(perf: CapturePerfSummary): string {
+  return perf.deFallbackTrigger ?? perf.deGateReason ?? "unknown";
+}
+
+/**
+ * Emit a `capture_fallback_profile` checkpoint per fallback-engaged capture
+ * summary. No-op when the env var is not `"true"` (default) or when the
+ * summary set has no fallback-engaged entries.
+ *
+ * Multi-composition batches produce multiple {@link CapturePerfSummary} in
+ * `perfSummaries` (one per worker session). Each fallback-engaged summary
+ * gets its own checkpoint — the emitter is *per-session*, not *per-render*
+ * — so cross-session divergence (e.g. one worker gated by `filter:blur`,
+ * another by `at_risk_timeline`) is visible individually. Downstream
+ * consumers can aggregate as needed.
+ *
+ * @param recorder Observability recorder for the current render.
+ * @param perfSummaries `CapturePerfSummary` collected from capture-stage sessions.
+ * @param env Env-var view (defaults to `process.env`) — injected for tests.
+ * @returns Count of checkpoints emitted (0 when opt-in is off or no fallback fired).
+ */
+export function emitFallbackCaptureProfile(
+  recorder: RenderObservabilityRecorder,
+  perfSummaries: readonly CapturePerfSummary[],
+  env: Readonly<Record<string, string | undefined>> = process.env,
+): number {
+  if (env[FALLBACK_PROFILE_ENV_VAR] !== "true") return 0;
+  let emitted = 0;
+  for (const perf of perfSummaries) {
+    if (!fallbackEngaged(perf)) continue;
+    const trigger = resolveTrigger(perf);
+    recorder.checkpoint("capture_fallback_profile", `fast-capture fallback profile (${trigger})`, {
+      stagePhase: "fallback-capture",
+      triggerReason: trigger,
+      frameCount: perf.frames,
+      captureTimeP50Ms: perf.p50TotalMs,
+      captureTimeP95Ms: perf.p95TotalMs,
+      captureTimeP99Ms: perf.p99TotalMs,
+      captureTimeAvgTotalMs: perf.avgTotalMs,
+    });
+    emitted++;
+  }
+  return emitted;
+}

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

@@ -170,6 +170,18 @@ const ALLOWED_STRING_DATA_KEYS = new Set([
   // from actual zero-frame stalls once capture is meant to be underway.
   // Field signal ts=1784019503.
   "stagePhase",
+  // Full-fidelity fast-capture fallback trigger — the specific reason
+  // drawElement gated off ("filter:blur", "filter:drop-shadow",
+  // "backdrop-filter", "clip-path", "at_risk_timeline", "swiftshader", …).
+  // Populated on the `capture_fallback_profile` checkpoint emitted by
+  // `fallbackCaptureProfile.ts` when the operator opts into
+  // `HF_PROFILE_FALLBACK_CAPTURE=true` so downstream metric consumers can
+  // characterize per-frame perf by the exact trigger. Complementary to
+  // `deGateReason`, which is the low-cardinality bucket for aggregation —
+  // this string preserves the fine-grained "which CSS property" for
+  // diagnostic reads. Sanitized like any observation message; low-cardinality
+  // by construction (bounded by the fallback-trigger enumeration).
+  "triggerReason",
 ]);
 const RESERVED_LOG_KEYS = new Set([
   "data",

packages/producer/src/services/renderOrchestrator.ts

@@ -132,6 +132,7 @@ import {
   type RenderObservationData,
   type RenderObservabilitySummary,
 } from "./render/observability.js";
+import { emitFallbackCaptureProfile } from "./render/fallbackCaptureProfile.js";
 import { type HdrPerfCollector, type HdrPerfSummary } from "./render/hdrPerf.js";
 import {
   assertVideoFrameCoverage,
@@ -3051,6 +3052,17 @@ export async function executeRenderJob(
       }
     } // end SDR capture paths block
 
+    // Opt-in per-frame timing summary for the fast-capture fallback path
+    // (drawElement → screenshot when composition uses filter:blur,
+    // filter:drop-shadow, clip-path, backdrop-filter, or hits any other
+    // fallback gate). Emits a `capture_fallback_profile` observability
+    // checkpoint per fallback-engaged session behind
+    // `HF_PROFILE_FALLBACK_CAPTURE=true`. No-op otherwise, and no-op
+    // when no session's capture engaged the fallback path — healthy
+    // (drawElement) renders pay zero overhead. See
+    // `fallbackCaptureProfile.ts` for the framing rationale.
+    emitFallbackCaptureProfile(observability, dedupPerfs);
+
     applyRenderWarningPolicy(
       job,
       [...layeredCaptureWarnings, ...dedupPerfs.flatMap((perf) => perf.warnings ?? [])],