daniel/deepdrft
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases 13 Wiki Activity

Remove harmful single-load guard; instrument reload/reset path for double-header-parse hunt

Browse Source
This commit is contained in:
daniel-c-harvey
2026-06-24 23:59:09 -04:00
parent 8fa37f995b
commit e98e616997
1 changed files with 59 additions and 53 deletions
Download Patch File Download Diff File Expand all files Collapse all files
DeepDrftPublic.Client/Services/StreamingAudioPlayerService.cs
+58 -52
View File
@@ -64,16 +64,6 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
private readonly ILogger<StreamingAudioPlayerService> _logger;
private string? _currentTrackId;
// The track key of the load currently in flight, set at LoadTrackStreaming entry BEFORE ResetToIdle
// (which clears _currentTrackId) and cleared only when that load's finally runs as the still-active
// operation. It is the idempotency key that collapses a duplicate same-track entry for ONE play
// action into the first load: a second SelectTrackStreaming for the SAME track while its load is
// still in flight is a redundant re-dispatch (UI double-fire, queue re-entry, or a JS false-end
// auto-advance back onto the same track), not a real track switch, so it is dropped. A load for a
// DIFFERENT track is a genuine switch and supersedes as before — this guard never suppresses it.
// Null when no load is in flight.
private string? _loadInFlightTrackId;
// Monotonic load-generation counter (diagnostic). Incremented on every LoadTrackStreaming entry and
// stamped into the load's logs so two loads for ONE user play action — the "Duration set from header
// logged twice" double-load hypothesis that needs in-browser confirmation — are unmistakable: a
@@ -209,29 +199,19 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
private async Task LoadTrackStreaming(TrackDto track, double? startPosition = null)
{
// Idempotency guard (single-load invariant). A load already in flight for THIS SAME track means
// a duplicate dispatch of one play action — a UI double-fire, a queue re-entry, or a JS false-end
// that auto-advanced back onto the same track. Dropping it collapses the play to exactly one load
// without touching the live operation. A load for a DIFFERENT track is a real switch and falls
// through to supersede the in-flight one exactly as before, so this never blocks navigation. The
// check is on the WASM single-threaded dispatcher, so reading/writing _loadInFlightTrackId needs
// no lock; the field is set below before the first await and cleared in finally for the active load.
if (_loadInFlightTrackId is { } inFlight && inFlight == track.EntryKey)
{
// [RELOAD-DIAG] Entry probe — captures every LoadTrackStreaming with its startPosition so a
// same-track reload (format switch) is distinguishable from a fresh play. _loadGeneration here
// is the PREVIOUS load's id (incremented below); it pins which generation this entry follows.
_logger.LogInformation(
"Streaming load for track {TrackId} skipped — a load for the same track is already in flight (single-load guard)",
track.EntryKey);
return;
}
_loadInFlightTrackId = track.EntryKey;
"[RELOAD-DIAG] LoadTrackStreaming ENTRY track={TrackId} startPosition={StartPosition} (prevGen={Gen})",
track.EntryKey, startPosition?.ToString("F2") ?? "null", _loadGeneration);
// Always reset to clean state before loading new track. ResetToIdle
// both cancels and awaits any in-flight streaming loop, so by the time
// we return from it the previous loop is guaranteed to have exited and
// there is no risk of interleaved ProcessStreamingChunk calls against
// the single-instance JS StreamDecoder. clearLoadGuard:false — we just armed
// _loadInFlightTrackId for THIS load; the prologue reset must not wipe it.
await ResetToIdle(clearLoadGuard: false);
// the single-instance JS StreamDecoder.
await ResetToIdle("prologue");
// Stamp this load with a fresh generation id (diagnostic — see _loadGeneration). Logged at
// start and finish so a double-load shows as two overlapping start/finish pairs for one play.
@@ -403,17 +383,10 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
IsLoading = false;
_logger.LogInformation("Streaming load #{Gen} finished for track {TrackId} (superseded={Superseded})",
loadGeneration, track.EntryKey, !ReferenceEquals(_streamingCancellation, loadCts));
// Release the single-load guard only when this load is still the active operation. A
// superseding load for a DIFFERENT track has already overwritten _loadInFlightTrackId with
// its own key before its first await; clearing it here would unlatch the guard mid-way
// through that newer load and let a duplicate of IT slip through. The CTS identity is the
// same "am I still the active operation?" test the notify/state guards use. ResetToIdle
// (the supersede path) does not touch this field — the incoming load owns its lifecycle.
if (ReferenceEquals(_streamingCancellation, loadCts))
{
_loadInFlightTrackId = null;
// Only notify if this load is still the active operation. A superseding seek
// owns state notifications; firing here mid-seek would push a stale snapshot.
if (ReferenceEquals(_streamingCancellation, loadCts))
{
await NotifyStateChanged();
}
}
@@ -440,6 +413,11 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
double startPosition,
CancellationToken cancellationToken)
{
// [RELOAD-DIAG] Positioned-start entry (the format-switch / load-at-timestamp path).
_logger.LogInformation(
"[RELOAD-DIAG] StartFromPositionAsync ENTRY track={TrackId} startPosition={StartPosition:F2} (gen={Gen})",
trackId, startPosition, _loadGeneration);
// Resolve the byte offset for the target time. Opus answers immediately from its sidecar; WAV
// returns failure until its header is parsed, so we probe the byte-0 segment and retry. The
// byte-0 segment is disposed once it has served its purpose (header probe / nothing for Opus),
@@ -536,6 +514,10 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
// Capture the once-only duration the header yields so the UI and play session have it.
if (result.Duration.HasValue && Duration == null)
{
// [RELOAD-DIAG] Header duration set via the probe path (StartFromPositionAsync probe).
_logger.LogInformation(
"[RELOAD-DIAG] Duration set from header (PROBE path) {Duration:F2}s (gen={Gen})",
result.Duration.Value, _loadGeneration);
Duration = result.Duration.Value;
_playTracker?.SetDuration(result.Duration.Value);
}
@@ -681,6 +663,13 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
double? seekPosition,
CancellationToken cancellationToken)
{
// [RELOAD-DIAG] Distinguishes a fresh forward load (seekPosition null) from a seek/refill re-entry
// (seekPosition non-null), which reinitializes the decoder — a candidate for a second header parse.
_logger.LogInformation(
"[RELOAD-DIAG] RunSegmentedStreamAsync ENTRY track={TrackId} cursor={Cursor} seekPosition={SeekPosition} kind={Kind} (gen={Gen})",
trackId, cursor, seekPosition?.ToString("F2") ?? "null",
seekPosition is null ? "forward-load" : "seek/refill-reentry", _loadGeneration);
byte[]? buffer = null;
var segment = firstSegment;
try
@@ -747,6 +736,12 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
if (chunkResult.Duration.HasValue && Duration == null)
{
Duration = chunkResult.Duration.Value;
// [RELOAD-DIAG] Header duration set via the stream-loop path. The gen + seekPosition
// context (logged at RunSegmentedStreamAsync entry) tells whether this is the fresh
// forward load or a seek/refill re-entry re-parsing the header.
_logger.LogInformation(
"[RELOAD-DIAG] Duration set from header (STREAM-LOOP path) {Duration:F2}s (gen={Gen})",
Duration, _loadGeneration);
_logger.LogInformation("Duration set from header: {Duration:F2} seconds", Duration);
// Feed the once-only duration to the play session for the completion
// fraction. No-op when no session is open; idempotent otherwise.
@@ -923,7 +918,7 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
public override async Task Stop()
{
// In streaming mode, Stop = Unload (data is consumed, can't replay)
await ResetToIdle();
await ResetToIdle("stop");
}
/// <summary>
@@ -931,7 +926,7 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
/// </summary>
public override async Task Unload()
{
await ResetToIdle();
await ResetToIdle("unload");
}
/// <summary>
@@ -941,6 +936,9 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
{
if (!IsLoaded || !IsStreamingMode) return;
// [RELOAD-DIAG] Seek entry — precedes the within-buffer vs beyond-buffer branch below.
_logger.LogInformation("[RELOAD-DIAG] Seek ENTRY position={Position:F2} (gen={Gen})", position, _loadGeneration);
try
{
var result = await _audioInterop.SeekAsync(PlayerId, position);
@@ -981,6 +979,11 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
/// </summary>
private async Task SeekBeyondBuffer(double seekPosition, long byteOffset)
{
// [RELOAD-DIAG] Seek-beyond-buffer entry — re-streams from an offset and reinitializes the decoder.
_logger.LogInformation(
"[RELOAD-DIAG] SeekBeyondBuffer ENTRY seekPosition={SeekPosition:F2} byteOffset={ByteOffset} (gen={Gen})",
seekPosition, byteOffset, _loadGeneration);
if (string.IsNullOrEmpty(_currentTrackId))
{
ErrorMessage = "Cannot seek - no track loaded";
@@ -1118,6 +1121,11 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
/// </summary>
private async Task RecoverFromFailedRefill(double seekPosition, string userFacingError)
{
// [RELOAD-DIAG] Refill-failure recovery entry — a mid-stream re-fetch failed and we are halting.
_logger.LogInformation(
"[RELOAD-DIAG] RecoverFromFailedRefill ENTRY seekPosition={SeekPosition:F2} (gen={Gen})",
seekPosition, _loadGeneration);
// Halt the starved scheduler JS-side (stop sources, drop stale buffers, anchor at the target).
// Best-effort: if even this interop fails the player is no worse off, and we still surface the
// error and settle C# state below.
@@ -1144,15 +1152,16 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
/// <summary>
/// Single method to reset all state - called by both Stop and Unload, and as the prologue of a new
/// load. <paramref name="clearLoadGuard"/> is true for the direct stop/unload/dispose callers and
/// false when a fresh <see cref="LoadTrackStreaming"/> calls it: that load has already set
/// <c>_loadInFlightTrackId</c> to its own key to arm the single-load guard, so the prologue must not
/// wipe it. The direct callers DO clear it so a later replay of the same track is not wrongly
/// suppressed by a guard key left over from an interrupted in-flight load (whose CTS-identity check
/// in finally fails after ResetToIdle nulls the CTS, so the load itself never clears the field).
/// load.
/// </summary>
private async Task ResetToIdle(bool clearLoadGuard = true)
/// <param name="caller">[RELOAD-DIAG] Diagnostic label naming the call site (prologue / stop / unload
/// / dispose) so a trace shows WHICH reset nulled Duration. Removable with the rest of the
/// instrumentation; defaults so existing call shapes are unaffected.</param>
private async Task ResetToIdle(string caller = "unspecified")
{
// [RELOAD-DIAG] Which caller is resetting, and at which generation.
_logger.LogInformation("[RELOAD-DIAG] ResetToIdle caller={Caller} (gen={Gen})", caller, _loadGeneration);
// 0. Close any open play session BEFORE tearing down (§2.1). ResetToIdle is the single funnel
// for stop / unload / dispose / track-switch (a new LoadTrackStreaming calls it first), so a
// superseded listen is recorded here with its high-water bucket. Close is idempotent — if the
@@ -1185,6 +1194,9 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
IsLoaded = false;
IsLoading = false;
CurrentTime = 0;
// [RELOAD-DIAG] Duration nulled here — the only site that nulls it. If "Duration set from header"
// appears after this line for the SAME generation, a reset ran mid-load.
_logger.LogInformation("[RELOAD-DIAG] ResetToIdle nulling Duration (gen={Gen})", _loadGeneration);
Duration = null;
LoadProgress = 0;
ErrorMessage = null;
@@ -1201,12 +1213,6 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
_currentTrackId = null;
_currentFormat = AudioFormat.Lossless;
// Direct stop/unload/dispose: release the single-load guard so a later replay of the same track
// is not suppressed. NOT cleared on the load prologue (clearLoadGuard:false) — that load owns the
// key it just armed.
if (clearLoadGuard)
_loadInFlightTrackId = null;
await NotifyStateChanged();
}
@@ -1286,7 +1292,7 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
try
{
// ResetToIdle closes any open play session, so a dispose mid-play still records the listen.
await ResetToIdle();
await ResetToIdle("dispose");
}
catch
{