perf(engine): extraction-phase instrumentation#444
Conversation
This stack of pull requests is managed by Graphite. Learn more about stacking. |
miguel-heygen
left a comment
There was a problem hiding this comment.
Review: perf(engine): extraction-phase instrumentation
Clean additive-only change — zero deletions, zero regression risk. The ExtractionPhaseBreakdown type is well-typed, the forward-looking cache placeholder fields (cacheHits, cacheMisses) avoid a type-breaking change in #446, and the sampleDirectoryBytes helper is defensively coded (iterative stack, error-swallowing).
P2 — Should fix
vfrPreflightMs subtraction creates asymmetric semantics.
breakdown.vfrPreflightMs = Date.now() - vfrPreflightStart - breakdown.vfrProbeMs;hdrPreflightMs wraps the entire HDR preflight block (probe + analysis + conversion), but vfrPreflightMs deliberately excludes probe time. A consumer looking at both *PreflightMs fields would expect analogous scopes. Either:
- (a) Rename to
vfrTranscodeMsto match what it actually measures, or - (b) Include probe time in
vfrPreflightMs(matchinghdrPreflightMs) — the separatevfrProbeMsalready provides the finer decomposition.
Option (b) is cleaner.
JSDoc references phase3ExtractMs but the field is named extractMs.
* - phase3ExtractMs wraps the parallel `extractVideoFramesRange` calls
P3 — Suggestions
- Test coverage is VFR-only. HDR-path fields (
hdrProbeMs,hdrPreflightMs,hdrPreflightCount) are never asserted — even a simpleexpect(...).toBeGreaterThanOrEqual(0)per field would catch initialization bugs. sampleDirectoryBytesfollows symlinks viastatSync. UsinglstatSyncand skipping symlinks would be more accurate for "bytes on disk in workDir." Minor since the workDir is engine-controlled.tmpPeakBytesreturns0when workDir is missing, but the type isnumber | undefined. Usingundefinedfor the missing-directory case would be more semantically precise.
Verdict: Approve with minor fixes
The instrumentation overhead is sub-ms (a handful of Date.now() calls). The design cleanly enables #445 and #446. Fix the vfrPreflightMs semantics and the JSDoc typo before merge.
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.
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).
76948c9 to
5cfabff
Compare
|
Pushed
On the P3s, kept as-is for this PR since they're orthogonal to the semantic fix:
All three would land clean in a single small follow-up PR; happy to do that after this stack merges so the downstream PRs aren't re-validated against moving semantics. |
The CLI already ships `render_complete` events to PostHog but only carries a subset of `RenderPerfSummary` (duration_ms, capture_avg_ms, etc.). With #444 adding per-phase breakdown and #446 adding cache counters, the data is sitting in `job.perfSummary.videoExtractBreakdown` and `job.perfSummary.tmpPeakBytes` but never reaching PostHog. This forwards the new fields as flat properties (flat is easier to query with PostHog insights than nested objects): - tmp_peak_bytes - stage_compile_ms, stage_video_extract_ms, stage_audio_process_ms, stage_capture_ms, stage_encode_ms, stage_assemble_ms - extract_resolve_ms, extract_hdr_probe_ms, extract_hdr_preflight_ms, extract_hdr_preflight_count, extract_vfr_probe_ms, extract_vfr_preflight_ms, extract_vfr_preflight_count, extract_phase3_ms, extract_cache_hits, extract_cache_misses `extract_phase3_ms` disambiguates from `stage_video_extract_ms`: the former is just the parallel ffmpeg extract inside Phase 3, the latter is the full stage (resolve + probe + preflight + extract). All fields optional — the Docker subprocess call site (no perfSummary available) still compiles and ships events without them.
The CLI already ships `render_complete` events to PostHog but only carries a subset of `RenderPerfSummary` (duration_ms, capture_avg_ms, etc.). With #444 adding per-phase breakdown and #446 adding cache counters, the data is sitting in `job.perfSummary.videoExtractBreakdown` and `job.perfSummary.tmpPeakBytes` but never reaching PostHog. This forwards the new fields as flat properties (flat is easier to query with PostHog insights than nested objects): - tmp_peak_bytes - stage_compile_ms, stage_video_extract_ms, stage_audio_process_ms, stage_capture_ms, stage_encode_ms, stage_assemble_ms - extract_resolve_ms, extract_hdr_probe_ms, extract_hdr_preflight_ms, extract_hdr_preflight_count, extract_vfr_probe_ms, extract_vfr_preflight_ms, extract_vfr_preflight_count, extract_phase3_ms, extract_cache_hits, extract_cache_misses `extract_phase3_ms` disambiguates from `stage_video_extract_ms`: the former is just the parallel ffmpeg extract inside Phase 3, the latter is the full stage (resolve + probe + preflight + extract). All fields optional — the Docker subprocess call site (no perfSummary available) still compiles and ships events without them.
miguel-heygen
left a comment
There was a problem hiding this comment.
Re-checked the live head. The vfrPreflightMs semantics and extractMs JSDoc fixes are in place, the latest CI is green, and I found no remaining blockers.

What
Adds per-phase timings and counters to
extractAllVideoFramesand surfaces them on the producer'sRenderPerfSummaryasvideoExtractBreakdownalongside a newtmpPeakBytesworkDir 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
videoExtractMsstage 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
ExtractionPhaseBreakdowntype withresolveMs,hdrProbeMs,hdrPreflightMs/Count,vfrProbeMs,vfrPreflightMs/Count,extractMs,cacheHits,cacheMisses. Populated inline withDate.now()wrappers — overhead is sub-millisecond on every phase.ExtractionResult.phaseBreakdown.RenderPerfSummarywithvideoExtractBreakdown?: ExtractionPhaseBreakdownandtmpPeakBytes?: number.tmpPeakBytesis 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 (buildHdrCaptureOptionsrefactor). Dropped that piece for a marginal observability loss.Test plan
Validation on
packages/producer/tests/vfr-screen-recording:Total elapsed within noise of pre-PR baseline (2665 → 2673 → 3228ms across hosts).
videoFrameExtractor.test.ts