feat: signed A/V sync offset (−500..+500), negative advances by eating live stream head (OBS eat-head semantics)
Positive offsets still delay the whole mix via the delay line (lip-sync fix); negative offsets now ARM once at StartLive and drop |N| ms off the pipe's write head so audio events land earlier when audio runs BEHIND video. Slider relabeled AUDIO SYNC, Min −500, locked while live/recording (IsEditMode). LayoutStore and VM clamp to −500..500. OBS reference for eat-the-head negative sync: https://obsproject.com/kb/obs-studio/buffering-time (negative sync values pull audio earlier by discarding buffered player audio). Test: StartLive_NegativeOffset_AdvancesAudio_ByDroppingTheStreamHead (6x0.9 head must be eaten before 0.2 bed reaches the wire).
This commit is contained in:
+60
-120
@@ -1,143 +1,83 @@
|
||||
# HANDOFF — 2026-09-14 (AUDIO−VIDEO SYNC FIX SHIPPED: StartLive now clears the pre-live ring backlog)
|
||||
# HANDOFF — 2026-09-14 (SIGNED AUDIO SYNC ONLINE: −500..+500, negative advances by eating the stream head; slider locked while live/recording)
|
||||
|
||||
## Branch / Commit State
|
||||
|
||||
`main` HEAD = `5ba4d70`. Ahead of origin by **27 commits**. Working tree **dirty**:
|
||||
the sync fix is implemented + tests green below, HANDOFF/MyMistakes updated — NOT yet
|
||||
committed. **NOT pushing** — the prior no-push ruling (transparency + audio-silence) is
|
||||
clear on the first gate; the second was the sync issue, whose fix is now in the tree
|
||||
but the user has not greenlit a push. On-board next: verify a take, then decide.
|
||||
`main` HEAD = **`11a7af2`** (pre-live ring-backlog fix, committed, pushed NOT authorized).
|
||||
Working tree **dirty** with the signed-sync work below — NOT yet committed. **NOT pushing**
|
||||
(no-push ruling still in effect; the last two fixes — audio silence + ring backlog — are
|
||||
committed locally and the user has not greenlit a push).
|
||||
|
||||
Heads-up for any reader: the previous HANDOFF (a62a283 era) described webcam/audio/
|
||||
truncation fixes as **uncommitted** — that file was stale on arrival. They were
|
||||
actually already committed:
|
||||
DB now: **`Audio.SyncOffsetMs = 0`** (confirmed via sqlite3 this session — the creator slid
|
||||
the sync to 0 and the write finally stuck; sound is correct at 0). The 0.54s residual in the
|
||||
1128 take ≈ 300ms injected offset (leftover DB value) + ~240ms natural (partly webcam
|
||||
clap-quantization ±40–85ms, partly measurement).
|
||||
|
||||
- `724af14` fix: audio silence (idempotent `AudioSyncDelay.Configure`), webcam gray
|
||||
block (cbW/cbH default), truncated videos (SceneGraph split/static bake docs + FramePump probe)
|
||||
- `5ba4d70` docs: audio-sync offset measured ~367ms w/ 300 offset → "set SyncOffsetMs=0"
|
||||
## ✅ SHIPPED (this dirty tree) — signed audio sync, −500..+500
|
||||
|
||||
Build was green (0 warnings) and 295 tests passing at the prior session end; no code
|
||||
changed this session (analysis only).
|
||||
**What:** the audio-sync control is now a SIGNED offset. Positive = delay the mix (audio runs
|
||||
AHEAD of video — existing `AudioSyncDelay` behavior, unchanged and live-reactive). Negative =
|
||||
**advance** the audio (audio runs BEHIND video): OBS's "eat the head of the buffer" fix —
|
||||
the mixer drops the first |N| ms of the written stream at the pipe, re-anchoring the audio
|
||||
stream so every event lands |N| ms EARLIER relative to video.
|
||||
|
||||
## ✅ SHIPPED — pre-live capture ring backlog fix (2026-09-14)
|
||||
**Mechanism (AudioMixer):** `StartLive` arms `_advanceSamplesRemaining = |N| ms → samples` at
|
||||
go-live (a negative offset can only eat the HEAD of the stream; it is armed once, not
|
||||
live-reactive). `LiveLoopAsync` skips `min(budget, mixBuffer.Length)` samples off each write
|
||||
head while the budget lasts — the pipe writer accepts a partial chunk via `AsMemory(writeFrom)`.
|
||||
Positive path untouched (delay line still re-reads the Func every tick).
|
||||
|
||||
**Root cause:** `AudioMixer.Start()` begins mic and loopback capture at **app startup**
|
||||
for the level meters. The 2-second ring buffers (`_micBuffer` = 96k floats = 2.0s mono;
|
||||
`_loopbackBuffer` = 192k floats = 2.0s stereo) fill continuously with pre-live audio.
|
||||
`StartLive` → `LiveLoopAsync` drained from the ring's tail — the **oldest** sample —
|
||||
so every recorded event landed ~2.0s late in the audio track (fixed lag, scaled with
|
||||
time-since-app-launch, capped at ring depth).
|
||||
|
||||
**Fix:** `AudioMixer.StartLive()` now runs `_micBuffer.Clear(); _loopbackBuffer.Clear();`
|
||||
immediately after the pipe starts, before the drain task runs — the in-flight ≤10ms
|
||||
chunk loss is imperceptible and correct ("recording begins at go-live").
|
||||
**UI/plumbing:**
|
||||
- `MainViewModel.Audio.cs` — clamp `Math.Clamp(value, -500, 500)`, doc updated.
|
||||
- `LayoutStore.Settings.cs` — `LoadAudioSyncOffsetMs`/`SaveAudioSyncOffsetMs` clamp −500..500.
|
||||
- `PreviewPane.xaml` — label **SYNC → "AUDIO SYNC"**, `Minimum="-500"`, tooltip explains both
|
||||
directions (calibrate with a clap: clap late → negative; early → positive), and
|
||||
**`IsEnabled="{Binding IsEditMode}"`** — the slider locks during live AND recording (gun
|
||||
safety, same property `IsRecording`/`StreamStatus` already raise PropertyChanged for).
|
||||
- `AudioSyncDelay` unchanged (still clamps negative→0 internally; header doc updated to point
|
||||
at the mixer for the advance side).
|
||||
|
||||
**Regression test (the ONE integration test for this change):**
|
||||
`StartLive_DiscardsPreLiveBacklog_SoFirstAudioIsCurrent` in
|
||||
`ytLive.Tests/AudioPipelineTests.cs` — saturates the loopback ring with stale 0.8
|
||||
(simulated pre-live meters), StartLive, then emits fresh 0.2; asserts the wire carries
|
||||
~0.2 (max < 0.3), failing loudly if the stale 0.8 backlog survived the clear.
|
||||
`StartLive_NegativeOffset_AdvancesAudio_ByDroppingTheStreamHead` in `AudioPipelineTests.cs` —
|
||||
−40 ms advance (8-tick budget at 5ms interval), emits 6×0.9 fresh right after StartLive (≤
|
||||
budget, so the head MUST be eaten) then a long 0.2 bed; asserts the wire max ≈ 0.2 (< 0.3).
|
||||
Fails loudly if −N no longer drops the head (0.9 leaks).
|
||||
|
||||
**Test collateral:** the 3 existing pipe-emit tests pre-filled the rings BEFORE
|
||||
StartLive (relying on the bug as a reservoir). Their emits now land right after
|
||||
StartLive (post-clear, pre-connect — the pipe drops pre-connect writes, so this keeps
|
||||
the ring primed for the client) with the 2026-09-14 comments updated. All passed.
|
||||
**User directives (this session):**
|
||||
- Signed −500..+500 with positive=delay / negative=advance, relabel "AUDIO SYNC", default 0.
|
||||
- **Lock the sync control when live or recording** (done — `IsEditMode`).
|
||||
- **NOTE ONLY, no fix:** the live recording is completely different from the "recording
|
||||
results" shown in Chat view (recorded in `bugs.md` — do not rediscover as a surprise).
|
||||
- **Before 1.0:** write a detailed USER-DOC tutorial on the audio-sync feature (see TASKS.md
|
||||
note; add it to the gold-pass/1.0 checklist). `docs/` currently holds only the README image.
|
||||
|
||||
Verified: `AudioPipelineTests` 26/26 green. Room-native build 0 warnings. Full gate
|
||||
pending (verify.sh clean build + full suite + scope check).
|
||||
## Take verification so far (ring-backlog fix)
|
||||
|
||||
### Read/Write semantics confirmed (AudioRingBuffer.cs)
|
||||
|
||||
Thread-safe via `_sync`: Write evicts oldest when full; Read returns from
|
||||
`tail = (_head - _count + C) % C` — when full `tail == _head`, so every drained sample
|
||||
is one lap behind the last write. `Clear()` is locked; it is the right seam.
|
||||
|
||||
**Root cause (confirmed two independent takes):** `AudioMixer.Start()` begins mic and
|
||||
loopback capture at **app startup** for the level meters. The 2-second ring buffers
|
||||
(`_micBuffer` = 96k floats = 2.0s mono; `_loopbackBuffer` = 192k floats = 2.0s stereo)
|
||||
fill continuously with pre-live audio. `StartLive` → `LiveLoopAsync` drains from the
|
||||
ring's tail — the **oldest** sample, which is the moment-of-go-live sample minus the
|
||||
full ring depth — so every recorded event appears ~2.0s late in the audio track. The
|
||||
lag is **fixed** for the entire recording and scales linearly with "how long the app was
|
||||
open before you hit record", capped at the 2.0s ring depth (plus the configured sync
|
||||
offset plus ~0.1s encoder pipeline).
|
||||
|
||||
**Read/Write semantics confirmed** in `AudioRingBuffer.cs` (thread-safe via `_sync`):
|
||||
Write evicts oldest samples when full (`_count == _buffer.Length`); Read returns from
|
||||
`tail = (_head - _count + C) % C` — when full, `tail == _head`, meaning every drained
|
||||
sample is exactly one lap behind what was last written. `Clear()` exists and is locked;
|
||||
it is the right seam.
|
||||
|
||||
**Only one Clear call exists** in the capture path: `RestartMic()` (AudioMixer.cs:132)
|
||||
clears `_micBuffer` on device swap. **Neither buffer is cleared at `StartLive`** — this
|
||||
is the bug.
|
||||
|
||||
**Taking:** the lag also explains the earlier 13:58 take that measured only ~367ms
|
||||
with 300ms offset active: the app had just been restarted for that take, so the rings
|
||||
were only partially pre-filled (lag = min(2.0s, time-since-app-launch)). Two takes
|
||||
hours later (rings fully saturated) reproduce the full ~2.0s backlog consistently.
|
||||
|
||||
---
|
||||
|
||||
**Take 1** (ty-20260912-1923-0000-2.mp4, talking + 3 claps):
|
||||
- Audio 17.25s, video 17.05s (1023 frames), no frame drops — NOT truncated.
|
||||
- Per-clap offsets: +2.16 / +2.18 / +2.15s (audio later). Cross-correlation peak:
|
||||
**+133 frames (+2.217s)**, sharp and unique. Fixed offset, no drift.
|
||||
- DB: `Audio.SyncOffsetMs = 300` (not 0 as the 5ba4d70 commit message claimed —
|
||||
the write never actually landed).
|
||||
|
||||
**Take 2** (ty-20260914-1104-0000-2.mp4, clean clap test):
|
||||
- Audio 22.31s, video 22.10s (1326 frames), no frame drops.
|
||||
- Audio clap peak at **14.04s**; video motion peak at **11.93s** (yavg 2.75 vs
|
||||
background ~0.1–0.5). Offset: **+2.11s** — confirms the same mechanism.
|
||||
- Tiny pre-clap blips at 0.2/1.5/4.5/13.5s are faint artifacts (< 100 RMS);
|
||||
the 11617-RMS clap is unambiguous.
|
||||
|
||||
**Theory of the "cut off at the end":** audio events land ~2s late; when the video
|
||||
ends the audio track is still playing the final 2s of real-time content, giving the
|
||||
impression of a cut. The audio track's slightly longer duration (17.25 vs 17.05;
|
||||
22.31 vs 22.10) is the tail of that delayed signal — real audio outlives the
|
||||
pump-stopped video.
|
||||
|
||||
**Theories RULED OUT by data:**
|
||||
- ❌ Frame truncation / slow full-render — video is real-time; frame counts match
|
||||
wall-clock (FramePump log: 301/300 per 5s, dropped 0, avg render 14ms).
|
||||
- ❌ Named-pipe-connect drop — would *shorten* audio (events earlier), opposite sign.
|
||||
Pipe connected near-instantly in both takes.
|
||||
- ❌ AudioSyncDelay alone — capped at 0..500ms; 300ms is a subset, not the whole.
|
||||
- ❌ Audio drift/resampler rate — offset is constant, not growing.
|
||||
Take `ty-20260914-1128-0000-2.mp4` (1920×1080@60fps, 356 frames / 5.93s): audio clap RMS peak
|
||||
3.260s; video diff-frame 163 → 2.717s; **offset ≈ +0.54s** — collapsed from +2.11/2.22s; the
|
||||
remaining ~300ms was the baked-in `SyncOffsetMs=300` (now 0). Both streams `start_time=0` — not
|
||||
an `avoid_negative_ts` artifact.
|
||||
|
||||
## Open threads
|
||||
|
||||
- **Audio-silence verification** — FIXED code (idempotent `Configure`, committed
|
||||
`724af14`); the 19:23 take had real peakMix. Final user confirmation still pending.
|
||||
- **Audio sync offset DB value** — `Audio.SyncOffsetMs = 300` (the "set to 0" write
|
||||
in 5ba4d70 never actually landed). Fix for the ~2s ring backlog is now SHIPPED (local,
|
||||
uncommitted). Next: re-record the clap pattern, run the cross-correlation recipe → expect
|
||||
residual ≈ 400ms (300ms configured sync + ~100ms pipeline); then optionally zero the
|
||||
slider to hit ~100ms.
|
||||
- **Truncation with DYNAMIC scenes** — proven mechanism + probe in place; static
|
||||
scenes full-length. 19:23 take confirms dynamic scenes hold ~60fps (no truncation)
|
||||
but with 30ms stall cadence.
|
||||
- **Webcam MJPG missing**, **web capture ~10–14Hz**, **layer SortOrder not persisting**
|
||||
— queued, unchanged.
|
||||
- **Verify signed sync on device:** re-run the clap take with a NEGATIVE offset to confirm the
|
||||
advance direction end-to-end (the regression test proves the mixer; a take proves the file).
|
||||
- **Audio-silence verification** — fixed code (`724af14`) confirmed; creator heard real audio.
|
||||
- **Webcam MJPG missing / ~10–14Hz**, layer SortOrder, truncation-with-dynamic-scenes — queued.
|
||||
- **Sync control tutorial in user docs — REQUIRED before 1.0** (creator directive).
|
||||
|
||||
## Landmines
|
||||
|
||||
- testhost shares startup.log — filter by time.
|
||||
- `cmd.exe /c "taskkill /F /IM ytLive.exe"` (WSL form double-slashes mangle) before rebuilds.
|
||||
- Build/tests: Windows dotnet host (`/mnt/c/Program Files/dotnet/dotnet.exe`). 0 warnings.
|
||||
- ffmpeg/ffprobe: `/mnt/c/Program Files/Krita (x64)/bin/ffmpeg.exe` with Windows paths.
|
||||
- **`Audio.SyncOffsetMs` currently = 300 in the DB** (contradicts the "set to 0"
|
||||
line in 5ba4d70; the write likely never happened). Non-zero offsets still depend on
|
||||
the idempotent `Configure` guard to avoid the silence bug.
|
||||
- `MyMistakes.md` → Recipes registry now has the **audio/video sync measurement
|
||||
recipe** (claps + cross-correlation) — grep before re-deriving.
|
||||
- `cmd.exe /c "taskkill /F /IM ytLive.exe"` (WSL double-slashes mangle) before rebuilds.
|
||||
- Build/tests: **Windows dotnet host** (`/mnt/c/Program Files/dotnet/dotnet.exe`). 0 warnings.
|
||||
- ffmpeg/ffprobe: `/mnt/c/Program Files/Krita (x64)/bin/` with Windows paths.
|
||||
- `MyMistakes.md` has the **audio/video sync measurement recipe** (claps + cross-correlation)
|
||||
— grep it before re-deriving.
|
||||
- sqlite3 lives at `/home/gramps/android-sdk/platform-tools/sqlite3` (WSL) for the DB at
|
||||
`/mnt/c/Users/gramp/AppData/Roaming/ytLlive/ytLlive.db`.
|
||||
|
||||
## Next step
|
||||
|
||||
**Verify the shipped fix:** re-record with the same clap pattern and run the
|
||||
cross-correlation recipe from `MyMistakes.md` → expect offset ≈ 400ms (300ms configured
|
||||
sync + ~100ms pipeline) with a `SyncOffsetMs=300` DB value, or ~100ms with the slider
|
||||
zeroed. Then commit this session's work (StartLive clear + regression test + docs) and
|
||||
decide with the user whether the no-push ruling is lifted.
|
||||
Run the verify.sh gate (clean build, 0 warnings, full suite, scope check) on the dirty tree,
|
||||
then commit the signed-sync work unit (no push). Optionally a device clap take with a negative
|
||||
offset to validate the advance on the file.
|
||||
Reference in New Issue
Block a user