Merge guard revert + reload-path instrumentation into streaming-overhaul
This commit is contained in:
@@ -64,16 +64,6 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
private readonly ILogger<StreamingAudioPlayerService> _logger;
|
private readonly ILogger<StreamingAudioPlayerService> _logger;
|
||||||
private string? _currentTrackId;
|
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
|
// 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
|
// 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
|
// 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)
|
private async Task LoadTrackStreaming(TrackDto track, double? startPosition = null)
|
||||||
{
|
{
|
||||||
// Idempotency guard (single-load invariant). A load already in flight for THIS SAME track means
|
// [RELOAD-DIAG] Entry probe — captures every LoadTrackStreaming with its startPosition so a
|
||||||
// a duplicate dispatch of one play action — a UI double-fire, a queue re-entry, or a JS false-end
|
// same-track reload (format switch) is distinguishable from a fresh play. _loadGeneration here
|
||||||
// that auto-advanced back onto the same track. Dropping it collapses the play to exactly one load
|
// is the PREVIOUS load's id (incremented below); it pins which generation this entry follows.
|
||||||
// without touching the live operation. A load for a DIFFERENT track is a real switch and falls
|
_logger.LogInformation(
|
||||||
// through to supersede the in-flight one exactly as before, so this never blocks navigation. The
|
"[RELOAD-DIAG] LoadTrackStreaming ENTRY track={TrackId} startPosition={StartPosition} (prevGen={Gen})",
|
||||||
// check is on the WASM single-threaded dispatcher, so reading/writing _loadInFlightTrackId needs
|
track.EntryKey, startPosition?.ToString("F2") ?? "null", _loadGeneration);
|
||||||
// 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)
|
|
||||||
{
|
|
||||||
_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;
|
|
||||||
|
|
||||||
// Always reset to clean state before loading new track. ResetToIdle
|
// Always reset to clean state before loading new track. ResetToIdle
|
||||||
// both cancels and awaits any in-flight streaming loop, so by the time
|
// 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
|
// we return from it the previous loop is guaranteed to have exited and
|
||||||
// there is no risk of interleaved ProcessStreamingChunk calls against
|
// there is no risk of interleaved ProcessStreamingChunk calls against
|
||||||
// the single-instance JS StreamDecoder. clearLoadGuard:false — we just armed
|
// the single-instance JS StreamDecoder.
|
||||||
// _loadInFlightTrackId for THIS load; the prologue reset must not wipe it.
|
await ResetToIdle("prologue");
|
||||||
await ResetToIdle(clearLoadGuard: false);
|
|
||||||
|
|
||||||
// Stamp this load with a fresh generation id (diagnostic — see _loadGeneration). Logged at
|
// 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.
|
// 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;
|
IsLoading = false;
|
||||||
_logger.LogInformation("Streaming load #{Gen} finished for track {TrackId} (superseded={Superseded})",
|
_logger.LogInformation("Streaming load #{Gen} finished for track {TrackId} (superseded={Superseded})",
|
||||||
loadGeneration, track.EntryKey, !ReferenceEquals(_streamingCancellation, loadCts));
|
loadGeneration, track.EntryKey, !ReferenceEquals(_streamingCancellation, loadCts));
|
||||||
// Release the single-load guard only when this load is still the active operation. A
|
// Only notify if this load is still the active operation. A superseding seek
|
||||||
// superseding load for a DIFFERENT track has already overwritten _loadInFlightTrackId with
|
// owns state notifications; firing here mid-seek would push a stale snapshot.
|
||||||
// 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))
|
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.
|
|
||||||
await NotifyStateChanged();
|
await NotifyStateChanged();
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -440,6 +413,11 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
double startPosition,
|
double startPosition,
|
||||||
CancellationToken cancellationToken)
|
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
|
// 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
|
// 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),
|
// 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.
|
// Capture the once-only duration the header yields so the UI and play session have it.
|
||||||
if (result.Duration.HasValue && Duration == null)
|
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;
|
Duration = result.Duration.Value;
|
||||||
_playTracker?.SetDuration(result.Duration.Value);
|
_playTracker?.SetDuration(result.Duration.Value);
|
||||||
}
|
}
|
||||||
@@ -681,6 +663,13 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
double? seekPosition,
|
double? seekPosition,
|
||||||
CancellationToken cancellationToken)
|
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;
|
byte[]? buffer = null;
|
||||||
var segment = firstSegment;
|
var segment = firstSegment;
|
||||||
try
|
try
|
||||||
@@ -747,6 +736,12 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
if (chunkResult.Duration.HasValue && Duration == null)
|
if (chunkResult.Duration.HasValue && Duration == null)
|
||||||
{
|
{
|
||||||
Duration = chunkResult.Duration.Value;
|
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);
|
_logger.LogInformation("Duration set from header: {Duration:F2} seconds", Duration);
|
||||||
// Feed the once-only duration to the play session for the completion
|
// Feed the once-only duration to the play session for the completion
|
||||||
// fraction. No-op when no session is open; idempotent otherwise.
|
// fraction. No-op when no session is open; idempotent otherwise.
|
||||||
@@ -923,7 +918,7 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
public override async Task Stop()
|
public override async Task Stop()
|
||||||
{
|
{
|
||||||
// In streaming mode, Stop = Unload (data is consumed, can't replay)
|
// In streaming mode, Stop = Unload (data is consumed, can't replay)
|
||||||
await ResetToIdle();
|
await ResetToIdle("stop");
|
||||||
}
|
}
|
||||||
|
|
||||||
/// <summary>
|
/// <summary>
|
||||||
@@ -931,7 +926,7 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
/// </summary>
|
/// </summary>
|
||||||
public override async Task Unload()
|
public override async Task Unload()
|
||||||
{
|
{
|
||||||
await ResetToIdle();
|
await ResetToIdle("unload");
|
||||||
}
|
}
|
||||||
|
|
||||||
/// <summary>
|
/// <summary>
|
||||||
@@ -941,6 +936,9 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
{
|
{
|
||||||
if (!IsLoaded || !IsStreamingMode) return;
|
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
|
try
|
||||||
{
|
{
|
||||||
var result = await _audioInterop.SeekAsync(PlayerId, position);
|
var result = await _audioInterop.SeekAsync(PlayerId, position);
|
||||||
@@ -981,6 +979,11 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
/// </summary>
|
/// </summary>
|
||||||
private async Task SeekBeyondBuffer(double seekPosition, long byteOffset)
|
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))
|
if (string.IsNullOrEmpty(_currentTrackId))
|
||||||
{
|
{
|
||||||
ErrorMessage = "Cannot seek - no track loaded";
|
ErrorMessage = "Cannot seek - no track loaded";
|
||||||
@@ -1118,6 +1121,11 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
/// </summary>
|
/// </summary>
|
||||||
private async Task RecoverFromFailedRefill(double seekPosition, string userFacingError)
|
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).
|
// 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
|
// Best-effort: if even this interop fails the player is no worse off, and we still surface the
|
||||||
// error and settle C# state below.
|
// error and settle C# state below.
|
||||||
@@ -1144,15 +1152,16 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
|
|
||||||
/// <summary>
|
/// <summary>
|
||||||
/// Single method to reset all state - called by both Stop and Unload, and as the prologue of a new
|
/// 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
|
/// load.
|
||||||
/// 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).
|
|
||||||
/// </summary>
|
/// </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
|
// 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
|
// 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
|
// 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;
|
IsLoaded = false;
|
||||||
IsLoading = false;
|
IsLoading = false;
|
||||||
CurrentTime = 0;
|
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;
|
Duration = null;
|
||||||
LoadProgress = 0;
|
LoadProgress = 0;
|
||||||
ErrorMessage = null;
|
ErrorMessage = null;
|
||||||
@@ -1201,12 +1213,6 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
_currentTrackId = null;
|
_currentTrackId = null;
|
||||||
_currentFormat = AudioFormat.Lossless;
|
_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();
|
await NotifyStateChanged();
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -1286,7 +1292,7 @@ public class StreamingAudioPlayerService : AudioPlayerService, IStreamingPlayerS
|
|||||||
try
|
try
|
||||||
{
|
{
|
||||||
// ResetToIdle closes any open play session, so a dispose mid-play still records the listen.
|
// ResetToIdle closes any open play session, so a dispose mid-play still records the listen.
|
||||||
await ResetToIdle();
|
await ResetToIdle("dispose");
|
||||||
}
|
}
|
||||||
catch
|
catch
|
||||||
{
|
{
|
||||||
|
|||||||
Reference in New Issue
Block a user