fix(web): web-layer capture cadence 10Hz → ~30Hz while recording — widget animations no longer play ~1/6 speed

The recording is 60fps but WebView2 capture was a blind 100ms DispatcherTimer = 10Hz;
each captured web frame repeated ~6x into the file caps web animation at the capture
rate, not the page's (user: 'the animation appears to be too slow').

- New CaptureScheduler (Services/CaptureScheduler.cs): per-session dispatcher timer
  that DROPS a tick while a capture is in flight (latest-wins, never queues) — the
  guard that makes a higher cadence safe: concurrent full-HD PNG CapturePreviewAsync
  calls (~10-30ms each, slow per WebView2Feedback#20) would stack CPU and publish
  stale-after-fresh. Effective cadence = max(interval, capture duration).
- Cadence: SetCaptureInterval(33) on record/stream start, (200) idle — applied via
  MainViewModel.Streaming.Operations.cs.
- De-throttle the hidden page: shared CoreWebView2Environment created BEFORE
  EnsureCoreWebView2Async with --disable-backgrounding-occluded-windows
  --disable-renderer-backgrounding --disable-features=CalculateNativeWinOcclusion.
  Off-screen WebView2 is a hidden page when the host window is unfocused/covered and
  Chromium then parks rAF and clamps timers to ~1s (WebView2Feedback#1172/#3070,
  Chrome-88 timer-throttling blog).
- Telemetry: first 30 captures per session log elapsed ms (PNG encode + decode) to
  startup.log — that decides whether ~30Hz stays or drops to ~20Hz; the FramePump
  drops frames (never time-lapses, slice 10) if UI-thread GC churn starves it.
- ONE test: CaptureScheduler_Drops_Ticks_While_Capture_InFlight_And_Resumes
  (deterministic TCS-driven, no WebView2 runtime). Suite 290/291 — sole failure the
  pre-existing compositor pixel test.
- Docs same-commit: ai.md slice 11, MyMistakes.md, HANDOFF.

References: https://github.com/MicrosoftEdge/WebView2Feedback/issues/1172
https://github.com/MicrosoftEdge/WebView2Feedback/issues/3070
https://github.com/MicrosoftEdge/WebView2Feedback/issues/20
https://developer.chrome.com/blog/timer-throttling-in-chrome-88
This commit is contained in:
2026-09-10 10:25:41 -07:00
parent ec7c734bdd
commit 5e78065c2d
7 changed files with 292 additions and 66 deletions
+70 -51
View File
@@ -1,66 +1,85 @@
# HANDOFF — 2026-09-10
# HANDOFF — 2026-09-10 (evening)
## Branch / Commit State
`main` HEAD = `c45cbc9` (slice 10 committed), **ahead of origin by 15, NOT pushing** —
**user ruling (2026-09-10): do not push until the web-overlay transparency AND audio
silence issues are addressed.** Both are open (see Still Open). Working tree clean.
`main` HEAD currently = `c45cbc9` (slice 10). **Slice 11 is uncommitted** in the working tree
(WebView2 capture cadence + de-throttle; see below). **ahead of origin by 16, NOT pushing** —
user ruling (2026-09-10): do not push until the web-overlay **transparency AND audio-silence**
issues are addressed. Both are open (see Still Open). Milestone tag `milestone-recording-timing`
(annotated) on `c45cbc9` — rollback point: `git reset --hard milestone-recording-timing`.
## The timing saga — where it stands
## Timing saga — CLOSED (verified)
- **slice 9 (committed `bd396e4`)** fixed the DURATION (count-based CFR, deadline never
rebased, `-re` removed): file length == wall time by frame-count construction.
- **But the CONTENT still hiccuped** — the creator read "1...23...4...56..." in the
recording, and the aggregates (301/300, uniform PTS, 15.6s wall vs 15.74s file) could
NOT see it. Root cause finally measured in `FfmpegEncoder.SubmitFrameAsync`: it BLOCKED
on `WriteAsync(8.3MB)+FlushAsync` when ffmpeg lagged the pipe, and slice 9's burst
`while` loop then re-wrote that SAME composite for every crossed slot — frozen runs.
- **slice 10 (current, uncommitted)** — the OBS `obs-encoder.c` shape:
1. `FfmpegEncoder.SubmitFrameAsync` is an ENQUEUE into a bounded `Channel<byte[]>`
(cap 120) drained by its own task; the pump NEVER blocks on the pipe.
2. Queue full → drop the NEWEST frame + count (`IFfmpegEncoder.DroppedFrames`).
Stop flushes the whole queue, then EOF.
3. Pump: ONE fresh composite per iteration (burst loop deleted) — no stale re-write.
4. **Burned-in frame counter** (the new judge, replaces the WSL ticker): 6-digit
dot-matrix strip, white box, bottom-right of every composite. Decoding the file
reads +1/frame; jumps = counted drops. Clock-independent.
5. Stats: `worst submit`, `dropped N`, `stalls K`; stall log names iterations > 2× interval.
- slice 9 `bd396e4`: duration == wall time (count-based CFR, deadline never rebased, `-re` removed).
- slice 10 `c45cbc9`: bounded `Channel` encoder queue + drop-newest policy + burned-in dot-matrix
frame counter (bottom-right). Verified on two takes (`ty-20260910-0949…-2.mp4`, 2383 frames 39.92s;
`ty-20260910-0957…-2.mp4`, 2270 frames 38.05s): **every frame decodes, counter advances +1/frame,
zero gaps/dups**. Content cadence both: median 2 frames, max gap 9, longest frozen run 8 (133ms).
User: "I think we're good on this issue" → **timing CLOSED.**
## NEXT STEP (ONE user run required — the take that closes timing)
## The web-overlay threads (the active push-gate work) — Slice 11 in tree
Record ~20s (WSL ticker visible in the preview is optional now — the burned counter is
the judge), then check:
- **decode the recording and read the bottom-right frame counter** (probe a few frames
widely spaced + the same region across a densely-sampled range): the number advances
**exactly +1 per frame**, jumping only where drops are countable
- `%APPDATA%\ytLlive\startup.log`: `FramePump stats:` ≈ n/n per 5s (n=300 @60fps),
`dropped 0`, `stalls 0`, `worst submit ≈ 1-3ms`
- NO "FramePump stall:" lines, NO frozen-content runs in the playback
- Extract a few frames around any suspicious moment and correlation-check the strip.
Two user-reframed symptoms converged on ONE root cause and one change is in the tree (uncommitted):
## Committed so far this session (before slice 10)
1. "The widget is an animated resource — the animation looks **too slow**."
2. (earlier) "image renders but the **transparent pixels are black**."
- `d212d5a` — tools: WSL ticker (`tools/ticker.c` + binary)
- `bd396e4` — fix(rec): CFR emission + `-re` removal + docs (ai.md slice 9, MyMistakes,
HANDOFF). Cites libobs video-io.c.
- Do NOT push until the user says (multi-commit local only).
Root cause of #1 (code-proven): the recording is 60fps, but the WebView2 capture loop was a blind
100ms `DispatcherTimer` = 10Hz → the widget's motion is sampled 6× under rate → repeated-frame
slow-mo. PLUS Chromium hidden-page throttling (rAF parked, timers→1s; WebView2Feedback#1172/#3070)
when the off-screen page's host window is unfocused/covered. #2 remains UNVERIFIED (the diagnostic
PNG+alpha log is bound to the FIRST capture ever = the initial about:blank doc, so it can never see
the widget — 5/5 sessions logged alpha=0 blank; instrument is blind, not the capture).
**Slice 11 (uncommitted, files below):**
- `Services/CaptureScheduler.cs` (new): per-session dispatcher timer that DROPS ticks while a
capture is in flight (latest-wins, never queues). Interval owner-configurable: 33ms recording /
200ms idle.
- `Services/WebView2Manager.cs`: scheduler replaces the raw timer; shared `CoreWebView2Environment`
created BEFORE `EnsureCoreWebView2Async` with `--disable-backgrounding-occluded-windows
--disable-renderer-backgrounding --disable-features=CalculateNativeWinOcclusion`
(`GetEnvironmentAsync`); `SetCaptureInterval(int)`; capture-cost telemetry (first 30 captures/
session → startup.log).
- `ViewModels/MainViewModel.Streaming.Operations.cs`: `SetCaptureInterval(33)` on record/stream
start, `(200)` on stop.
- `ytLive.Tests/WebView2ManagerTests.cs`: ONE test
`CaptureScheduler_Drops_Ticks_While_Capture_InFlight_And_Resumes` (deterministic TCS-driven, no
WebView2 runtime).
- Docs same commit: `ai.md` slice 11, `MyMistakes.md` recipe "web widget captured at 10Hz…".
Suite: 290/291 pass — sole failure the PRE-EXISTING `Composite_FullScene_MasterPixels` pixel
(1380,700) cyan-vs-magenta (out of scope; fails with any fix stashed).
## NEXT STEP (the take that closes the web animation speed)
1. Commit slice 11 (scope-check first; commit cites WebView2Feedback#1172/#3070/#20 + Chrome-88 blog).
2. Run a normal recording with the animated widget on screen for ~20s. Expected:
- startup.log: `capture #1..#30 … took Nms` lines (tell us the per-capture cost) — **this decides
whether 30Hz stays or drops to ~20Hz**; also `FramePump stats:` should show no new dropped-frame
growth vs before (GC-churn check).
- Widget animation ~2-3× closer to real-time (10→30Hz).
- If it only became jittery instead of fast: check the FramePump dropped-frame counters.
3. Then, separately, the TRANSPARENCY verification (still open): re-point the first-capture dump/
alpha-log at a POST-PAINT capture of the real widget document (currently bound to about:blank) —
the change that makes "are transparent margins real?" answerable. Intended next change.
## Still Open
- Web overlay: pre-parse transparency injection NOT yet proven — recorded diagnostic PNGs
(`%TEMP%\ytLive-web-<id>.png`) were 100% alpha=0 AND RGB=0 (an EMPTY capture). Frozen
pending the timing verification.
- Audio silence: silent audio (full-length, -91dB) in the take-15 file — the named-pipe
audio delivers ~nothing. Separate from timing; queued follow-up, NOT this change.
- WSL-ticker-under-heavy-load reliability check: informational (burned counter is judge).
- Pre-existing: `Composite_FullScene_MasterPixels` line 109 pixel (1380,700) — verbose
cyan-vs-magenta; fails with slice-9 stashed; untouched by both slices. Separate
compositor investigation. DO NOT fix in the timing work.
- **Web transparency UNVERIFIED** — the diagnostic instrument is blind (fires on about:blank); last
known visual state take-25 black box; user's "transparent pixels black" may be the opacity bug OR
the preview surface. Needs the post-paint instrument fix (above) then a take. Push gate reason #1.
- **Audio silence** — silent audio (−91dB full-length) in take-15; named-pipe audio delivers ~nothing.
Queued follow-up. Push gate reason #2.
- Pre-existing compositor pixel test failure (never in scope).
## 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
- Build via the Windows dotnet host: `/mnt/c/Program Files/dotnet/dotnet.exe build "C:\Users\gramp\Documents\Code\projects\ytLive\ytLive.csproj"`
- No Linux ffmpeg / no sudo on this box — probing uses `/mnt/c/Program Files/Krita (x64)/bin/ffmpeg.exe`
- `tools/ticker`: constant ~+982ms offset on the FIRST line is cosmetic (t0 a beat late)
- testhost shares startup.log with app — filter by time when triaging.
- Locked DLLs: `taskkill //F //IM testhost.exe //IM ytLive.exe` before rebuild.
- Build/tests via `/mnt/c/Program Files/dotnet/dotnet.exe build …` / `… vstest
"C:\Users\gramp\Documents\Code\projects\ytLive\ytLive.Tests\bin\Debug\net8.0-windows10.0.19041.0\ytLive.Tests.dll"`.
- Probing recordings: `/mnt/c/Program Files/Krita (x64)/bin/ffmpeg.exe` / `ffprobe.exe` (Windows-form paths).
- `tools/ticker`: constant ~+982ms offset on the FIRST line is cosmetic.
- WebView2Manager Ran into LOH churn worry: each capture allocs a BitmapImage raster (~8.3MB) that
is garbage per capture; at 30Hz that's ~250MB/s LOH on the UI thread → potential gen2 pauses
showing as FramePump dropped frames. Slice 12 candidate if the take's stats show it.