mirror of
https://github.com/heygen-com/hyperframes.git
synced 2026-09-03 12:54:29 +00:00
Merge pull request #2515 from heygen-com/via/fastcapture-fallback-profiling
feat(engine): opt-in per-frame timing on fast-capture fallback path
This commit is contained in:
+11
-1
@@ -110,4 +110,14 @@ RUN cd packages/producer && bunx tsx scripts/generate-font-data.ts
|
||||
|
||||
WORKDIR /app/packages/producer
|
||||
|
||||
ENTRYPOINT ["bunx", "tsx", "src/regression-harness.ts", "--", "--sequential"]
|
||||
# Skip fixtures tagged `transparency` (Chrome alpha-channel PSNR quirks not
|
||||
# reproducible on the CI image) and `field-signal-reproducer` (known-broken
|
||||
# fixture per PR #2512 — codifies a real bug awaiting a fix). Mirrors the
|
||||
# `--exclude-tags` in the local `test:regression*` scripts in
|
||||
# packages/producer/package.json so `bun run docker:test*` and the aws-lambda
|
||||
# smoke tests skip the same set. Docker CMD args from `docker run <image> ...`
|
||||
# are appended after these flags, so positional test names (e.g. shard args
|
||||
# `hdr-regression style-5-prod ...` in .github/workflows/regression.yml) still
|
||||
# resolve normally; the harness applies excludeTags whether testNames is empty
|
||||
# or non-empty (see discoverTestSuites in src/regression-harness.ts).
|
||||
ENTRYPOINT ["bunx", "tsx", "src/regression-harness.ts", "--", "--sequential", "--exclude-tags", "transparency,field-signal-reproducer"]
|
||||
|
||||
@@ -108,6 +108,7 @@ export {
|
||||
discardWarmupCapture,
|
||||
getCompositionDuration,
|
||||
getCapturePerfSummary,
|
||||
percentileOf,
|
||||
prepareCaptureSessionForReuse,
|
||||
type CaptureSession,
|
||||
isTransientBrowserError,
|
||||
|
||||
@@ -0,0 +1,90 @@
|
||||
/**
|
||||
* Tests for the `percentileOf` helper added alongside the fast-capture
|
||||
* fallback profiling diagnostic (PR: `feat(engine): opt-in per-frame
|
||||
* timing on fast-capture fallback path`).
|
||||
*
|
||||
* The helper feeds the `capture_fallback_profile` observability checkpoint
|
||||
* — a diagnostic-only surface that has to give reviewers of future fallback
|
||||
* perf regressions a *trustworthy* number, so the percentile math is
|
||||
* pinned by these tests rather than left as read-through-the-caller
|
||||
* behavior.
|
||||
*
|
||||
* Nearest-rank semantics were chosen to match the existing `medianOf` p50
|
||||
* helper (`sorted[Math.floor(sorted.length / 2)]`) so p50 and p95/p99 stay
|
||||
* comparable — an interpolated-percentile answer would differ from the p50
|
||||
* emission for small sample sets and make cross-percentile reads confusing.
|
||||
*/
|
||||
|
||||
import { describe, expect, it } from "vitest";
|
||||
import { percentileOf } from "./frameCapture.js";
|
||||
|
||||
describe("percentileOf", () => {
|
||||
it("returns 0 for empty samples (matches medianOf's empty behavior)", () => {
|
||||
expect(percentileOf([], 0.5)).toBe(0);
|
||||
expect(percentileOf([], 0.95)).toBe(0);
|
||||
expect(percentileOf([], 0.99)).toBe(0);
|
||||
});
|
||||
|
||||
it("returns the sole sample regardless of percentile for length-1 input", () => {
|
||||
expect(percentileOf([42], 0.5)).toBe(42);
|
||||
expect(percentileOf([42], 0.95)).toBe(42);
|
||||
expect(percentileOf([42], 0.99)).toBe(42);
|
||||
});
|
||||
|
||||
it("computes nearest-rank percentiles on a fixed 100-sample ramp (1..100)", () => {
|
||||
const samples = Array.from({ length: 100 }, (_, i) => i + 1);
|
||||
// floor(0.5 * 100) = 50 → sorted[50] = 51
|
||||
expect(percentileOf(samples, 0.5)).toBe(51);
|
||||
// floor(0.95 * 100) = 95 → sorted[95] = 96
|
||||
expect(percentileOf(samples, 0.95)).toBe(96);
|
||||
// floor(0.99 * 100) = 99 → sorted[99] = 100
|
||||
expect(percentileOf(samples, 0.99)).toBe(100);
|
||||
});
|
||||
|
||||
it("clamps p=1 (would land at length) to the last sample rather than out-of-range", () => {
|
||||
const samples = Array.from({ length: 100 }, (_, i) => i + 1);
|
||||
// floor(1.0 * 100) = 100 → clamped to sorted[99] = 100
|
||||
expect(percentileOf(samples, 1.0)).toBe(100);
|
||||
});
|
||||
|
||||
it("does not require pre-sorted input (sorts a shuffled sample set)", () => {
|
||||
const samples = [10, 3, 7, 1, 5, 9, 2, 8, 4, 6];
|
||||
// sorted = [1..10]; floor(0.5*10)=5 → sorted[5]=6
|
||||
expect(percentileOf(samples, 0.5)).toBe(6);
|
||||
// floor(0.95*10)=9 → sorted[9]=10
|
||||
expect(percentileOf(samples, 0.95)).toBe(10);
|
||||
// floor(0.99*10)=9 → sorted[9]=10
|
||||
expect(percentileOf(samples, 0.99)).toBe(10);
|
||||
});
|
||||
|
||||
it("does not mutate the caller's samples array", () => {
|
||||
const samples = [5, 3, 8, 1, 9, 2, 7, 4, 6];
|
||||
const snapshot = [...samples];
|
||||
percentileOf(samples, 0.95);
|
||||
expect(samples).toEqual(snapshot);
|
||||
});
|
||||
|
||||
it("rounds fractional millisecond samples the same way medianOf does", () => {
|
||||
// 100 ramped fractional samples 0.5, 1.5, 2.5, …, 99.5.
|
||||
const samples = Array.from({ length: 100 }, (_, i) => i + 0.5);
|
||||
// floor(0.5*100)=50 → sorted[50] = 50.5 → Math.round → 51
|
||||
expect(percentileOf(samples, 0.5)).toBe(51);
|
||||
// floor(0.95*100)=95 → sorted[95] = 95.5 → Math.round → 96
|
||||
expect(percentileOf(samples, 0.95)).toBe(96);
|
||||
});
|
||||
|
||||
it("distinguishes p95 from p99 on a heavy-tailed sample set", () => {
|
||||
// 95 samples at 40ms (steady-state) + 5 samples at 200ms (paint-heavy tail)
|
||||
// — a shape the fast-capture fallback path is expected to produce
|
||||
// (see `fallbackCaptureProfile.ts` framing for why p95≠p99 matters here).
|
||||
const steady = Array.from({ length: 95 }, () => 40);
|
||||
const tail = Array.from({ length: 5 }, () => 200);
|
||||
const samples = [...steady, ...tail];
|
||||
// sorted: [40 x95, 200 x5]; floor(0.5*100)=50 → 40
|
||||
expect(percentileOf(samples, 0.5)).toBe(40);
|
||||
// floor(0.95*100)=95 → sorted[95] = 200 (first of the tail)
|
||||
expect(percentileOf(samples, 0.95)).toBe(200);
|
||||
// floor(0.99*100)=99 → sorted[99] = 200
|
||||
expect(percentileOf(samples, 0.99)).toBe(200);
|
||||
});
|
||||
});
|
||||
@@ -179,6 +179,17 @@ export interface CaptureSession {
|
||||
deVerifyFrames?: Map<number, Buffer>;
|
||||
/** Low-cardinality init-gate reason when drawElement routed to baseline (telemetry). */
|
||||
deGateReason?: string;
|
||||
/**
|
||||
* Full trigger string when drawElement gated off to the screenshot fallback
|
||||
* path — preserves the specific CSS effect (`filter:blur`,
|
||||
* `filter:drop-shadow`, `backdrop-filter`, `clip-path`) that
|
||||
* {@link deGateReason} sanitizes down to a low-cardinality bucket. Populated
|
||||
* on the same fallback-gate branches as `deGateReason`; consumed by the
|
||||
* `capture_fallback_profile` observability checkpoint gated behind
|
||||
* `HF_PROFILE_FALLBACK_CAPTURE=true`. See
|
||||
* `packages/producer/src/services/render/fallbackCaptureProfile.ts`.
|
||||
*/
|
||||
deFallbackTrigger?: string;
|
||||
/** Wall-clock ms spent capturing self-verification ground truth at init (telemetry). */
|
||||
deVerifyInitMs?: number;
|
||||
/** Count of per-frame "No cached paint record" screenshot fallbacks (telemetry). */
|
||||
@@ -651,6 +662,7 @@ async function initDrawElementOrTransparentBackground(
|
||||
(!forceScreenshot || forceDE);
|
||||
if ((session.config?.useDrawElement ?? false) && supersampling) {
|
||||
session.deGateReason = "supersampling";
|
||||
session.deFallbackTrigger = "supersampling";
|
||||
console.log(
|
||||
"[engine] --experimental-fast-capture disabled for this render: drawElementImage " +
|
||||
"ignores deviceScaleFactor, so supersampled (DPR > 1) output uses screenshot capture.",
|
||||
@@ -658,6 +670,7 @@ async function initDrawElementOrTransparentBackground(
|
||||
}
|
||||
if ((session.config?.useDrawElement ?? false) && !supersampling && forceScreenshot) {
|
||||
session.deGateReason = "render_mode_hint";
|
||||
session.deFallbackTrigger = "render_mode_hint";
|
||||
console.log(
|
||||
"[engine] fast capture: falling back to screenshot — render-mode compatibility " +
|
||||
"hint forced screenshot capture (e.g. raw requestAnimationFrame composition).",
|
||||
@@ -707,6 +720,7 @@ async function initDrawElementOrTransparentBackground(
|
||||
});
|
||||
if (!supportsDrawElement) {
|
||||
session.deGateReason = "unsupported_chrome";
|
||||
session.deFallbackTrigger = "unsupported_chrome";
|
||||
console.log(
|
||||
`[engine] fast capture: falling back to ${session.launchCaptureMode} capture — ` +
|
||||
"this Chrome build does not implement canvas.drawElementImage (Dev/Canary-only " +
|
||||
@@ -732,6 +746,7 @@ async function initDrawElementOrTransparentBackground(
|
||||
const mode = resolveDrawElementCaptureMode(session.isSwiftShader, transparent);
|
||||
if (mode === "screenshot") {
|
||||
session.deGateReason = "swiftshader";
|
||||
session.deFallbackTrigger = "swiftshader";
|
||||
// Fall back to the browser's LAUNCH mode, not unconditionally to
|
||||
// "screenshot": on a BeginFrame-launched browser (Linux fast capture)
|
||||
// Page.captureScreenshot hangs for the full protocol timeout, while
|
||||
@@ -752,6 +767,11 @@ async function initDrawElementOrTransparentBackground(
|
||||
const cssFx = await detectCssEffectRisk(page);
|
||||
if (cssFx) {
|
||||
session.deGateReason = `css_effect:${(cssFx.split(":")[0] ?? "").replace(/[^a-z-]/gi, "")}`;
|
||||
// Full specific effect ("filter:blur" / "filter:drop-shadow" /
|
||||
// "backdrop-filter" / "clip-path") — `deGateReason` sanitizes
|
||||
// this to the low-cardinality prefix; `deFallbackTrigger` keeps
|
||||
// the fine-grained value for the diagnostic profile emission.
|
||||
session.deFallbackTrigger = cssFx;
|
||||
console.log(
|
||||
`[engine] fast capture: falling back to ${session.launchCaptureMode} capture — ` +
|
||||
`${cssFx} detected (drawElementImage cannot reproduce it; see fast-capture-limitations.md)`,
|
||||
@@ -786,6 +806,7 @@ async function initDrawElementOrTransparentBackground(
|
||||
);
|
||||
if (atRisk.size > 0 && atRiskFraction > fractionFloor) {
|
||||
session.deGateReason = "at_risk_timeline";
|
||||
session.deFallbackTrigger = "at_risk_timeline";
|
||||
console.log(
|
||||
`[engine] fast capture: falling back to ${session.launchCaptureMode} capture — ` +
|
||||
`${atRisk.size}/${totalFrames} frames animate a compositor-incompatible prop ` +
|
||||
@@ -803,6 +824,7 @@ async function initDrawElementOrTransparentBackground(
|
||||
const threeD = await initThreeDProjection(page);
|
||||
if (!forceDE && !threeD.ok) {
|
||||
session.deGateReason = "3d_init_failed";
|
||||
session.deFallbackTrigger = "3d_init_failed";
|
||||
console.log(
|
||||
`[engine] fast capture: falling back to ${session.launchCaptureMode} capture — ` +
|
||||
`3D projection init failed (${threeD.reason ?? "unknown"})`,
|
||||
@@ -3510,6 +3532,26 @@ function medianOf(samples: number[]): number {
|
||||
return Math.round(sorted[Math.floor(sorted.length / 2)] ?? 0);
|
||||
}
|
||||
|
||||
/**
|
||||
* Percentile of a positive-real sample set (nearest-rank; matches how the
|
||||
* existing {@link medianOf} p50 helper picks the middle index). `p` is a
|
||||
* fraction in [0, 1]; the sample at `floor(p * n)` (clamped to `[0, n-1]`)
|
||||
* is returned. Sample set is not mutated. Returns 0 for empty input, mirroring
|
||||
* the p50 helper.
|
||||
*
|
||||
* Used for the `capture_fallback_profile` observability checkpoint added in
|
||||
* the fast-capture fallback profiling PR: we already collect `capturePerf.frameMs`
|
||||
* per session, so computing p95/p99 is one sort + two lookups — cheap enough
|
||||
* to always compute alongside the existing p50, no separate opt-in path
|
||||
* needed for the math. The env gate lives at the emission site.
|
||||
*/
|
||||
export function percentileOf(samples: number[], p: number): number {
|
||||
if (samples.length === 0) return 0;
|
||||
const sorted = [...samples].sort((a, b) => a - b);
|
||||
const idx = Math.min(sorted.length - 1, Math.max(0, Math.floor(p * sorted.length)));
|
||||
return Math.round(sorted[idx] ?? 0);
|
||||
}
|
||||
|
||||
export function getCapturePerfSummary(session: CaptureSession): CapturePerfSummary {
|
||||
const frames = Math.max(1, session.capturePerf.frames);
|
||||
return {
|
||||
@@ -3519,6 +3561,8 @@ 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),
|
||||
p95TotalMs: percentileOf(session.capturePerf.frameMs, 0.95),
|
||||
p99TotalMs: percentileOf(session.capturePerf.frameMs, 0.99),
|
||||
subTimelineWaitOutcome: session.subTimelineWaitOutcome,
|
||||
warnings: session.warnings.map((warning) => ({
|
||||
...warning,
|
||||
@@ -3539,6 +3583,7 @@ export function getCapturePerfSummary(session: CaptureSession): CapturePerfSumma
|
||||
beginFrameHasDamage: session.beginFrameHasDamageCount,
|
||||
captureMode: session.captureMode,
|
||||
deGateReason: session.deGateReason,
|
||||
deFallbackTrigger: session.deFallbackTrigger,
|
||||
deWorkerEncode: session.workerEncodeEnabled ?? false,
|
||||
deVerifyArmed: session.deVerifyFrames?.size ?? 0,
|
||||
deVerifyInitMs: session.deVerifyInitMs ?? 0,
|
||||
|
||||
@@ -218,6 +218,22 @@ export interface CapturePerfSummary {
|
||||
* averages). Basis for in-the-wild speedup estimates. 0 when no frames.
|
||||
*/
|
||||
p50TotalMs: number;
|
||||
/**
|
||||
* 95th-percentile per-frame capture time (nearest-rank). Emitted alongside
|
||||
* p50 so the fast-capture-fallback-profile diagnostic (opt-in via
|
||||
* `HF_PROFILE_FALLBACK_CAPTURE=true`) can distinguish "steady-state slow"
|
||||
* from "long-tail spikes"; the p50 alone hides the tail on any sample set
|
||||
* with a heavy right-skew (typical of screenshot capture on GC pauses or
|
||||
* paint-heavy frames). 0 when no frames.
|
||||
*/
|
||||
p95TotalMs: number;
|
||||
/**
|
||||
* 99th-percentile per-frame capture time (nearest-rank). Same purpose as
|
||||
* `p95TotalMs` — the extreme-tail counterpart, useful for characterizing
|
||||
* the WORST frame you're likely to encounter on the fallback path. 0 when
|
||||
* no frames.
|
||||
*/
|
||||
p99TotalMs: number;
|
||||
/** Sub-composition timeline wait outcome (absent pre-init). */
|
||||
subTimelineWaitOutcome?: SubTimelineWaitOutcome;
|
||||
/** Correctness warnings observed before or during capture. */
|
||||
@@ -262,6 +278,18 @@ export interface CapturePerfSummary {
|
||||
* drawElement ran or was never attempted.
|
||||
*/
|
||||
deGateReason?: string;
|
||||
/**
|
||||
* Full-fidelity fallback trigger — the specific reason (CSS FX + property,
|
||||
* e.g. `filter:blur`, `filter:drop-shadow`, `backdrop-filter`, `clip-path`,
|
||||
* or an unsanitized gate name like `at_risk_timeline`, `swiftshader`,
|
||||
* `unsupported_chrome`, `render_mode_hint`, `supersampling`, `3d_init_failed`)
|
||||
* that gated drawElement off. Complementary to {@link deGateReason}, which
|
||||
* sanitizes down to a low-cardinality bucket for aggregation; this field
|
||||
* keeps the specific CSS FX so the `capture_fallback_profile` observability
|
||||
* checkpoint can characterize per-frame perf by the exact trigger. Undefined
|
||||
* when drawElement ran (no fallback) or was never attempted.
|
||||
*/
|
||||
deFallbackTrigger?: string;
|
||||
/** Worker-encode pipeline active (the drain that runs self-verification). */
|
||||
deWorkerEncode: boolean;
|
||||
/** Self-verification ground-truth samples armed at init (0 = verification off/skipped). */
|
||||
|
||||
@@ -0,0 +1,54 @@
|
||||
// Pure-function tests for `parseArgs()` in the regression harness. Pins the
|
||||
// `--exclude-tags` comma-parsing contract that the values baked into
|
||||
// `Dockerfile.test` and `packages/producer/package.json` test scripts depend
|
||||
// on. When someone changes the parser (e.g. to space-separated or repeated
|
||||
// flags) these tests + the invocation strings in the Dockerfile / package.json
|
||||
// must move together.
|
||||
|
||||
import { describe, expect, it } from "bun:test";
|
||||
import { parseArgs } from "./regression-harness.js";
|
||||
|
||||
// parseArgs reads from index 2 onwards (node + script name are argv[0..1]).
|
||||
const withProgram = (rest: string[]): string[] => ["node", "regression-harness.ts", ...rest];
|
||||
|
||||
describe("parseArgs() — --exclude-tags", () => {
|
||||
it("splits a single --exclude-tags argument on commas", () => {
|
||||
const opts = parseArgs(withProgram(["--exclude-tags", "transparency,field-signal-reproducer"]));
|
||||
expect(opts.excludeTags).toEqual(["transparency", "field-signal-reproducer"]);
|
||||
});
|
||||
|
||||
it("accepts a single tag with no comma", () => {
|
||||
const opts = parseArgs(withProgram(["--exclude-tags", "transparency"]));
|
||||
expect(opts.excludeTags).toEqual(["transparency"]);
|
||||
});
|
||||
|
||||
it("supports repeated --exclude-tags flags (accumulating)", () => {
|
||||
const opts = parseArgs(
|
||||
withProgram(["--exclude-tags", "transparency", "--exclude-tags", "field-signal-reproducer"]),
|
||||
);
|
||||
expect(opts.excludeTags).toEqual(["transparency", "field-signal-reproducer"]);
|
||||
});
|
||||
|
||||
it("matches the values baked into Dockerfile.test ENTRYPOINT and package.json scripts", () => {
|
||||
// Pins the exact string the Dockerfile.test ENTRYPOINT + package.json
|
||||
// `test:regression*` scripts pass. If either invocation site changes to
|
||||
// whitespace-separated or another delimiter, this test fails and forces
|
||||
// an audit of the parser at the same time.
|
||||
const opts = parseArgs(
|
||||
withProgram([
|
||||
"--sequential",
|
||||
"--exclude-tags",
|
||||
"transparency,field-signal-reproducer",
|
||||
"hdr-regression",
|
||||
]),
|
||||
);
|
||||
expect(opts.sequential).toBe(true);
|
||||
expect(opts.excludeTags).toEqual(["transparency", "field-signal-reproducer"]);
|
||||
expect(opts.testNames).toEqual(["hdr-regression"]);
|
||||
});
|
||||
|
||||
it("defaults excludeTags to an empty array when the flag is absent", () => {
|
||||
const opts = parseArgs(withProgram([]));
|
||||
expect(opts.excludeTags).toEqual([]);
|
||||
});
|
||||
});
|
||||
@@ -241,7 +241,10 @@ function formatResidualSuffix(residualRmsDb: number | null, error: string | unde
|
||||
return `, residualRMS: ${residualRmsDb.toFixed(2)} dBFS`;
|
||||
}
|
||||
|
||||
function parseArgs(argv: string[]): CliOptions {
|
||||
// Exported for unit testing (pinning `--exclude-tags` comma-parsing so the
|
||||
// values baked into `Dockerfile.test` and `packages/producer/package.json`
|
||||
// scripts keep matching the parser's contract).
|
||||
export function parseArgs(argv: string[]): CliOptions {
|
||||
const testNames: string[] = [];
|
||||
const excludeTags: string[] = [];
|
||||
let update = false;
|
||||
|
||||
@@ -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);
|
||||
});
|
||||
});
|
||||
@@ -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;
|
||||
}
|
||||
@@ -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",
|
||||
|
||||
@@ -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 ?? [])],
|
||||
|
||||
Reference in New Issue
Block a user