Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 19 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -274,6 +274,25 @@ phase plan these entries follow.

### Fixed

- **Every track after the first showed nothing but the artist and title.** The album, cover art
and destination arrived a second into each song and were gone a moment later, on every track
except the first one of a session — while the files themselves were tagged correctly, so the
lookup was plainly working and only the page was wrong. The cause was that a report from the
pipeline named the track it was *about*, and the shell read that as the track playing. Encoding,
tagging and saving happen to the previous song while the next one is already recording, so those
reports named a track that had finished: the now-playing line snapped back to it, which was the
signal to drop the album, art and path of the song that was recording, and the next elapsed tick
a seventieth of a second later snapped it forward again and dropped them a second time. Nothing
re-runs a lookup for a track already under way, so the card stayed bare for the rest of it. The
first track escaped only because nothing was finishing behind it. Reports now carry what is
playing separately from what they are about, and the page takes its now-playing line, elapsed
counter and transport state from the former — which also stops the counter jumping to the
previous track's length and the transport flickering out of Recording each time a file lands.
While it was there: the page and the tray no longer announce a song called "Spotify". The poller
seeds an empty track when it starts listening, so that whatever is already playing counts as a
change, and Spotify's own idle window title parses to the same empty thing — both of which
render as the bare application name. A placeholder for the absence of a track is now reported
as no track.
- **Unplugging the device being recorded left the recording running against nothing.** The
detection for this was built and correct — it notices both ways of losing an endpoint, the
pinned device disappearing and Windows moving the default elsewhere — and nothing was listening
Expand Down
41 changes: 32 additions & 9 deletions src/Offstream.App/ViewModels/RecordViewModel.cs
Original file line number Diff line number Diff line change
Expand Up @@ -500,25 +500,40 @@ private void OnLineWritten(object? sender, LogLine line) => Dispatch(() =>
/// Applies a progress report to the status line, now-playing and the elapsed counter.
/// </summary>
/// <remarks>
/// <para>
/// These arrive around fourteen times a second while a track plays, which is what makes the
/// counter smooth and what makes this method's cost matter. Every assignment here is an
/// <see cref="ObservableObject"/> property that raises nothing when the value is unchanged,
/// so a report that repeats the previous one costs three comparisons and no layout.
/// </para>
/// <para>
/// The now-playing line comes from <see cref="RecordingProgress.NowPlaying"/> rather than
/// from <see cref="RecordingProgress.Track"/>, and the counter and the transport are only
/// touched by a report that concerns the track playing. The pipeline finishes the previous
/// song while the next one records, so its encoding, tagging and saved reports name a track
/// that is over and carry the length it ran to — applied here, they rewrote the card with
/// the finished song's name and jumped the counter to its duration until the next tick undid
/// both.
/// </para>
/// </remarks>
private void OnProgress(object? sender, RecordingProgress progress) => Dispatch(() =>
{
NowPlaying = progress.Track ?? Strings.RecordNothingPlaying;
Elapsed = progress.Elapsed ?? TimeSpan.Zero;
IsCapturing = progress.Stage == RecordingStage.Recording;
NowPlaying = progress.NowPlaying ?? Strings.RecordNothingPlaying;

Transport = progress.Stage switch
if (progress.ConcernsNowPlaying)
{
RecordingStage.Recording => Strings.RecordTransportRecording,
RecordingStage.WaitingForTrack => Strings.RecordTransportWaiting,
_ => Strings.RecordTransportStopped,
};
Elapsed = progress.Elapsed ?? TimeSpan.Zero;
IsCapturing = progress.Stage == RecordingStage.Recording;

if (IsBusy) return;
Transport = progress.Stage switch
{
RecordingStage.Recording => Strings.RecordTransportRecording,
RecordingStage.WaitingForTrack => Strings.RecordTransportWaiting,
_ => Strings.RecordTransportStopped,
};
}

if (IsBusy || !progress.ConcernsNowPlaying) return;

Status = progress.Stage switch
{
Expand Down Expand Up @@ -581,6 +596,14 @@ private void OnTrackEnriched(object? sender, TrackEnrichedEventArgs e) => Dispat
/// the value is unchanged, so this does not run.
/// </para>
/// <para>
/// That only holds because the name is now taken from <see cref="RecordingProgress.NowPlaying"/>,
/// which changes when the song does. It used to be taken from the report's subject, which the
/// previous track's encoding and tagging reports set back to the finished song — so every
/// track after the first had its album, art and destination cleared twice moments after
/// enrichment supplied them, and nothing left to put them back. Only the first track of a
/// session escaped, having nothing finishing behind it.
/// </para>
/// <para>
/// The order this depends on is that the progress report naming the new track arrives before
/// its enrichment does, which the enricher's settle delay and round trip make certain. If it
/// ever inverted, the cost is one track showing no album — a blank where something unknown
Expand Down
7 changes: 6 additions & 1 deletion src/Offstream.App/ViewModels/ShellViewModel.cs
Original file line number Diff line number Diff line change
Expand Up @@ -177,9 +177,14 @@ private void OnStateChanged(object? sender, EventArgs e) => UiThread.Dispatch(()
UpdateTooltip();
});

/// <remarks>
/// The tooltip answers "what is being recorded", so it follows
/// <see cref="RecordingProgress.NowPlaying"/> and not the report's subject — the reports that
/// finish the previous track name a song that has already stopped playing.
/// </remarks>
private void OnProgress(object? sender, RecordingProgress progress) => UiThread.Dispatch(() =>
{
_track = progress.Track;
_track = progress.NowPlaying;
UpdateTooltip();
});

Expand Down
19 changes: 17 additions & 2 deletions src/Offstream.Core/Diagnostics/RecordingProgress.cs
Original file line number Diff line number Diff line change
Expand Up @@ -22,14 +22,29 @@ public enum RecordingStage
/// render.
/// </remarks>
/// <param name="Stage">Where the pipeline is.</param>
/// <param name="Track">Human-readable track description, when one is known.</param>
/// <param name="Track">
/// Human-readable description of the track this report is <i>about</i>, when one is known —
/// which is not always the one playing. Encoding and tagging run on the previous track while
/// the next one records, so those reports name a song that finished minutes ago.
/// </param>
/// <param name="Elapsed">Time spent on the current track, when recording.</param>
/// <param name="Message">Free-text detail for the log pane.</param>
/// <param name="NowPlaying">
/// What is playing at the instant of the report, regardless of what the report is about. This is
/// what a now-playing display wants; <paramref name="Track"/> is what a log line wants.
/// </param>
/// <param name="ConcernsNowPlaying">
/// Whether <paramref name="Track"/> and <paramref name="NowPlaying"/> are the same recording, so
/// that <paramref name="Elapsed"/> and <paramref name="Stage"/> describe the live track rather
/// than the tail end of an earlier one.
/// </param>
public sealed record RecordingProgress(
RecordingStage Stage,
string? Track = null,
TimeSpan? Elapsed = null,
string? Message = null)
string? Message = null,
string? NowPlaying = null,
bool ConcernsNowPlaying = true)
{
public static RecordingProgress Idle { get; } = new(RecordingStage.Idle);

Expand Down
84 changes: 70 additions & 14 deletions src/Offstream.Core/Recording/RecordingSession.cs
Original file line number Diff line number Diff line change
Expand Up @@ -415,7 +415,7 @@ private void OnTrackTimeChanged(object? sender, TrackTimeChangedEventArgs e)

Report(
recording is null ? RecordingStage.WaitingForTrack : RecordingStage.Recording,
(recording ?? _poller.CurrentTrack)?.ToString(),
recording ?? _poller.CurrentTrack,
TimeSpan.FromSeconds(e.TrackTimeSeconds));
}

Expand Down Expand Up @@ -453,15 +453,15 @@ private void OnTrackChanged(object? sender, TrackChangedEventArgs e)

if (!_policy.IsTypeAllowed(track))
{
Report(RecordingStage.WaitingForTrack, track.ToString(), message: DescribeSkipped(track));
Report(RecordingStage.WaitingForTrack, track, message: DescribeSkipped(track));
return;
}

if (_policy.IsMaxOrderNumberAsFileExceeded)
{
Report(
RecordingStage.WaitingForTrack,
track.ToString(),
track,
message: $"File counter reached its maximum ({_settings.OrderNumberMax}); not recording.");

return;
Expand All @@ -476,7 +476,7 @@ private void OnTrackChanged(object? sender, TrackChangedEventArgs e)
{
Report(
RecordingStage.WaitingForTrack,
track.ToString(),
track,
message: $"Kept the file already on disk and did not record {track}.");

return;
Expand Down Expand Up @@ -521,7 +521,7 @@ private void StartRecorder(Track detected, OutputPaths paths)
_recording = Task.Run(() => recorder.RunAsync(_stopping.Token), CancellationToken.None);
}

Report(RecordingStage.Recording, track.ToString(), message: $"Recording {track}.");
Report(RecordingStage.Recording, track, message: $"Recording {track}.");
}

/// <summary>
Expand Down Expand Up @@ -688,7 +688,7 @@ private void Handle(TrackRecording recording)

Report(
RecordingStage.Encoding,
recording.Track.ToString(),
recording.Track,
recording.Duration,
$"Encoding {recording.Track}.");

Expand All @@ -697,7 +697,7 @@ private void Handle(TrackRecording recording)
case RecordingOutcome.TooShort:
Report(
RecordingStage.WaitingForTrack,
recording.Track.ToString(),
recording.Track,
recording.Duration,
$"Discarded {recording.Track}: shorter than "
+ $"{_settings.MinimumRecordedLengthSeconds}s.");
Expand All @@ -707,7 +707,7 @@ private void Handle(TrackRecording recording)
case RecordingOutcome.AlreadyRecorded:
Report(
RecordingStage.WaitingForTrack,
recording.Track.ToString(),
recording.Track,
recording.Duration,
$"Kept the file already on disk and discarded this recording of {recording.Track}: "
+ $"{recording.Destination}");
Expand Down Expand Up @@ -763,7 +763,7 @@ private void OnEncodeCompleted(object? sender, EncodeCompletedEventArgs e)

Report(
RecordingStage.WaitingForTrack,
track.ToString(),
track,
recording.Duration,
$"Kept the file already on disk and discarded this recording of {track}: {destination}");

Expand All @@ -788,14 +788,14 @@ private void OnEncodeCompleted(object? sender, EncodeCompletedEventArgs e)
"Cover art could not be embedded in {Track}. The recording itself is fine.",
track);

