From 9e406744804db742d1929c7c9fa727a302978251 Mon Sep 17 00:00:00 2001 From: James Date: Thu, 23 Apr 2026 15:59:35 +0000 Subject: [PATCH 1/2] perf(engine): extraction-phase instrumentation Adds per-phase timings and counters to `extractAllVideoFrames`: resolve, HDR probe/preflight, VFR probe/preflight, per-video extract, plus cacheHits/cacheMisses placeholders for the downstream cache PR. Surfaces them on `RenderPerfSummary.videoExtractBreakdown` and samples the render's `workDir` size into `tmpPeakBytes` right before cleanup. These are foundational for measuring every other perf PR in the stack. Overhead is zero (ten Date.now() calls across a multi-second phase). A VFR-fixture breakdown is asserted in videoFrameExtractor.test.ts. --- packages/engine/src/index.ts | 1 + .../src/services/videoFrameExtractor.test.ts | 5 ++ .../src/services/videoFrameExtractor.ts | 56 +++++++++++++++++++ .../src/services/renderOrchestrator.ts | 45 +++++++++++++++ .../src/services/videoFrameExtractor.ts | 1 + 5 files changed, 108 insertions(+) diff --git a/packages/engine/src/index.ts b/packages/engine/src/index.ts index 041418527..0bfc00bcc 100644 --- a/packages/engine/src/index.ts +++ b/packages/engine/src/index.ts @@ -122,6 +122,7 @@ export { type ExtractedFrames, type ExtractionOptions, type ExtractionResult, + type ExtractionPhaseBreakdown, } from "./services/videoFrameExtractor.js"; export { createVideoFrameInjector } from "./services/videoFrameInjector.js"; diff --git a/packages/engine/src/services/videoFrameExtractor.test.ts b/packages/engine/src/services/videoFrameExtractor.test.ts index eab82023e..84f59cff4 100644 --- a/packages/engine/src/services/videoFrameExtractor.test.ts +++ b/packages/engine/src/services/videoFrameExtractor.test.ts @@ -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 diff --git a/packages/engine/src/services/videoFrameExtractor.ts b/packages/engine/src/services/videoFrameExtractor.ts index b16627af9..f27f836c2 100644 --- a/packages/engine/src/services/videoFrameExtractor.ts +++ b/packages/engine/src/services/videoFrameExtractor.ts @@ -46,12 +46,39 @@ 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. + * - phase3ExtractMs wraps the parallel `extractVideoFramesRange` calls; it + * reflects max-across-parallel-workers, not sum. + */ +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 +402,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 +448,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 +485,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 +495,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 +533,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 +541,10 @@ export async function extractAllVideoFrames( }); } } + breakdown.vfrPreflightMs = Date.now() - vfrPreflightStart - breakdown.vfrProbeMs; // Phase 3: Extract frames (parallel) + const phase3Start = Date.now(); const results = await Promise.all( resolvedVideos.map(async ({ video, videoPath }) => { if (signal?.aborted) { @@ -531,6 +584,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 +602,7 @@ export async function extractAllVideoFrames( errors, totalFramesExtracted, durationMs: Date.now() - startTime, + phaseBreakdown: breakdown, }; } diff --git a/packages/producer/src/services/renderOrchestrator.ts b/packages/producer/src/services/renderOrchestrator.ts index 308bb85fd..574c68d3e 100644 --- a/packages/producer/src/services/renderOrchestrator.ts +++ b/packages/producer/src/services/renderOrchestrator.ts @@ -19,6 +19,7 @@ import { rmSync, readFileSync, readdirSync, + statSync, writeFileSync, copyFileSync, appendFileSync, @@ -28,6 +29,7 @@ import { type EngineConfig, resolveConfig, extractAllVideoFrames, + type ExtractionPhaseBreakdown, createFrameLookupTable, type VideoElement, FrameLookupTable, @@ -150,6 +152,41 @@ function getMaxFrameIndex(frameDir: string): number { return max; } +/** + * Sum file sizes under `dir` recursively. Used to report a `tmpPeakBytes` + * proxy in `RenderPerfSummary` right before workDir cleanup. Swallows errors + * because it's purely observational — a missing workDir or symlink loop must + * not fail the render. + */ +function sampleDirectoryBytes(dir: string): number { + let total = 0; + const stack: string[] = [dir]; + while (stack.length > 0) { + const current = stack.pop(); + if (!current) continue; + let entries: string[] = []; + try { + entries = readdirSync(current); + } catch { + continue; + } + for (const name of entries) { + const full = join(current, name); + try { + const st = statSync(full); + if (st.isDirectory()) { + stack.push(full); + } else if (st.isFile()) { + total += st.size; + } + } catch { + // ignore + } + } + } + return total; +} + // Diagnostic helpers used by the HDR layered compositor when KEEP_TEMP=1 // is set. They are pure (capture no state), so we keep them at module scope // to avoid re-creating closures per frame and to make them callable from @@ -237,6 +274,10 @@ export interface RenderPerfSummary { videoCount: number; audioCount: number; stages: Record; + /** Per-phase breakdown of the Phase 2 video extraction (resolve, HDR probe, HDR preflight, VFR probe/preflight, per-video extract). Undefined when the composition has no videos. */ + videoExtractBreakdown?: ExtractionPhaseBreakdown; + /** Bytes on disk in the render's workDir at assembly time (sampled before cleanup). Lets callers correlate peak temp usage with render duration. */ + tmpPeakBytes?: number; captureAvgMs?: number; capturePeakMs?: number; /** @@ -2552,6 +2593,8 @@ export async function executeRenderJob( const totalElapsed = Date.now() - pipelineStart; sampleMemory(); + const tmpPeakBytes = existsSync(workDir) ? sampleDirectoryBytes(workDir) : 0; + const perfSummary: RenderPerfSummary = { renderId: job.id, totalElapsedMs: totalElapsed, @@ -2566,6 +2609,8 @@ export async function executeRenderJob( videoCount: composition.videos.length, audioCount: composition.audios.length, stages: perfStages, + videoExtractBreakdown: extractionResult?.phaseBreakdown, + tmpPeakBytes, hdrDiagnostics: hdrDiagnostics.videoExtractionFailures > 0 || hdrDiagnostics.imageDecodeFailures > 0 ? { ...hdrDiagnostics } diff --git a/packages/producer/src/services/videoFrameExtractor.ts b/packages/producer/src/services/videoFrameExtractor.ts index 224e3b6ed..136c096fd 100644 --- a/packages/producer/src/services/videoFrameExtractor.ts +++ b/packages/producer/src/services/videoFrameExtractor.ts @@ -13,4 +13,5 @@ export { type ExtractedFrames, type ExtractionOptions, type ExtractionResult, + type ExtractionPhaseBreakdown, } from "@hyperframes/engine"; From 5cfabff36bfc5548f7a0cd320217a0dc7d12b999 Mon Sep 17 00:00:00 2001 From: James Russo Date: Thu, 23 Apr 2026 22:01:49 +0000 Subject: [PATCH 2/2] perf(engine): unify vfrPreflightMs semantics with hdrPreflightMs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Address Miguel's review feedback on #444: vfrPreflightMs was subtracting vfrProbeMs from the wall-clock measurement, creating asymmetric semantics vs hdrPreflightMs (which includes hdrProbeMs). A consumer looking at both *PreflightMs fields expects analogous scopes — the separate *ProbeMs fields already provide the finer decomposition. Also fix the JSDoc reference to phase3ExtractMs (the field is extractMs). --- packages/engine/src/services/videoFrameExtractor.ts | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/packages/engine/src/services/videoFrameExtractor.ts b/packages/engine/src/services/videoFrameExtractor.ts index f27f836c2..406d45cf1 100644 --- a/packages/engine/src/services/videoFrameExtractor.ts +++ b/packages/engine/src/services/videoFrameExtractor.ts @@ -56,8 +56,11 @@ export interface ExtractionOptions { * Field semantics: * - *Ms fields are wall-clock durations inside each phase. * - *Count fields report how many sources triggered that phase. - * - phase3ExtractMs wraps the parallel `extractVideoFramesRange` calls; it + * - 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; @@ -541,7 +544,7 @@ export async function extractAllVideoFrames( }); } } - breakdown.vfrPreflightMs = Date.now() - vfrPreflightStart - breakdown.vfrProbeMs; + breakdown.vfrPreflightMs = Date.now() - vfrPreflightStart; // Phase 3: Extract frames (parallel) const phase3Start = Date.now();