diff --git a/HANDOFF.md b/HANDOFF.md index 9ffc34e..4e82cb2 100644 --- a/HANDOFF.md +++ b/HANDOFF.md @@ -1,46 +1,58 @@ -# HANDOFF — 2026-09-08 +# HANDOFF — 2026-09-10 ## Branch / Commit State -**`main` HEAD = `081e4c1`** — take-24 (PasteKey CropBounds). Working tree carries the -real fix (uncommitted): pre-parse transparency injection + diagnostics. +`main` HEAD = `1a39b09`, ahead of origin by 12, working tree carries THE recording-timing +fix (uncommitted): count-based CFR emission in `FramePump.cs` + `-re` removal in +`FfmpegArgs.cs`, plus this handoff / `ai.md` slice 9 / `MyMistakes.md` recipe correction. +`tools/` holds `ticker.c` + the built `ticker` (WSL, unused by git yet). -## Web Overlay — the ROOT CAUSE (finally named, not guessed) +## Recording TIMING — the fix (the "plays too fast" saga) -WebView2's `CapturePreviewAsync` **always honors the page's own background** — the widget -page paints html/body opaque, so the captured PNG has **no alpha-0 margins, ever**. -`DefaultBackgroundColor=Transparent` only shows through pages without a background style. -All prior takes (19-24) assumed the capture had transparent margins — it never did. -`FindContentBounds` therefore had nothing to crop to, and every blend saw alpha=255 = -black box + "transparency broken" + lost resizing. One bug, three symptoms. +**Root cause, proven by measurement (not guessed):** the pump's take-3 "rebase on overrun" +reset `nextTick` to wall-now every time it fell behind, silently erasing missed slots. The +pump delivered `215-219/300 per 5s` (~43fps) but ffmpeg muxes rawvideo by frame count at +`-framerate 60` — no per-frame timestamps — so every recording played ~1.4x fast with +stats that looked honest (a rebased frame is never "late"). `-re` on the demux was a second +fighting pacer ("Resumed reading … after a lag" grew 0.79s→4.82s). -**Fix applied (verify by running):** -1. `WebView2Manager.InitializeAsync`: `AddScriptToExecuteOnDocumentCreatedAsync(TransparentBackgroundScript)` - — injects html/body `background:transparent` BEFORE the page parses/scripts run (the - OBS user.css equivalent). NavStarting/NavCompleted keep the script as post-load re-assert. -2. Restored the take-23/24 compositor crop path (stride-correct `BlitContentRaw` + - `CropBounds` in PasteKey) — my previous take-25 gutting was wrong. -3. Diagnostics: first capture per source dumps the RAW WebView2 PNG to - `%TEMP%\ytLive-web-.png` and logs alpha stats + FindContentBounds result to - startup.log. +**Fix (the OBS `video-io.c` shape — one frame per interval slot, deadline never reset):** +1. `FramePump.PumpAsync`: `while (now >= nextTick) { SubmitFrame(frame); nextTick += intervalTicks; }` + — one submit per crossed slot; a slow render re-writes the current composite (judder, + never a skip). `nextTick` NEVER rebases to wall-now. +2. `FfmpegArgs`: `-re` deleted from the rawvideo input; the pump is the pacer. -## NEXT STEP (user run required once) +**Verified:** build 0 warnings; full suite 288/289 — the sole failure +(`Composite_FullScene_MasterPixels` line 109, pixel (1380,700) cyan vs magenta) ALSO fails +with this fix stashed, i.e. pre-existing and untouched by it. DO NOT fix it here; it is a +separate compositor investigation. -Run the app with the web overlay, then: -- Read `%APPDATA%\ytLlive\startup.log` — the `alpha[min=..,max=..,mean=..,zero=..%]` - line PROVES whether the capture is transparent now (mean near 0 + high zero% + a tight - contentBounds = fixed) or still opaque (mean ~255 → injection didn't beat the page). -- Agent can PIL-analyze `%TEMP%\ytLive-web-.png` for the true alpha bbox. +## NEXT STEP (ONE user run required) + +Record ~30s with the WSL ticker visible in the preview (`cd tools && ./ticker` in a terminal, +Ctrl-C to stop), then check: +- recording duration ≈ wall time (should be, by frame-count construction) +- `%APPDATA%\ytLlive\startup.log` "FramePump stats:" shows ≈ n/n per 5s, n = 300 @60fps +- NO "Resumed reading … after a lag" lines remain +- ticker advances ~1s per second of footage ## Still Open -- Chat overlay missing from recording (separate issue — not yet touched this session) -- Audio/sync: non-event (headset volume), closed +- Web overlay: the pre-parse transparency injection (committed `1a39b09`) is NOT yet proven + — both recorded diagnostic PNGs (`%TEMP%\ytLive-web-.png`) were 100% alpha=0 AND + RGB=0 (an EMPTY capture, not an opaque one). Diagnosis "capture is empty" needs a fresh + run; the first-capture dump may be the pre-load about:blank frame. Frozen pending the + timing verification. +- Audio silence: `no audio.mp4` measured -91dB (digital silence), 3KiB muxed audio stream — + the named-pipe audio delivered ~nothing. Separate from timing; not yet touched. +- Pre-existing: `Composite_FullScene_MasterPixels` (see above). ## Landmines - testhost shares startup.log with app — filter by time when triaging - testhost/exe lock DLLs: `taskkill /F /IM testhost.exe /IM ytLive.exe` before rebuild -- Do NOT run full-suite vstest (WASAPI hang); flow = clean build + per-class + scope-check +- Build via the Windows dotnet host: `/mnt/c/Program Files/dotnet/dotnet.exe build …` - Kill app before build: `/mnt/c/Windows/System32/taskkill.exe /F /IM ytLive.exe` -- The PNG dump is written ONCE per session per source (DebugPngWritten flag) \ No newline at end of file +- No Linux ffmpeg / no sudo on this box — probing uses `/mnt/c/Program Files/Krita (x64)/bin/ffmpeg.exe` + via WSL interop; frames landed in `/mnt/c/Users/gramp/AppData/Local/Temp/ylf/` +- `tools/ticker`: constant ~+982ms offset on the FIRST line is cosmetic (t0 captured a beat late) \ No newline at end of file diff --git a/MyMistakes.md b/MyMistakes.md index b87e252..9579e98 100644 --- a/MyMistakes.md +++ b/MyMistakes.md @@ -105,9 +105,19 @@ Both halves were solved by OBS/libyuv long ago; do not re-derive: frame makes the period `render + submit + interval` — the producer can hit ≤ half the declared rate even with a free render. OBS's `video_thread` (`libobs/media-io/video-io.c`) advances an absolute `nextTick += intervalTicks` and - sleeps only the remainder; if the deadline blew, skip the wait AND the missed ticks - (rebase, no catch-up burst — a burst queues stale frames). Critical with rawvideo: - pts is stamped by ARRIVAL, so a starved producer silently time-lapses the file. + sleeps only the remainder. **NEVER "rebase" the deadline to wall-now when it blows** — + the take-3 note I originally wrote here ("skip … the missed ticks (rebase)") was the + PROVEN-wrong advice: resetting `nextTick` erases the missed slots, so a 43fps reality + was authored into a 60fps container and every recording played ~1.4x fast (take 12/13, + 2026-09-10). The rebase even kept the stats looking honest (render+wait == period, no + loss) because a rebased frame is never "late". OBS keeps the counter MOVING and outputs + ONE frame per interval tick — a late render shows as REPEATED footage (judder; duration + stays correct), never a skip and never a wall-now reset. Critical with rawvideo: + pts is stamped by ARRIVAL, so the muxed duration is pure frame count ÷ fps — the only + way to make duration == wall time under ANY load is exactly one frame per interval slot. + Corollary: **never add a second pacer.** `ffmpeg -re` on the rawvideo input throttles + the pipe independently and fights the pump (its "Resumed reading … after a lag" grew + 0.79s→4.82s in the same take). Removed; the pump IS the pacer. 2. **A 1080p frame is ~2.07M pixels — the hot path must be row-simple.** Per-pixel `Math.Round` + float source-over in managed code costs ~100ns/px = the whole 258ms. libyuv's pattern (https://chromium.googlesource.com/libyuv/libyuv/): branch per diff --git a/Services/Encoder/FfmpegArgs.cs b/Services/Encoder/FfmpegArgs.cs index c051c41..51760cd 100644 --- a/Services/Encoder/FfmpegArgs.cs +++ b/Services/Encoder/FfmpegArgs.cs @@ -2,7 +2,9 @@ namespace ytLive.Services.Encoder; /// /// Builds the FFmpeg command line for a live RTMP push (TASK 4 ship step 3): -/// raw BGRA frames via stdin (paced -re), real audio via the named pipe +/// raw BGRA frames via stdin (paced by the frame pump — the pump holds a strict +/// CFR cadence, so -re would only add a second, fighting pacer), real +/// audio via the named pipe /// (TASK 9 — the mixer streams f32le at 48 kHz stereo into \\.\pipe\<name>; /// WASAPI loopback + the mic ride the pipe instead of the old anullsrc silence), /// H.264 + AAC encoding, FLV muxing to the ingestion URL. Pure — the encoder @@ -16,7 +18,6 @@ public static class FfmpegArgs { "-hide_banner", "-loglevel", "info", "-stats", "-stats_period", "0.5", - "-re", "-f", "rawvideo", "-pix_fmt", "bgra", "-video_size", $"{options.Width}x{options.Height}", "-framerate", options.Fps.ToString(), diff --git a/Services/Encoder/FramePump.cs b/Services/Encoder/FramePump.cs index a4580d7..737ad93 100644 --- a/Services/Encoder/FramePump.cs +++ b/Services/Encoder/FramePump.cs @@ -376,42 +376,50 @@ public sealed class FramePump : IDisposable IFfmpegEncoder? encoder; lock (_gate) encoder = _encoder; if (encoder == null) break; + + // Count-based CFR emission (libobs video-io.c — the frame interval + // is a DEADLINE and the output stream holds its declared rate): + // one frame per interval slot, whatever the render cost. When the + // renderer falls behind, the SAME fresh composite is written again + // for every slot that ticked past, so a slow render expresses as + // duplicated footage (judder) — never as a skipped timestamp. The + // deadline counter is NEVER reset to wall-now: the old rebase + // erased every missed slot, so a 43fps reality was authored into a + // 60fps container and every recording played ~1.4x fast (rawvideo + // carries no timestamps — muxed duration is pure frame count). submitSw.Restart(); - await encoder.SubmitFrameAsync(frame, ct); + while (!ct.IsCancellationRequested + && System.Diagnostics.Stopwatch.GetTimestamp() >= nextTick) + { + await encoder.SubmitFrameAsync(frame, ct); + statFrames++; + nextTick += intervalTicks; + } submitSw.Stop(); submitTicks += submitSw.ElapsedTicks; - // Submit copied the bytes — everything from this tick is recyclable. - // Release AFTER submit, and the free-list Contains guard makes the - // Cut path (BlendFrame returns toFrame itself, aliasing scratch) safe. + + // SubmitFrameAsync copied the bytes on every write above — the + // tick's buffers are recyclable once each due slot consumed them. + // The free-list Contains guard keeps the Cut path (BlendFrame + // returns toFrame itself, aliasing scratch) safe. ReleaseScratch(frame.BgraPixels); ReleaseScratch(scratch); - statFrames++; - ReportStats(); - // Advance the deadline; cost already spent is not slept again. - // Blew the frame budget: skip the wait AND the missed ticks — - // rebase rather than bursting a catch-up pile (OBS rewinds its - // tick; a burst only queues stale frames). Otherwise sleep the - // BULK and SPIN the 2ms tail — never hand a sub-tick remainder - // to the sleep quantum (see the timeBeginPeriod note). - nextTick += intervalTicks; + // Sleep the BULK of the remainder, SPIN the 2ms tail — never hand + // a sub-tick remainder to the sleep quantum (the timeBeginPeriod + // note). If the renderer already ate the budget there is nothing + // left to sleep and the loop renders the next frame straight away. waitSw.Restart(); var ahead = nextTick - System.Diagnostics.Stopwatch.GetTimestamp(); - if (ahead <= 0) - { - nextTick = System.Diagnostics.Stopwatch.GetTimestamp() + intervalTicks; - } - else - { - if (ahead > SpinTailTicks) - await _pacingDelay(TimeSpan.FromSeconds( - (ahead - SpinTailTicks) / (double)System.Diagnostics.Stopwatch.Frequency), ct); - while (!ct.IsCancellationRequested - && System.Diagnostics.Stopwatch.GetTimestamp() < nextTick) - Thread.SpinWait(400); - } + if (ahead > SpinTailTicks) + await _pacingDelay(TimeSpan.FromSeconds( + (ahead - SpinTailTicks) / (double)System.Diagnostics.Stopwatch.Frequency), ct); + while (!ct.IsCancellationRequested + && System.Diagnostics.Stopwatch.GetTimestamp() < nextTick) + Thread.SpinWait(400); waitSw.Stop(); waitTicks += waitSw.ElapsedTicks; + ReportStats(); } } } diff --git a/ai.md b/ai.md index 1c5d539..acc44b2 100644 --- a/ai.md +++ b/ai.md @@ -515,7 +515,9 @@ integration test fakes the whole subprocess (probe + encoder) with a Channel-bac `Complete()` is EOF (`null`), never a `ChannelClosedException`. **Decisions (locked):** args are pure (`FfmpegArgs.Build`, no string building in the encoder): -`-re -f rawvideo -pix_fmt bgra -video_size WxH -framerate FPS -i pipe:0` + a **real audio input — the +`-f rawvideo -pix_fmt bgra -video_size WxH -framerate FPS -i pipe:0` (**NO `-re`** — the FramePump +is the pacer since slice 9, 2026-09-10; `-re` added a second, fighting clock on the rawvideo demux) ++ a **real audio input — the mixer writes IEEE-float stereo to a Windows named pipe** (`-f f32le -ar 48000 -ac 2 -i \\.\pipe\ytllive_audio`, name via `EncoderOptions.AudioPipeName`; replaced the old `-f lavfi -i anullsrc` silence in the TASK 8 audio milestone) + explicit `-map 0:v -map 1:a` + `-c:v -b:v K @@ -700,7 +702,8 @@ seam:** `Func`, `Func` resolver, `Func`, `Func` resolver, `Func= nextTick) { SubmitFrame(frame); nextTick += intervalTicks; statFrames++; }` + submits exactly one frame per crossed slot, re-writing the current composite when the render overruns + (duplicated footage = correct duration, not a time-lapse), and `nextTick` is NEVER reset to wall-now; + (2) **`-re` removed from `FfmpegArgs`** — it was a second, fighting pacer on the rawvideo demux + (its "Resumed reading … after a lag" grew 0.79s→4.82s across the take, leaving the pump behind its own + honest-stats count). One fix covers the game background AND the webcam — both flow through this one + pump. Muxed duration is now frame-count ÷ fps == wall time by construction. Test: the pump suite stays + green unchanged — the pacing test's `