Report(RecordingStage.Tagging, track.ToString());
Report(RecordingStage.Tagging, track);
}

TrackSaved?.Invoke(this, new TrackSavedEventArgs(track, destination, recording.Duration));

Report(
RecordingStage.WaitingForTrack,
track.ToString(),
track,
recording.Duration,
DescribeSaved(outputFile, replacing));
}
Expand Down Expand Up @@ -909,9 +909,65 @@ private void StopRecordingTimer()
private void RaiseFailed(Track track, string message, Exception? exception = null)
{
Failed?.Invoke(this, new RecordingFailedEventArgs(track, message, exception));
Report(RecordingStage.WaitingForTrack, track.ToString());
Report(RecordingStage.WaitingForTrack, track);
}

/// <summary>
/// Emits a progress report, and works out what is playing while it does.
/// </summary>
/// <remarks>
/// <para>
/// <b>The track a report is about is not always the track playing.</b> Encoding, tagging and
/// the save message all describe the <i>previous</i> song and arrive well after the next one
/// has started, because finalising to disk deliberately overlaps the following recording.
/// Consumers that showed <see cref="RecordingProgress.Track"/> as the now-playing line
/// therefore flipped back to the finished song for as long as it took the next elapsed tick
/// to correct them — and anything keyed on that line changing, like the shell dropping a
/// track's album and cover art, fired twice on a track it should not have touched at all.
/// </para>
/// <para>
/// Both facts are computed here rather than at the eleven call sites, so a new report cannot
/// forget to carry them and cannot disagree with the others about what "now" means. The live
/// track is the one being recorded, falling back to whatever Spotify is showing when nothing
/// is being recorded — an advertisement is still playing, and a now-playing line that blanks
/// out for one reads as a bug. Identity is by reference, not by name: the poller hands each
/// track over once and the session snapshots it, so two plays of the same song are two
/// objects and are told apart correctly.
/// </para>
/// </remarks>
private void Report(RecordingStage stage, Track? track = null, TimeSpan? elapsed = null, string? message = null)
{
if (_progress is null) return;

// Stopped and idle mean the session is not listening, so nothing is playing as far as
// this report is concerned — whatever the poller last saw is stale by definition.
var live = stage is RecordingStage.Stopped or RecordingStage.Idle
? null
: Named(CurrentTrack ?? _poller.CurrentTrack);

var subject = Named(track);

_progress.Report(new RecordingProgress(
stage,
subject?.ToString(),
elapsed,
message,
live?.ToString(),
subject is null || ReferenceEquals(subject, live)));
}

