fix(audio): _delayedMix never initialized — one NRE line behind the 'known failure', the class hang, AND the log flood; loopback gain now honest

The creator-declared known failure (Mix_HonorsProviderGains) and AudioPipelineTests'
standalone hang shared ONE root cause, born in TASK 22: AudioMixer.FillAndMix
dereferenced _delayedMix (declared float[]? , never assigned) as delayed.Length —
every live-mix tick NRE'd before the pipe write, so NO audio ever reached the wire
(tests starved -> hung/fail; app -> swallowed catch logged only ex.Message, 10ms
flood). Now: ctor-allocated + null-check, catch logs WITH stack via AppLog and is
throttled 5s, and a cancelled token breaks out before logging.

Bonus contract fix: AudioGainProvider.LoopbackGain returned unity on a disproven
premise ('loopback scales with endpoint volume'). The creator's tonight observation —
volume at 20%, meter pegged — proves the WASAPI tap is pre-endpoint-volume, so the
mixer must multiply by GameAudioVolume for stream honesty (this is what ai.md always
specified; the 'failing' test encoded the same and was RIGHT).

AudioPipelineTests: 25/25 in 26ms, standalone, no hang. Known-failure count: ZERO.
ai.md tests paragraph rewritten (no more suite-total claims, both ex-'knowns'
explained); TASK 22 regression recorded; MyMistakes: the known-failure-label rules.
This commit is contained in:
2026-09-01 21:20:45 -07:00
parent 5a1a3c566a
commit 5ead064d54
5 changed files with 61 additions and 20 deletions
+22
View File
@@ -124,3 +124,25 @@ with `#Name`) + panel properties (`IsHitTestVisible/Opacity/children/actual size
test process shares `%APPDATA%\ytLlive\startup.log` with the real app: lines like test process shares `%APPDATA%\ytLlive\startup.log` with the real app: lines like
`camera 'test-camera' failed` are test noise, not DB state — to check pollution, query `camera 'test-camera' failed` are test noise, not DB state — to check pollution, query
the DB directly (`python3 sqlite3`, `SELECT DeviceId FROM Webcam`), not the log. the DB directly (`python3 sqlite3`, `SELECT DeviceId FROM Webcam`), not the log.
## A "known failure" label without a recorded cause = a bug on life support
(2026-09-01, the audio triple-take) One line — `_delayedMix` (nullable, added by TASK 22,
never initialized) dereferenced as `delayed.Length` — produced THREE symptoms that lived in
the map as two separate "pre-existing, do-not-chase" entries: (a)
`Mix_HonorsProviderGains…` "known failure", (b) `AudioPipelineTests` hangs when run at all
(a test reading a named pipe with no writer blocks — hung test ≠ flaky test, it's a starved
producer), (c) startup.log flooded "Audio live loop error" every 10ms (the mixer loop caught
and logged only `ex.Message` — stack thrown away).
Rules derived:
1. NEVER label a test "known/pre-existing" without writing WHY (exception type + first app
frame). An unexplained known-failure is deferred archaeology that hardens into fog.
2. A test that waits on IPC + a producer whose output vanished are usually ONE bug — look
for the producer before blaming the test.
3. Catch-and-log-swallow of `ex.Message` hides root causes; log with stack (`AppLog.Write(ex,
...)`) and throttle (5s) instead of dropping or flooding.
Bonus: the "failing" test encoded the MAP's contract (`loopbackGain = GameAudioVolume`); the
code had drifted to unity on a disproven premise (loopback capture does NOT follow endpoint
volume — creator's 20%-volume/pegged-meter observation killed it). The test was right all
along — failing tests may be the last honest witnesses; interrogate, don't pardon.
+8 -4
View File
@@ -28,8 +28,12 @@ public sealed class AudioGainProvider
/// <summary>Mic gain for the live mix (0 = muted).</summary> /// <summary>Mic gain for the live mix (0 = muted).</summary>
public double MicGain() => _micMuted() ? 0 : _micVolume(); public double MicGain() => _micMuted() ? 0 : _micVolume();
/// <summary>Loopback (desktop/game) gain for the live mix (0 = muted, 1 = unity). /// <summary>Loopback (desktop/game) gain for the live mix (0 = muted).
/// Unity because the slider now drives system volume via PushSystemVolume, /// Honesty rule (2026-09-01): WASAPI loopback capture does NOT shrink with the
/// so the WASAPI loopback signal is already scaled by the user's volume choice.</summary> /// endpoint volume — the creator dropped system volume to 20% and the captured
public double LoopbackGain() => _gameMuted() ? 0 : 1.0; /// level stayed pegged — so the mixer must multiply by GameAudioVolume itself
/// for the stream to follow the knob (the old unity assumption left the stream
/// at full desktop volume while the headphones went quiet; ai.md always
/// specified loopbackGain = GameAudioVolume — the code had drifted).</summary>
public double LoopbackGain() => _gameMuted() ? 0 : _gameVolume();
} }
+17 -3
View File
@@ -1,3 +1,4 @@
using ytLive.Helpers;
using ytLive.Services; using ytLive.Services;
namespace ytLive.Services.Audio; namespace ytLive.Services.Audio;
@@ -48,6 +49,7 @@ public sealed class AudioMixer : IDisposable
private float[]? _loopbackChunk; private float[]? _loopbackChunk;
private float[]? _mixBuffer; private float[]? _mixBuffer;
private float[]? _delayedMix; private float[]? _delayedMix;
private DateTime _lastLoopErrorLogged = DateTime.MinValue;
public AudioMixer( public AudioMixer(
IAudioSource mic, IAudioSource mic,
@@ -78,6 +80,7 @@ public sealed class AudioMixer : IDisposable
_micChunk = new float[framesPerTick]; _micChunk = new float[framesPerTick];
_loopbackChunk = new float[framesPerTick * 2]; _loopbackChunk = new float[framesPerTick * 2];
_mixBuffer = new float[framesPerTick * 2]; _mixBuffer = new float[framesPerTick * 2];
_delayedMix = new float[framesPerTick * 2];
_mic.Started += OnMicStarted; _mic.Started += OnMicStarted;
_mic.SampleReady += OnMicSample; _mic.SampleReady += OnMicSample;
@@ -280,7 +283,18 @@ public sealed class AudioMixer : IDisposable
} }
catch (Exception ex) catch (Exception ex)
{ {
_log?.Invoke($"Audio live loop error: {ex.Message}"); // Throttled + never on a dead session: the 2026-09-01 first-launch flood
// was one logged NRE every 10ms tick (see _delayedMix fix). Log at most
// once per 5s, and stop looping if the pipe writer is gone for good.
if (cancellationToken.IsCancellationRequested)
break;
var now = DateTime.UtcNow;
if (now - _lastLoopErrorLogged >= TimeSpan.FromSeconds(5))
{
_lastLoopErrorLogged = now;
AppLog.Write(ex, "Audio live loop error");
_log?.Invoke($"Audio live loop error: {ex.Message}");
}
} }
var delay = nextTick - DateTime.UtcNow; var delay = nextTick - DateTime.UtcNow;
@@ -343,8 +357,8 @@ public sealed class AudioMixer : IDisposable
_masterLimiter.Process(mix); _masterLimiter.Process(mix);
_syncDelay.Configure(_syncOffsetMs?.Invoke() ?? 0); _syncDelay.Configure(_syncOffsetMs?.Invoke() ?? 0);
var delayed = _delayedMix!; var delayed = _delayedMix;
if (delayed.Length < mix.Length) if (delayed is null || delayed.Length < mix.Length)
delayed = _delayedMix = new float[mix.Length]; delayed = _delayedMix = new float[mix.Length];
_syncDelay.Process(mix, delayed); _syncDelay.Process(mix, delayed);
Array.Copy(delayed, mix, mix.Length); Array.Copy(delayed, mix, mix.Length);
+2 -1
View File
@@ -1127,11 +1127,12 @@ change. First GUI smoke test: add a short real mp4 on native Windows, confirm it
3. ☑ UI: compact "SYNC" slider (0..500) on the mic bar with a status dot (green = no-op, amber = offset set) via `IntToSyncBrushConverter`. 3. ☑ UI: compact "SYNC" slider (0..500) on the mic bar with a status dot (green = no-op, amber = offset set) via `IntToSyncBrushConverter`.
4. ☑ Persisted in `LayoutStore.Settings` (`Audio.SyncOffsetMs`) via `LoadAudioSyncOffsetMs`/`SaveAudioSyncOffsetMs`; saved from `SaveLayoutNow`. 4. ☑ Persisted in `LayoutStore.Settings` (`Audio.SyncOffsetMs`) via `LoadAudioSyncOffsetMs`/`SaveAudioSyncOffsetMs`; saved from `SaveLayoutNow`.
5. ☑ Tests: `AudioSyncDelayTests` — zero-delay identity, negative→0 clamp, >500 ms clamp to 500 ms, and 10 ms → 960 interleaved-sample shift. 5. ☑ Tests: `AudioSyncDelayTests` — zero-delay identity, negative→0 clamp, >500 ms clamp to 500 ms, and 10 ms → 960 interleaved-sample shift.
6. ⚠ **Post-ship regression (found 2026-09-01, first real launch):** this task's sync-delay line `_delayedMix` was declared nullable and never initialized — the first `delayed.Length` deref NRE'd EVERY live-mix tick, silently killing all live/record audio, hanging `AudioPipelineTests`, and being mislabeled a "known failure". Fixed in the recording-verification pass (init + null-check + throttled loop errors logged with stack); `AudioPipelineTests` 25/25 green afterward. Lesson recorded in MyMistakes.
### Design decisions ### Design decisions
- **Global offset first** — one setting for all audio sources. Per-source is v1.1+. - **Global offset first** — one setting for all audio sources. Per-source is v1.1+.
- **Positive-only (delay audio)** — the physically-correct direction (audio runs ahead of the video). True "advance" needs a video-side delay and is tracked as per-source/advance in v1.1 (line 1388). - **Positive-only (delay audio)** — the physically-correct direction (audio runs ahead of the video). True "advance" needs a video-side delay and is PERMANENTLY OUT with per-source sync (TASKS.md → "Out of product" — v1.x phrasing retired 2026-09-01).
- **Simple slider** — 0 to +500 ms, default 0. No numeric input needed. - **Simple slider** — 0 to +500 ms, default 0. No numeric input needed.
- **Visual feedback** — "sync OK" status dot shows when an offset is dialled in. - **Visual feedback** — "sync OK" status dot shows when an offset is dialled in.
+12 -12
View File
@@ -126,18 +126,18 @@ the Socials fediverse-heal roundtrip, AboutHubTests, NotificationAreaIntegration
GlobalHotkeyTests + HotkeyConfigTests (TASK 20), WebcamMenuGateTests (TASK 26), ChatLayerGateTests GlobalHotkeyTests + HotkeyConfigTests (TASK 20), WebcamMenuGateTests (TASK 26), ChatLayerGateTests
(TASK 27), BroadcastPullOutTests (TASK 29), DefaultRecordFolder fallback (TASK 30), WebView2ManagerTests (TASK 27), BroadcastPullOutTests (TASK 29), DefaultRecordFolder fallback (TASK 30), WebView2ManagerTests
(TASK 17), RecordingFileTests + OnAirSignTests (TASK 18), SessionTeardownTests (2026-09-01 (TASK 17), RecordingFileTests + OnAirSignTests (TASK 18), SessionTeardownTests (2026-09-01
rollback) — **~250 total (exact whole-suite count not claimable — the full run hangs and rollback) — **ZERO known failures as of 2026-09-01. `AudioPipelineTests` 25/25 green in 26ms —
`AudioPipelineTests` hangs even STANDALONE (confirmed 2026-09-01 — treat the class as the "known failing" `Mix_HonorsProviderGains…` and the class's notorious STANDALONE HANG shared
un-runnable until the audio channel-init fix lands). Every other class passes individually one root cause: TASK 22's `_delayedMix` (nullable, never initialized) was dereferenced
through the Windows dotnet.exe host, including the real-`MainWindow`/RealApp tests — 247 pass (`delayed.Length` on null) every live-mix tick — a swallowed NRE starved the pipe the tests
was the last full-suite number (2026-08-31); since then: the ONE remaining known failure is read and flooded startup.log. Test was right, code drifted from the map's own contract
`AudioPipelineTests.Mix_HonorsProviderGains…` (the creator-declared known, suspected WASAPI (loopbackGain = GameAudioVolume — now honored; the "unity because loopback scales with the
channel declaration/init), `RoundClipInteractionTests.Round_Clip_Corner_Is_Grabbable…` was endpoint" assumption was disproven by the creator's 20%-volume meter observation). The former
root-caused and FIXED 2026-09-01 (two stale-test layers — namescoped `FindName` + RoundClip "known failure" (stale-test layers: namescoped `FindName` + `VisualTreeHelper.HitTest`
`VisualTreeHelper.HitTest` used where `UIElement.InputHitTest` models input; see MyMistakes where `UIElement.InputHitTest` models input — see MyMistakes) was fixed the same day.
recipe; no product bug), and three tests were ADDED (locator dead-pin 404, EndBroadcast Per-class runs through the Windows dotnet.exe host execute the RealApp/MainWindow suites fine;
close-out, SessionTeardown rollback). "GUI suites can't run from here" was an overstatement — only the FULL-suite run still hangs (WASAPI teardown, pre-existing) — and the whole-suite
per-class Windows-host vstest runs them fine.)** "247 total" era count is stale; trust per-class results.**
Reward-event capture (monetization awareness, see the Monetization section) will add its integration Reward-event capture (monetization awareness, see the Monetization section) will add its integration
tests here when it ships: one real chat-poll payload containing all seven reward event types → tests here when it ships: one real chat-poll payload containing all seven reward event types →