diff --git a/DeepDrftPublic.Client/Services/AudioPlayerService.cs b/DeepDrftPublic.Client/Services/AudioPlayerService.cs index 5221e3c..df069e7 100644 --- a/DeepDrftPublic.Client/Services/AudioPlayerService.cs +++ b/DeepDrftPublic.Client/Services/AudioPlayerService.cs @@ -186,6 +186,10 @@ public abstract class AudioPlayerService : IPlayerService, IAsyncDisposable var result = await _audioInterop.UnloadAsync(PlayerId); if (result.Success) { + // [RELOAD-DIAG] One of two base-class sites that null Duration (the other is + // OnPlaybackEndCallback). Logged so a run can attribute a "Duration set from header" + // re-fire to this path vs the spurious end-callback. Trivially removable. + OnDurationNulledDiag("Unload"); IsPlaying = false; IsPaused = false; CurrentTime = 0; @@ -278,6 +282,12 @@ public abstract class AudioPlayerService : IPlayerService, IAsyncDisposable private async Task OnPlaybackEndCallback() { + // [RELOAD-DIAG] The second base-class Duration-null site — the JS PlaybackScheduler's + // end-of-playback callback. A false (mid-stream) fire here is the Opus-startup bug: it nulls + // Duration (forcing a second "Duration set from header"), sets IsLoaded=false/CurrentTime=0, + // and raises TrackEnded (premature queue auto-advance). After the scheduler fix this must fire + // only on genuine end-of-track. Trivially removable. + OnDurationNulledDiag("OnPlaybackEndCallback"); IsPlaying = false; IsPaused = false; IsLoaded = false; @@ -308,6 +318,14 @@ public abstract class AudioPlayerService : IPlayerService, IAsyncDisposable /// protected virtual void OnPlaybackEnded() { } + /// + /// [RELOAD-DIAG] Diagnostic seam — invoked at each base-class site that nulls + /// ( and ), naming the caller. The streaming + /// subclass overrides this to emit a tagged log via its logger so a run can attribute a re-fired + /// "Duration set from header" to its true cause. No-op in the base; trivially removable. + /// + protected virtual void OnDurationNulledDiag(string caller) { } + protected async Task EnsureInitializedAsync() { diff --git a/DeepDrftPublic.Client/Services/StreamingAudioPlayerService.cs b/DeepDrftPublic.Client/Services/StreamingAudioPlayerService.cs index 2e6badc..5f38290 100644 --- a/DeepDrftPublic.Client/Services/StreamingAudioPlayerService.cs +++ b/DeepDrftPublic.Client/Services/StreamingAudioPlayerService.cs @@ -138,6 +138,12 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS // Organic end-of-stream closes the session; the bucket reflects the high-water fraction reached. protected override void OnPlaybackEnded() => _playTracker?.Close(); + // [RELOAD-DIAG] Emit the tagged log at each base-class Duration-null site so a run unambiguously + // shows which path nulled Duration between two "Duration set from header" lines. Trivially removable. + protected override void OnDurationNulledDiag(string caller) => + _logger.LogInformation( + "[RELOAD-DIAG] Base nulling Duration caller={Caller} (gen={Gen})", caller, _loadGeneration); + public override async Task SelectTrack(TrackDto track) { await SelectTrackStreaming(track); diff --git a/DeepDrftPublic/Interop/audio/AudioPlayer.ts b/DeepDrftPublic/Interop/audio/AudioPlayer.ts index 85b375e..dfc12dd 100644 --- a/DeepDrftPublic/Interop/audio/AudioPlayer.ts +++ b/DeepDrftPublic/Interop/audio/AudioPlayer.ts @@ -237,6 +237,12 @@ export class AudioPlayer { } } this.streamingCompleted = true; + // Hand the genuine-end signal to the scheduler AFTER the tail buffers are added and + // scheduled: now an empty scheduled queue is a real end-of-track, not a startup gap, so + // the scheduler may fire onPlaybackEnded when its queue drains. If the queue was already + // empty at this point (the tail produced no buffers, or they were already played), + // setStreamComplete finalises immediately. + this.scheduler.setStreamComplete(true); return { success: true, bufferCount: this.scheduler.getBufferCount() }; } catch (error) { return { success: false, error: (error as Error).message }; @@ -321,9 +327,13 @@ export class AudioPlayer { } } - // Check if streaming is complete + // Check if streaming is complete. The StreamDecoder self-detects completion by byte + // count (WAV/MP3/FLAC); propagate that to the scheduler so a drained queue past this + // point is treated as a genuine end. Buffers from this chunk were already added above, + // so any final end fires through handleSourceEnded when they drain. if (this.streamDecoder.isComplete) { this.streamingCompleted = true; + this.scheduler.setStreamComplete(true); } const canStart = this.streamDecoder.headerParsed && diff --git a/DeepDrftPublic/Interop/audio/PlaybackScheduler.test.ts b/DeepDrftPublic/Interop/audio/PlaybackScheduler.test.ts index edc0a89..e3734e0 100644 --- a/DeepDrftPublic/Interop/audio/PlaybackScheduler.test.ts +++ b/DeepDrftPublic/Interop/audio/PlaybackScheduler.test.ts @@ -441,6 +441,197 @@ test('clear and clearForSeek release the back-pressure latch (C2 latency parity) assertEqual(s.evaluateProductionPause(), false, 'clearForSeek resets the latch'); }); +// === False end-of-playback guard (Opus-startup misfire) ====================================== +// +// The scheduler must distinguish a GENUINE end-of-track (stream complete AND queue drained) from a +// transient startup/underrun gap (queue drained while bytes are still streaming — Opus decodes via +// WebCodecs asynchronously, so the first buffers can lag the playback-start minimum). The end +// callback fires only in the first case. These tests drive the real handleSourceEnded cascade via +// FakeSource.stop() and assert onPlaybackEnded fires exactly when it should. + +/** Drive the schedule cursor + live sources to a fully-drained queue at the buffer tail. */ +function drainAllSources(s: PlaybackScheduler, cm: FakeContextManager): void { + const priv = s as unknown as { scheduledSources: Array<{ source: FakeSource }> }; + let guard = 0; + while (priv.scheduledSources.length > 0 && guard++ < 10000) { + // Stop the head source; its onended → handleSourceEnded removes it and schedules the next. + priv.scheduledSources[0].source.stop(); + } +} + +// A drained queue MID-STREAM (streamComplete false) must NOT fire onPlaybackEnded — it parks in +// underrun instead. This is the exact Opus-startup false-end. +test('drained queue while still streaming does not fire onPlaybackEnded (no false end)', () => { + const cm = new FakeContextManager(); + const s = makeScheduler(cm); + let ended = 0; + s.onPlaybackEnded = () => { ended++; }; + + // A short run of buffers, playback started, but the stream is NOT marked complete. + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 0; + s.playFromPosition(0); + + // Advance the clock past the buffered tail and drain every scheduled source. + cm.now = 1.0; + drainAllSources(s, cm); + + assertEqual(ended, 0, 'no end callback fired mid-stream'); + assertEqual(s.isActive(), false, 'scheduler parked (inactive) on underrun'); +}); + +// After a mid-stream underrun, newly decoded buffers must RESUME playback (scheduleNewBuffers +// re-anchors and re-activates) — not stay stuck, and still not fire a false end. +test('underrun resumes when new buffers arrive', () => { + const cm = new FakeContextManager(); + const s = makeScheduler(cm); + let ended = 0; + s.onPlaybackEnded = () => { ended++; }; + + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 0; + s.playFromPosition(0); + cm.now = 1.0; + drainAllSources(s, cm); // underrun + assertEqual(s.isActive(), false, 'inactive after underrun'); + + // Decode catches up: more buffers arrive and the producer schedules them. + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + s.scheduleNewBuffers(); + + assertEqual(s.isActive(), true, 'resumed active after refill'); + assertEqual(ended, 0, 'still no false end after resume'); + const priv = s as unknown as { scheduledSources: unknown[] }; + if (priv.scheduledSources.length === 0) { + throw new Error('expected new sources scheduled on resume'); + } +}); + +// GENUINE end: stream complete AND queue drains → onPlaybackEnded fires exactly once. +test('genuine end (streamComplete + drained) fires onPlaybackEnded exactly once', () => { + const cm = new FakeContextManager(); + const s = makeScheduler(cm); + let ended = 0; + s.onPlaybackEnded = () => { ended++; }; + + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 0; + s.playFromPosition(0); + s.setStreamComplete(true); // all bytes in, no more buffers coming + + cm.now = 1.0; + drainAllSources(s, cm); + + assertEqual(ended, 1, 'end fired once on genuine completion'); + assertEqual(s.isActive(), false, 'inactive after genuine end'); +}); + +// setStreamComplete arriving AFTER the queue has already drained mid-stream (the tail produced no +// new buffers) must finalise immediately — the genuine-end signal that landed late. +test('setStreamComplete after an already-drained queue finalises immediately', () => { + const cm = new FakeContextManager(); + const s = makeScheduler(cm); + let ended = 0; + s.onPlaybackEnded = () => { ended++; }; + + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 0; + s.playFromPosition(0); + cm.now = 1.0; + drainAllSources(s, cm); // underrun, no end yet + assertEqual(ended, 0, 'no end before completion signal'); + + s.setStreamComplete(true); // signal arrives now → finalise + assertEqual(ended, 1, 'end fired when completion signalled post-drain'); +}); + +// clearForSeek must reset streamComplete so a post-seek refill cannot inherit a stale "complete" +// and fire a premature end before its own bytes arrive. +test('clearForSeek resets streamComplete (no inherited end on refill)', () => { + const cm = new FakeContextManager(); + const s = makeScheduler(cm); + let ended = 0; + s.onPlaybackEnded = () => { ended++; }; + + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 0; + s.playFromPosition(0); + s.setStreamComplete(true); + + s.clearForSeek(); + s.setPlaybackOffset(5); + // Post-seek continuation: fresh buffers, playback resumes, stream NOT yet complete. + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 5; + s.playFromPosition(0); + cm.now = 6.0; + drainAllSources(s, cm); + + assertEqual(ended, 0, 'no end fired — stale streamComplete was cleared by clearForSeek'); +}); + +// pause() during underrun: setStreamComplete must NOT fire end while the user is paused. +// This is the narrow window the fix to pause() closes: without the underrun_ clear, a paused +// scheduler that was mid-underrun satisfies the setStreamComplete immediate-finalise guard +// (complete && underrun_ && drained) and fires TrackEnded / queue-advance while paused. +test('pause during underrun: setStreamComplete does not fire end while paused', () => { + const cm = new FakeContextManager(); + const s = makeScheduler(cm); + let ended = 0; + s.onPlaybackEnded = () => { ended++; }; + + // A short run of buffers, drain them mid-stream → scheduler parks in underrun. + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 0; + s.playFromPosition(0); + cm.now = 1.0; + drainAllSources(s, cm); // queue drained, streamComplete still false → underrun + assertEqual(s.isActive(), false, 'parked in underrun after drain'); + assertEqual(ended, 0, 'no end before pause'); + + // User pauses while the scheduler is parked in underrun. + s.pause(); + + // Stream completes with no further buffers (the tail produced nothing new). + // With the fix, pause() cleared underrun_ so this must NOT finalise immediately. + s.setStreamComplete(true); + + assertEqual(ended, 0, 'no end fired while paused — setStreamComplete must not fire during pause'); + assertEqual(s.isActive(), false, 'scheduler stays inactive after setStreamComplete during pause'); +}); + +// underrun → resume → genuine end fires exactly once: the full composition from a mid-stream gap +// through resumed playback to completion. Confirms no double-fire and no stuck scheduler. +test('underrun → resume → genuine end fires exactly once', () => { + const cm = new FakeContextManager(); + const s = makeScheduler(cm); + let ended = 0; + s.onPlaybackEnded = () => { ended++; }; + + // Drain initial buffers into underrun. + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + cm.now = 0; + s.playFromPosition(0); + cm.now = 1.0; + drainAllSources(s, cm); + assertEqual(s.isActive(), false, 'underrun after initial drain'); + assertEqual(ended, 0, 'no end count during underrun'); + + // Decode catches up: new buffers arrive and the scheduler resumes. + for (let i = 0; i < 3; i++) s.addBuffer(buf(0.3)); + s.scheduleNewBuffers(); + assertEqual(s.isActive(), true, 'resumed active after refill'); + assertEqual(ended, 0, 'still no end after resume'); + + // Mark the stream complete, then drain the resumed sources to genuine end. + s.setStreamComplete(true); + cm.now = 2.0; + drainAllSources(s, cm); + + assertEqual(ended, 1, 'end fires exactly once after genuine completion'); + assertEqual(s.isActive(), false, 'inactive after genuine end'); +}); + // --- run ------------------------------------------------------------------------------------- if (failures.length > 0) { console.error(failures.join('\n')); diff --git a/DeepDrftPublic/Interop/audio/PlaybackScheduler.ts b/DeepDrftPublic/Interop/audio/PlaybackScheduler.ts index 5379130..68030b9 100644 --- a/DeepDrftPublic/Interop/audio/PlaybackScheduler.ts +++ b/DeepDrftPublic/Interop/audio/PlaybackScheduler.ts @@ -107,6 +107,22 @@ export class PlaybackScheduler { // Mutated by evaluateProductionPause() — named to signal the state-advance on each call. private productionPaused_: boolean = false; + // True once the producer (C# read loop / Opus feed) has signalled that ALL bytes are in and + // every decodable buffer has been added. This is the discriminator between a genuine + // end-of-track and a transient gap. End-of-playback fires ONLY when this is true AND the + // scheduled queue has drained — a drained queue while this is false is a startup/underrun gap, + // not the end (Opus decodes via WebCodecs asynchronously, so the first AudioBuffer can lag the + // playback-start minimum, briefly leaving zero scheduled sources before real playback). Reset + // by clear/clearForSeek/resetToStart; set by setStreamComplete. + private streamComplete: boolean = false; + + // True while playback is logically running but the decoded queue ran dry mid-stream (underrun). + // We stop the scheduler (isActive_ = false) so no source schedules against a stale anchor, but + // remember we must re-anchor and resume the moment new buffers arrive — distinct from a paused/ + // stopped player, which clears this. Without it, scheduleNewBuffers would silently no-op on the + // !isActive_ guard and playback would never recover from a starvation gap. + private underrun_: boolean = false; + // Callbacks public onPlaybackEnded: (() => void) | null = null; @@ -121,6 +137,28 @@ export class PlaybackScheduler { this.buffers.push(buffer); } + /** + * Mark whether the byte stream is complete (all bytes received and all decodable buffers added). + * The end-of-playback callback fires only when this is true AND the scheduled queue has drained — + * so a drained queue while the stream is still in flight (startup/underrun) is never mistaken for + * end-of-track. Set true by AudioPlayer on markStreamComplete / decoder isComplete; set false on a + * fresh stream or a range-continuation reinit. Setting it true while playback has already drained + * mid-stream finalises the track immediately (the genuine-end signal arrived after the queue + * emptied — e.g. the very last buffers were the tail). + */ + setStreamComplete(complete: boolean): void { + this.streamComplete = complete; + // If the queue already drained mid-stream (we are parked in underrun) when the genuine-end + // signal arrives, finalise now — the tail produced no more buffers, so this drained state is + // the real end. Gated on underrun_ (logically-playing-but-starved), not isActive_, which is + // false during a parked underrun. A drained queue with no playback in flight (never started, + // or already finished) is left untouched. + if (complete && this.underrun_ && + this.scheduledSources.length === 0 && this.nextBufferIndex >= this.buffers.length) { + this.finishPlayback(); + } + } + /** * Get total duration of all stored buffers */ @@ -350,18 +388,25 @@ export class PlaybackScheduler { } if (startBufferIndex >= this.buffers.length) { - // Position landed at or past the end of all buffers. Previously this - // returned silently, leaving the player stuck "playing" with no source - // scheduled — a pause near the end followed by play never recovered. - // Treat this as end-of-track so listeners (UI / end callback) fire. - this.isActive_ = false; - this.playbackAnchorTime = 0; - this.playbackAnchorPosition = 0; - this.onPlaybackEnded?.(); + // Position landed at or past the end of all currently-decoded buffers. This is + // end-of-track ONLY if the stream is complete; otherwise it is a startup/underrun + // gap (decode hasn't caught up to the playhead yet) and firing onPlaybackEnded here + // would be a FALSE end — exactly the Opus-startup misfire. When complete, finish; + // when still streaming, park in underrun so scheduleNewBuffers resumes on the next + // decoded buffer rather than the player being stuck "playing" with nothing scheduled. + if (this.streamComplete) { + this.finishPlayback(); + } else { + this.underrun_ = true; + this.playbackAnchorPosition = position; + this.nextBufferIndex = startBufferIndex; + this.isActive_ = false; // no source to schedule yet; resume() re-anchors on refill + } return; } // Set timing anchors + this.underrun_ = false; this.playbackAnchorPosition = position; this.playbackAnchorTime = this.contextManager.currentTime; this.nextScheduleTime = this.contextManager.currentTime + 0.01; // Small lookahead @@ -380,6 +425,21 @@ export class PlaybackScheduler { return; // No new buffers } + // Resume from a mid-stream underrun: the queue had drained ahead of decode and we parked + // (isActive_ = false, underrun_ = true) instead of firing a false end. Newly decoded + // buffers are now available at nextBufferIndex, so re-anchor the clock at the resume point + // and re-enable scheduling. We re-anchor (rather than reusing the stale nextScheduleTime + // captured before the gap) so the resumed audio is contiguous from "now" — a stale anchor + // would schedule the next source in the past and the browser would drop or rush it. + if (this.underrun_) { + this.underrun_ = false; + this.isActive_ = true; + this.playbackAnchorTime = this.contextManager.currentTime; + this.nextScheduleTime = this.contextManager.currentTime + 0.01; + this.scheduleBuffersFrom(this.nextBufferIndex, 0); + return; + } + // Use isActive_ as the sentinel for "playback is running", not nextScheduleTime === 0. // AudioContext.currentTime can legitimately be 0 at context creation, which would cause // nextScheduleTime === 0 to incorrectly reset a value already set by playFromPosition. @@ -464,21 +524,53 @@ export class PlaybackScheduler { this.scheduleBuffersFrom(this.nextBufferIndex, 0); } - // Check if all playback has finished + // The scheduled queue drained AND the cursor caught up to every decoded buffer. Whether + // this is the end depends on the stream: + // - streamComplete: genuine end-of-track — finish and fire onPlaybackEnded. + // - still streaming: a mid-stream UNDERRUN (decode fell behind the playhead — the Opus + // WebCodecs startup gap, or a network stall). Firing onPlaybackEnded here is the false + // end this guards against. Park in underrun; scheduleNewBuffers resumes on the next + // decoded buffer. if (this.scheduledSources.length === 0 && this.nextBufferIndex >= this.buffers.length) { - this.isActive_ = false; - this.playbackAnchorTime = 0; - this.playbackAnchorPosition = 0; - this.onPlaybackEnded?.(); + if (this.streamComplete) { + this.finishPlayback(); + } else { + this.underrun_ = true; + // Hold the playhead at the decoded tail so getCurrentPosition stays exact during + // the gap. isActive_ goes false so no stale-anchor scheduling occurs; resume + // re-anchors at currentTime when buffers arrive. + this.playbackAnchorPosition = this.getCurrentPosition() - this.playbackOffset; + this.playbackAnchorTime = 0; + this.isActive_ = false; + } } } + /** + * Finalise playback: stop the clock, reset anchors, and fire the end-of-playback callback. The + * single genuine-end path, reached only when the stream is complete AND the queue has fully + * drained (handleSourceEnded / setStreamComplete) or playback resumed past a complete stream's + * end (playFromPosition). Never called for a transient startup/underrun gap. + */ + private finishPlayback(): void { + this.isActive_ = false; + this.underrun_ = false; + this.playbackAnchorTime = 0; + this.playbackAnchorPosition = 0; + this.onPlaybackEnded?.(); + } + /** * Pause playback - saves position and stops sources */ pause(): number { const position = this.getCurrentPosition(); this.isActive_ = false; // Prevent handleSourceEnded from scheduling more + // Clear the underrun flag: if the queue drained mid-stream and the user pauses before new + // buffers arrive, a subsequent setStreamComplete must not fire finishPlayback while still + // paused. On resume, playFromPosition re-parks underrun if the decoded tail still hasn't + // caught up, so no genuine end is lost by clearing it here. + this.underrun_ = false; this.stopAllSources(); // getCurrentPosition() returns absolute time (anchor + playbackOffset); the anchor // is buffer-relative, so strip the offset back out before storing it. @@ -507,6 +599,8 @@ export class PlaybackScheduler { */ resetToStart(): void { this.isActive_ = false; + this.underrun_ = false; + this.streamComplete = false; this.stopAllSources(); this.playbackAnchorPosition = 0; this.playbackAnchorTime = 0; @@ -519,6 +613,8 @@ export class PlaybackScheduler { */ clear(): void { this.isActive_ = false; + this.underrun_ = false; + this.streamComplete = false; this.stopAllSources(); this.buffers = []; this.playbackAnchorPosition = 0; @@ -536,6 +632,11 @@ export class PlaybackScheduler { */ clearForSeek(): void { this.isActive_ = false; + this.underrun_ = false; + // The range continuation is a fresh byte stream — it is NOT complete until its own + // markStreamComplete. Reset so a stale "complete" from the pre-seek stream cannot make the + // post-seek refill fire a premature end before its bytes arrive. + this.streamComplete = false; this.stopAllSources(); this.buffers = []; this.playbackAnchorPosition = 0;