From 102cb96b28210dac37966283401180c67f350aa3 Mon Sep 17 00:00:00 2001 From: gramps Date: Thu, 12 Nov 2026 11:39:20 -0800 Subject: [PATCH] fix(audio): only count audio that actually reached the encoder MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Second measurement of the same recording family (ty-20261112-1133-701-0000-2.mp4): wall clock (audio start -> audio stop) 6.477 s video: 386 frames 6.455 s correct audio: 294 packets 6.252 s 226 ms SHORT Same magnitude as the original bug, opposite sign — the clock fixed the tick-rate error and exposed the next one underneath. Audio started 49 ms before the pump, ffmpeg connected ~80 ms after, and every chunk written in that window was dropped (dropped writes 27). The loop still counted those frames as produced, so the track lost exactly that much time. Now: the clock does not start until the pipe is connected, and AudioClock.Advance counts a frame only when its write reached the pipe. A dropped write stays owed and is paid off on the next tick, so a start-up gap costs content (silence, which there was anyway) instead of length. Two measurements, two different signs, one lesson: the audio track's LENGTH has to be the clock's, and anything that removes samples without removing time — a fast tick, a dropped write — shows up as drift no static offset can fix. 674 tests (one notification-timing flake under full-suite load; passes alone), 0 warnings. --- Services/Audio/AudioClock.cs | 9 +++++++++ Services/Audio/AudioMixer.cs | 19 ++++++++++++++----- Services/Audio/NamedPipeAudioWriter.cs | 11 +++++++---- docs/ai/output.md | 3 +++ ytLive.Tests/AudioClockTests.cs | 9 +++++++++ 5 files changed, 42 insertions(+), 9 deletions(-) diff --git a/Services/Audio/AudioClock.cs b/Services/Audio/AudioClock.cs index 50ee97e..1cbbbff 100644 --- a/Services/Audio/AudioClock.cs +++ b/Services/Audio/AudioClock.cs @@ -31,4 +31,13 @@ public static class AudioClock var debt = expected - framesProduced; return (int)Math.Clamp(debt, 0L, maxFrames); } + + /// + /// Advance the produced count for frames that actually reached the encoder. A write that went + /// nowhere (ffmpeg had not connected yet) must stay owed: counting it would shorten the track by + /// that gap — measured 2026-11-12 on the first clock-driven recording, where 27 start-up drops made + /// the audio 226 ms short after the same bug had made it 224 ms long. + /// + public static long Advance(long framesProduced, int frames, bool wrote) + => framesProduced + (wrote ? frames : 0); } diff --git a/Services/Audio/AudioMixer.cs b/Services/Audio/AudioMixer.cs index 90aa2cc..e773b22 100644 --- a/Services/Audio/AudioMixer.cs +++ b/Services/Audio/AudioMixer.cs @@ -402,7 +402,7 @@ public sealed class AudioMixer : IDisposable // any scheduler error into a permanent A/V rate error (measured 2026-11-12: 2.1% fast, 224 ms // of drift in ten seconds); asking the clock how much is owed and producing exactly that keeps // the track the same length as the show. - var clock = Stopwatch.StartNew(); + Stopwatch? clock = null; long framesProduced = 0; var maxChunkFrames = micChunk.Length; @@ -411,6 +411,15 @@ public sealed class AudioMixer : IDisposable var nextTick = DateTime.UtcNow + _mixInterval; try { + // The clock starts when ffmpeg is actually reading. Before that there is nowhere for + // audio to go, and time spent waiting must not become a shorter track. + if (!pipe.IsConnected) + { + await Task.Delay(1, cancellationToken).ConfigureAwait(false); + continue; + } + + clock ??= Stopwatch.StartNew(); var frames = AudioClock.FramesDue( clock.Elapsed.TotalSeconds, framesProduced, OutputSampleRate, maxChunkFrames); if (frames <= 0) @@ -421,7 +430,6 @@ public sealed class AudioMixer : IDisposable } var (_, micDrained, loopDrained) = FillAndMix(micChunk, loopbackChunk, mixBuffer, frames); - framesProduced += frames; var samples = frames * 2; // Negative offset: skip the armed |N| ms of stream head. The pipe @@ -436,9 +444,10 @@ public sealed class AudioMixer : IDisposable writeFrom = drop; } - if (writeFrom < samples) - await pipe.WriteAsync(mixBuffer.AsMemory(writeFrom, samples - writeFrom), - cancellationToken).ConfigureAwait(false); + var wrote = writeFrom >= samples + || await pipe.WriteAsync(mixBuffer.AsMemory(writeFrom, samples - writeFrom), + cancellationToken).ConfigureAwait(false); + framesProduced = AudioClock.Advance(framesProduced, frames, wrote); _micDrainedTotal += micDrained; _loopDrainedTotal += loopDrained; diff --git a/Services/Audio/NamedPipeAudioWriter.cs b/Services/Audio/NamedPipeAudioWriter.cs index 0b872dd..6dcb33a 100644 --- a/Services/Audio/NamedPipeAudioWriter.cs +++ b/Services/Audio/NamedPipeAudioWriter.cs @@ -23,8 +23,10 @@ public interface IAudioPipeWriter : IDisposable /// connected to the pipe. long DroppedWrites { get; } - /// Writes interleaved float samples; dropped until the client connects. - Task WriteAsync(ReadOnlyMemory samples, CancellationToken cancellationToken = default); + /// Writes interleaved float samples. Returns false when nothing was written because the + /// client has not connected or the pipe is closed — the caller must not count that audio as + /// produced, or a start-up gap silently shortens the track. + Task WriteAsync(ReadOnlyMemory samples, CancellationToken cancellationToken = default); /// Closes the server end — ffmpeg sees EOF and ends the audio input. void Stop(); @@ -65,7 +67,7 @@ public sealed class NamedPipeAudioWriter : IAudioPipeWriter } } - public async Task WriteAsync(ReadOnlyMemory samples, CancellationToken cancellationToken = default) + public async Task WriteAsync(ReadOnlyMemory samples, CancellationToken cancellationToken = default) { NamedPipeServerStream? pipe; lock (_sync) @@ -76,11 +78,12 @@ public sealed class NamedPipeAudioWriter : IAudioPipeWriter { if (pipe?.IsConnected == false || pipe == null) DroppedWrites++; - return; + return false; } var bytes = MemoryMarshal.AsBytes(samples.Span).ToArray(); await pipe.WriteAsync(bytes, cancellationToken).ConfigureAwait(false); + return true; } public void Stop() diff --git a/docs/ai/output.md b/docs/ai/output.md index b1b5a29..ff3c444 100644 --- a/docs/ai/output.md +++ b/docs/ai/output.md @@ -308,6 +308,9 @@ devices, no timers). the lips across ten seconds and no static delay could fix it. Buffers size to the largest chunk the planner may return (`OutputSampleRate / 5`), and a stalled loop pays its debt over the following ticks rather than dumping one huge write. Video never had this bug — the pump paces off a stopwatch. + **The clock also starts only once ffmpeg is connected, and `Advance` counts a frame only when its write + reached the pipe**: the first clock-driven recording came out **226 ms short** because 27 start-up + writes were dropped before the encoder connected, which is the same desync wearing the opposite sign. - **TRAX — free background music (TASK 8):** `MusicPlayer` = NAudio `MediaFoundationReader` (mp3/wav/m4a) → `VolumeWaveProvider16` at the hardcoded **0.20** bed (no slider) → `WaveOutEvent` on the default device, **looping on any clean natural end** (`PlaybackStopped` with `e.Exception == null` diff --git a/ytLive.Tests/AudioClockTests.cs b/ytLive.Tests/AudioClockTests.cs index 4eac890..79a812f 100644 --- a/ytLive.Tests/AudioClockTests.cs +++ b/ytLive.Tests/AudioClockTests.cs @@ -46,5 +46,14 @@ public class AudioClockTests // And a stalled loop pays its debt off gradually rather than dumping it in one write. Assert.Equal(maxChunk, AudioClock.FramesDue(5.0, 0, rate, maxChunk)); Assert.Equal(0, AudioClock.FramesDue(5.0, rate * 5, rate, maxChunk)); + + // Audio that never reached the encoder stays owed. Counting it would shorten the track by the + // start-up gap — the mirror image of the drift this clock exists to prevent (27 dropped start-up + // writes made the first clock-driven recording 226 ms short). + var produced2 = 0L; + for (var i = 0; i < 27; i++) + produced2 = AudioClock.Advance(produced2, 480, wrote: false); + Assert.Equal(0, produced2); + Assert.Equal(480, AudioClock.Advance(produced2, 480, wrote: true)); } }