private void Report(RecordingStage stage, string? track = null, TimeSpan? elapsed = null, string? message = null) =>
_progress?.Report(new RecordingProgress(stage, track, elapsed, message));
/// <summary>
/// A track worth naming, or null for one that only stands in for the absence of a track.
/// </summary>
/// <remarks>
/// <see cref="SpotifyPoller.Start"/> seeds an empty <see cref="Track"/> so that the song
/// already playing counts as a change, and Spotify's own title when nothing is on parses to
/// the same thing. Either renders as the bare word "Spotify", so without this the page said
/// a song called Spotify was playing and the tray offered to be recording it, from the
/// instant the user pressed start.
/// </remarks>
private static Track? Named(Track? track) =>
track is not null && (!string.IsNullOrEmpty(track.Artist) || !string.IsNullOrEmpty(track.Title))
? track
: null;
}
31 changes: 31 additions & 0 deletions tests/Offstream.Core.Tests/Recording/RecordingSessionTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -715,6 +715,37 @@ await WaitFor(
"an elapsed-time report naming the track");
}

/// <summary>
/// Every report says what is playing, separately from what the report is about.
/// </summary>
/// <remarks>
/// The two are not the same. A track is encoded, tagged and saved while the next one is
/// already recording, so those reports name a song that has finished — and a shell that read
/// the subject as the now-playing line put the previous track back on the page, taking the
/// album, cover art and destination of the one actually recording down with it. Reporting
/// both facts is what lets the shell tell them apart; the flag is here so it does not have to
/// compare names, which two plays of the same song would defeat.
/// </remarks>
[Fact]
public async Task Session_ReportsWhatIsPlayingAlongsideWhatTheReportIsAbout()
{
await using var harness = new Harness();

harness.Session.Start();

await RecordTrackAsync(harness, Harness.Playing("Artist", "Title"));

await WaitFor(
() => harness.Reports.Any(r => r.Stage == RecordingStage.Recording && r.NowPlaying == "Artist - Title"),
"a recording report naming what is playing");

// The invariant the shell leans on: a report that claims to be about the live track has
// to actually name it, or the elapsed counter it carries belongs to something else.
Assert.DoesNotContain(
harness.Reports,
r => r.ConcernsNowPlaying && r.Track is not null && r.Track != r.NowPlaying);
}

[Fact]
public async Task Level_MeasuresWhatCaptureDelivers()
{
Expand Down
Loading
Loading