perf(engine): extraction-phase instrumentation (#444)

## What

Adds per-phase timings and counters to `extractAllVideoFrames` and surfaces them on the producer's `RenderPerfSummary` as `videoExtractBreakdown` alongside a new `tmpPeakBytes` workDir size sample.

## Why

Phase 2 video extraction has five distinct sub-phases (resolve, HDR probe, HDR preflight, VFR probe, VFR preflight, per-video extract) and today they collapse into a single `videoExtractMs` stage timing. That makes every subsequent perf PR in this stack immeasurable — you can't tell whether a win came from cache hits, preflight scope reduction, or pure extraction speed.

This PR is foundational for PR #445 (segment-scope HDR preflight) and PR #446 (content-addressed extraction cache).

## How

- New `ExtractionPhaseBreakdown` type with `resolveMs`, `hdrProbeMs`, `hdrPreflightMs/Count`, `vfrProbeMs`, `vfrPreflightMs/Count`, `extractMs`, `cacheHits`, `cacheMisses`. Populated inline with `Date.now()` wrappers — overhead is sub-millisecond on every phase.
- Returned on `ExtractionResult.phaseBreakdown`.
- Producer extends `RenderPerfSummary` with `videoExtractBreakdown?: ExtractionPhaseBreakdown` and `tmpPeakBytes?: number`. `tmpPeakBytes` is sampled from the workDir right before cleanup via a new recursive-size helper that swallows errors (purely observational — a missing workDir must never fail the render).

No changes to the capture-lifecycle resource tracking — earlier versions of this instrumentation plumbed injector LRU stats through `RenderOrchestrator`, which conflicted hard with upstream #371 (`buildHdrCaptureOptions` refactor). Dropped that piece for a marginal observability loss.

## Test plan

Validation on `packages/producer/tests/vfr-screen-recording`:
```json
"videoExtractBreakdown": {
  "resolveMs": 0, "hdrProbeMs": 0, "hdrPreflightMs": 0, "hdrPreflightCount": 0,
  "vfrProbeMs": 0, "vfrPreflightMs": 166, "vfrPreflightCount": 1,
  "extractMs": 97, "cacheHits": 0, "cacheMisses": 0
},
"tmpPeakBytes": 4578598
```
Total elapsed within noise of pre-PR baseline (2665 → 2673 → 3228ms across hosts).

- [x] Unit test: phase-breakdown assertion added to `videoFrameExtractor.test.ts`
- [x] Lint + format (oxlint + oxfmt)
- [x] Typecheck (engine + producer)
- [x] Manual perf validation against VFR fixture
This commit is contained in:
James Russo
2026-04-23 23:54:56 -04:00
committed by GitHub
parent bcfaded48c
commit 31354d52da
5 changed files with 111 additions and 0 deletions
@@ -189,6 +189,11 @@ describe.skipIf(!HAS_FFMPEG)("extractAllVideoFrames on a VFR source", () => {
// Pre-fix behavior produced ~90 frames (a 25% shortfall).
expect(frames.length).toBeGreaterThanOrEqual(119);
expect(frames.length).toBeLessThanOrEqual(121);
expect(result.phaseBreakdown).toBeDefined();
expect(result.phaseBreakdown.extractMs).toBeGreaterThan(0);
expect(result.phaseBreakdown.vfrPreflightCount).toBe(1);
expect(result.phaseBreakdown.vfrPreflightMs).toBeGreaterThan(0);
}, 60_000);
// Asserts both frame-count correctness and that we don't emit long runs of
@@ -46,12 +46,42 @@ export interface ExtractionOptions {
format?: "jpg" | "png";
}
/**
* Per-phase timings and counters emitted by `extractAllVideoFrames`.
*
* Used by the producer to surface `perfSummary.videoExtractBreakdown` — without
* this breakdown, a single `videoExtractMs` stage timing hides where cost lives
* (HDR preflight, VFR preflight, per-video ffmpeg extract) when tuning renders.
*
* Field semantics:
* - *Ms fields are wall-clock durations inside each phase.
* - *Count fields report how many sources triggered that phase.
* - extractMs wraps the parallel `extractVideoFramesRange` calls; it
* reflects max-across-parallel-workers, not sum.
* - hdrPreflightMs / vfrPreflightMs both include their probe-time sibling
* (hdrProbeMs / vfrProbeMs) for symmetric semantics. The probe-only fields
* are a finer decomposition, not a separate carve-out.
*/
export interface ExtractionPhaseBreakdown {
resolveMs: number;
hdrProbeMs: number;
hdrPreflightMs: number;
hdrPreflightCount: number;
vfrProbeMs: number;
vfrPreflightMs: number;
vfrPreflightCount: number;
extractMs: number;
cacheHits: number;
cacheMisses: number;
}
export interface ExtractionResult {
success: boolean;
extracted: ExtractedFrames[];
errors: Array<{ videoId: string; error: string }>;
totalFramesExtracted: number;
durationMs: number;
phaseBreakdown: ExtractionPhaseBreakdown;
}
export function parseVideoElements(html: string): VideoElement[] {
@@ -375,8 +405,21 @@ export async function extractAllVideoFrames(
const extracted: ExtractedFrames[] = [];
const errors: Array<{ videoId: string; error: string }> = [];
let totalFramesExtracted = 0;
const breakdown: ExtractionPhaseBreakdown = {
resolveMs: 0,
hdrProbeMs: 0,
hdrPreflightMs: 0,
hdrPreflightCount: 0,
vfrProbeMs: 0,
vfrPreflightMs: 0,
vfrPreflightCount: 0,
extractMs: 0,
cacheHits: 0,
cacheMisses: 0,
};
// Phase 1: Resolve paths and download remote videos
const phase1Start = Date.now();
const resolvedVideos: Array<{ video: VideoElement; videoPath: string }> = [];
for (const video of videos) {
if (signal?.aborted) break;
@@ -408,14 +451,19 @@ export async function extractAllVideoFrames(
}
}
breakdown.resolveMs = Date.now() - phase1Start;
// Phase 2: Probe color spaces and normalize if mixed HDR/SDR
const phase2ProbeStart = Date.now();
const videoColorSpaces = await Promise.all(
resolvedVideos.map(async ({ videoPath }) => {
const metadata = await extractMediaMetadata(videoPath);
return metadata.colorSpace;
}),
);
breakdown.hdrProbeMs = Date.now() - phase2ProbeStart;
const hdrPreflightStart = Date.now();
const hdrInfo = analyzeCompositionHdr(videoColorSpaces);
if (hdrInfo.hasHdr && hdrInfo.dominantTransfer) {
// dominantTransfer is "majority wins" — if a composition mixes PQ and HLG
@@ -440,6 +488,7 @@ export async function extractAllVideoFrames(
try {
await convertSdrToHdr(entry.videoPath, convertedPath, targetTransfer, signal, config);
entry.videoPath = convertedPath;
breakdown.hdrPreflightCount += 1;
} catch (err) {
errors.push({
videoId: entry.video.id,
@@ -449,15 +498,19 @@ export async function extractAllVideoFrames(
}
}
}
breakdown.hdrPreflightMs = Date.now() - hdrPreflightStart;
// Phase 2b: Re-encode VFR inputs to CFR so the fps filter in Phase 3 produces
// the expected frame count. Only the used segment is transcoded.
const vfrPreflightStart = Date.now();
const vfrNormDir = join(options.outputDir, "_vfr_normalized");
for (let i = 0; i < resolvedVideos.length; i++) {
if (signal?.aborted) break;
const entry = resolvedVideos[i];
if (!entry) continue;
const vfrProbeStart = Date.now();
const metadata = await extractMediaMetadata(entry.videoPath);
breakdown.vfrProbeMs += Date.now() - vfrProbeStart;
if (!metadata.isVFR) continue;
let segDuration = entry.video.end - entry.video.start;
@@ -483,6 +536,7 @@ export async function extractAllVideoFrames(
// extraction must seek from 0, not the original mediaStart. Shallow-copy
// to avoid mutating the caller's VideoElement.
entry.video = { ...entry.video, mediaStart: 0 };
breakdown.vfrPreflightCount += 1;
} catch (err) {
errors.push({
videoId: entry.video.id,
@@ -490,8 +544,10 @@ export async function extractAllVideoFrames(
});
}
}
breakdown.vfrPreflightMs = Date.now() - vfrPreflightStart;
// Phase 3: Extract frames (parallel)
const phase3Start = Date.now();
const results = await Promise.all(
resolvedVideos.map(async ({ video, videoPath }) => {
if (signal?.aborted) {
@@ -531,6 +587,8 @@ export async function extractAllVideoFrames(
}),
);
breakdown.extractMs = Date.now() - phase3Start;
// Collect results and errors
for (const item of results) {
if ("error" in item && item.error) {
@@ -547,6 +605,7 @@ export async function extractAllVideoFrames(
errors,
totalFramesExtracted,
durationMs: Date.now() - startTime,
phaseBreakdown: breakdown,
};
}