fix(pump+compositor): take-3 starvation — deadline pacing + row-blit fast paths

Two defects made the producer 17x slow (37s record -> 2.1s/127-frame file,
rawvideo stamps by arrival): FramePump slept the FULL interval after each
render (period = render+submit+interval) and SceneCompositor did per-pixel
float sampling + Math.Round blends over all 2.07M master pixels, scanning the
whole destination per overlay (258ms avg render vs 1.5ms submit).

Both solutions are established, not invented — researched before coding per
the derivative-work rule:
- deadline pacing: OBS libobs/media-io/video-io.c video_thread (nextTick +=
  intervalTicks, sleep only the remainder, rebase on overrun, never burst)
- row blits: libyuv pattern (BSD-3, chromium.googlesource.com/libyuv/libyuv)
  — 1:1 aligned identity fast path, per-pixel alpha branch, integer
  fixed-point blend, overlay clipped to the intersection rect, skip the dead
  black pre-fill when the backdrop covers

ONE integration test: Pump_Paces_To_The_Deadline_Compensating_Render_Cost
(lands after a fake-seam lesson: pacing fakes must await, not complete
synchronously, or the pump loop runs inline on StartAsync and hangs vstest).
Clean build 0 warnings; FramePumpTests 10/10, SceneCompositor/SceneGraph/
SocialBar/StretchMath 20/20. Docs same commit: ai.md pipeline section,
TASKS.md TASK 18 (webcam-in-output + rename modal verified from take 3),
MyMistakes recipe, HANDOFF rewritten. Take 4 pending on the user's machine.
This commit is contained in:
2026-09-03 09:02:45 -07:00
parent 7fcb2ad3da
commit 716a77f61a
7 changed files with 306 additions and 75 deletions
+50 -55
View File
@@ -2,72 +2,67 @@
## Branch / Commit State
**`main`**, clean tree, **11 local commits NOT pushed** until the user's "commit and push" lands
with this file's commit (expect `main == origin/main` at handoff commit). Tonight's series
(newest first):
**`main`** — take-3 starvation fix commits land locally (see `git log`); push only when the user says so.
The take-3 audit itself happened 2026-09-02/03: user recorded take 3 (`Downloads\recordings\`, manually
renamed `llamacasty-recording-3.mp4`), ffprobe + `startup.log` + an extracted frame did the diagnosis.
- this commit — docs: HANDOFF rewrite
- `4509bef` — docs: record-OR-stream ruling, scheduling scope, SYNC provenance, playout declined
- `af0d372` — docs: take-two outcomes (arrival-stamping, resolver key, top-bar model, TASK 18 status)
- `89fee6c` — fix: webcam identity→device key + always-present Start + [light]LABEL[pill] order
- `97ffc42` — chore(pump): render/submit stage-timing stats, 5s windows
- `8dcaee0` — fix(encoder): stderr logging + any-exit-is-failure + resolver null logging
- `7f2bda8` — fix(audio): game meter × volume (`GameMeterHonestyTests`)
- `5ead064` — fix(audio): `_delayedMix` NRE — killed the "known failure", the hang, AND the log flood; LoopbackGain honest
- `5a1a3c5` — fix(18): stop ends everything — pills clear, failures roll back (`SessionTeardownTests`)
- `688682d` — feat(9): transition(complete) close-out (never existed before)
- `22b780e` — fix(ffmpeg): month-end re-pin (daily aged out → 404) + actionable wrap
## What the take-3 audit found
## What tonight was
- **37s recording → 2.1s file, 127 frames @60fps** = ~17x time-lapse, audio truncated to match
(ffmpeg's rawvideo demuxer was blocked on the starved video input, so only ~2.3s of audio was consumed).
The user's "webcam at 6x, garbled" = the same file-level time-compression, most visible on the webcam.
- **The stage-timing seam paid for itself in one line**: `17/300 frames per 5s, avg render 258.1ms,
avg submit 1.5ms` — the encoder/pipe was healthy; `SceneCompositor.Render` was the whole bottleneck.
- **Two defects, both fixed (2026-09-03)** — research-first (OBS `libobs/media-io/video-io.c` deadline
pacing + libyuv row-blit pattern; cited in the commit and `MyMistakes.md` recipe):
1. `FramePump` slept the FULL interval after each render → period = render+interval. Now an absolute
`nextTick += intervalTicks` deadline; on overrun rebase (no catch-up burst).
2. Per-pixel float sampling + `Math.Round` blends over all 2.07M master px; `BlitOverlay` scanned the
full destination per overlay. Now: 1:1 aligned row-walk fast path (alpha branch, integer fixed-point
blend), `BlitOverlay` clipped to the intersection, backdrop-cover skips the black pre-fill.
3. **Webcam-in-output VERIFIED** from the take-3 frame (bottom-right, border + social bar render too).
- Test: `Pump_Paces_To_The_Deadline_Compensating_Render_Cost` (records the requested wait via the pacing
seam). Per-class runs: FramePumpTests 10/10, SceneCompositor+SceneGraph+SocialBar+StretchMath 20/20.
Clean build 0 warnings. **Landmine found the hard way:** a pacing fake returning
`Task.CompletedTask` synchronously runs the whole pump loop on `StartAsync`'s continuation and HANGS
the vstest run — fakes must genuinely await (`Task.Delay(d, ct)`) or yield.
- Minor logged on take-3 stop: `FramePump: encoder stop failed: No process is associated` — cosmetic
teardown race (process already exited before StopAsync's kill); follow-up only if it grows teeth.
Creator's first native runs since the refactor: startup crash → fixed (3 stacked faults); PM audit →
v1-complete declaration + out-of-product list (TASKS.md file end); first-ever real recordings → the
recording pipeline now demonstrably produces H.264+AAC MP4s (`Downloads\recordings\`, ffmpeg cached
in `%APPDATA%\ytLlive\tools\`).
## OPEN — do next, in order
**Test suite: ZERO known failures** (audio class was the last — root-caused to an uninitialized
field; TASK 22's fault is recorded in its entry). Per-class Windows-host vstest runs everything
including RealApp; only the FULL suite hangs (WASAPI teardown — don't run it).
## OPEN — do tomorrow, in order
1. **Take 3 (user records ~30s, record-only):** read `%APPDATA%\ytLlive\startup.log` — the new
`FramePump stats: n/target frames per 5s, avg render Xms submit Yms` lines will name the stage
behind the ~2fps producer starvation (symptoms: short file + 30x time-lapse + garbled audio,
one cause — rawvideo stamps by arrival). Also check: webcam now IN the output (89fee6c),
meter follows the volume knob, Stop slides pills off + Start present, top bar grouping feels right.
Also: take-2's file stayed auto-named `ty-…-0000.mp4` — did the rename modal appear?
2. **Then code, one integration test per change:** starvation fix (from #1's data) → radio pills /
record-OR-stream enforcement (ruling captured in TASKS.md TASK 18; `BeginGoLive(alsoRecord)` dies)
→ top bar Option A **pending user approval** (his "still not correct" message predates tonight's
89fee6c — have him LOOK first) → empty-state ruling pending: disabled / rehearsal (my recommendation) /
default-record → SYNC slider placement ruling pending (feature is his, permanently; position is open).
3. **Un-asked questions** (don't nag, just have the answers ready): why-stupid confirmation on
simultaneous rec+stream was given (VOD copy + hardware drag) ✓; "other issues" from take 1/2 —
user mentioned them but never listed; take 2 preview questions.
1. **Take 4 (user records ~30s, record-only)** → ffprobe the file (expect frames ≈ 60×seconds, duration
≈ wall time) + read `startup.log` `FramePump stats` (expect `n/300`, `avg render` ≤ ~16ms). If n/300
climbs only to ~45-55: next slice is the 8.3MB/frame LOH allocation → pool the master buffer.
2. **Then code, one integration test per change** (queue from before, unchanged): radio pills /
record-OR-stream enforcement (TASK 18 ruling; `BeginGoLive(alsoRecord)` dies) → top bar Option A
**pending user approval** → empty-state ruling pending (disabled / rehearsal / default-record) →
SYNC slider placement ruling pending.
3. **Un-asked questions** (don't nag; answers ready): the recorder said the desktop capture "didn't last
long enough to tell quality" — take 4 fixes that; "other issues" from takes 1/2 never listed.
## State of the app
Boots clean, records clean-ish (starvation pending), preview honest, top bar reordered per spec,
webcam-key fixed but NEVER verified in a real recording until take 3. The user's layout DB is
intact (real C920 row confirmed by direct sqlite read — the 'test-camera' log lines are testhost
noise, both processes share startup.log).
Boots clean. Recording pipeline: render starvation fixed pending take-4 confirmation; webcam + social bar
confirmed IN the output. ffmpeg cached at `%APPDATA%\ytLlive\tools\` (month-end pin). Test suite per-class
green; do NOT run full-suite vstest (WASAPI teardown hang, pre-existing).
## Landmines
- testhost shares startup.log with the app — filter by time when triaging.
- Stale testhost/exe locks the DLL (MSB3027): `taskkill /F /IM ytLive.exe` / `testhost.exe` first.
- Do NOT run full-suite vstest (hangs); do NOT claim suite totals — per-class only.
- `AudioPipelineTests` is healthy now but was the "known failure" graveyard — any new failure
there means a live-loop regression; read the logged stack (catches now log WITH stack + 5s throttle).
- Real-`MainWindow` tests MUST use `LayoutPathOverride` + temp DB; `VolumePushOverride` seam exists
so volume-slider tests never touch the machine's speakers.
- verify.sh's full-suite step hangs from WSL — flow tonight: clean build (0 warnings) + per-class
vstest + scope-check, all through the Windows dotnet.exe host.
- ffmpeg pin: month-end rule recorded (TASKS.md); BtbN keeps dailies ~14 days.
- Stale testhost/exe locks the DLL (MSB3027): `taskkill /F /IM testhost.exe` / `ytLive.exe` first.
- Do NOT run full-suite vstest (hangs); do NOT claim suite totals — per-class only. verify.sh's step 2 IS
the full-suite hang — flow: clean build + per-class vstest + scope-check.
- Windows binaries (ffprobe/ffmpeg under `%APPDATA%\ytLlive\tools\`) need WINDOWS paths
(`C:\Users\...`), never `/mnt/c/...` — the mount path reads as "No such file or directory".
- Real-`MainWindow` tests MUST use `LayoutPathOverride` + temp DB; `VolumePushOverride` seam exists so
volume-slider tests never touch the machine's speakers.
- `AudioPipelineTests` was the "known failure" graveyard — a new failure there means a live-loop
regression; read the logged stack (throttled, with stack).
- Pacing-seam fakes must yield/await — synchronous completion runs the pump loop inline (see above).
## @ User note
No unsolicited roadmap/next-step lists — work the queue above, report what changed, keep responses
SHORT (his words, twice tonight: walls of text are not getting read). Good dog: one integration test
per change. Committing is expected; pushing on his word — tonight he said push with the handoff.
He does not want tangents acknowledged twice (rename question = noise; the ask was ALWAYS the recording).
Keep responses SHORT; work the queue; one integration test per change; committing is expected, pushing is
his word.