diff --git a/CHANGELOG.md b/CHANGELOG.md index fac77f4..e565045 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -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 diff --git a/src/Offstream.App/ViewModels/RecordViewModel.cs b/src/Offstream.App/ViewModels/RecordViewModel.cs index b639a17..07f061c 100644 --- a/src/Offstream.App/ViewModels/RecordViewModel.cs +++ b/src/Offstream.App/ViewModels/RecordViewModel.cs @@ -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. /// /// + /// /// 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 /// property that raises nothing when the value is unchanged, /// so a report that repeats the previous one costs three comparisons and no layout. + /// + /// + /// The now-playing line comes from rather than + /// from , 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. + /// /// 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 { @@ -581,6 +596,14 @@ private void OnTrackEnriched(object? sender, TrackEnrichedEventArgs e) => Dispat /// the value is unchanged, so this does not run. /// /// + /// That only holds because the name is now taken from , + /// 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. + /// + /// /// 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 diff --git a/src/Offstream.App/ViewModels/ShellViewModel.cs b/src/Offstream.App/ViewModels/ShellViewModel.cs index b7c7e6e..ce7d7d1 100644 --- a/src/Offstream.App/ViewModels/ShellViewModel.cs +++ b/src/Offstream.App/ViewModels/ShellViewModel.cs @@ -177,9 +177,14 @@ private void OnStateChanged(object? sender, EventArgs e) => UiThread.Dispatch(() UpdateTooltip(); }); + /// + /// The tooltip answers "what is being recorded", so it follows + /// and not the report's subject — the reports that + /// finish the previous track name a song that has already stopped playing. + /// private void OnProgress(object? sender, RecordingProgress progress) => UiThread.Dispatch(() => { - _track = progress.Track; + _track = progress.NowPlaying; UpdateTooltip(); }); diff --git a/src/Offstream.Core/Diagnostics/RecordingProgress.cs b/src/Offstream.Core/Diagnostics/RecordingProgress.cs index e3e694a..ae29bb5 100644 --- a/src/Offstream.Core/Diagnostics/RecordingProgress.cs +++ b/src/Offstream.Core/Diagnostics/RecordingProgress.cs @@ -22,14 +22,29 @@ public enum RecordingStage /// render. /// /// Where the pipeline is. -/// Human-readable track description, when one is known. +/// +/// Human-readable description of the track this report is about, 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. +/// /// Time spent on the current track, when recording. /// Free-text detail for the log pane. +/// +/// What is playing at the instant of the report, regardless of what the report is about. This is +/// what a now-playing display wants; is what a log line wants. +/// +/// +/// Whether and are the same recording, so +/// that and describe the live track rather +/// than the tail end of an earlier one. +/// 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); diff --git a/src/Offstream.Core/Recording/RecordingSession.cs b/src/Offstream.Core/Recording/RecordingSession.cs index 5cdb8e9..1e9f60c 100644 --- a/src/Offstream.Core/Recording/RecordingSession.cs +++ b/src/Offstream.Core/Recording/RecordingSession.cs @@ -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)); } @@ -453,7 +453,7 @@ 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; } @@ -461,7 +461,7 @@ private void OnTrackChanged(object? sender, TrackChangedEventArgs e) { Report( RecordingStage.WaitingForTrack, - track.ToString(), + track, message: $"File counter reached its maximum ({_settings.OrderNumberMax}); not recording."); return; @@ -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; @@ -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}."); } /// @@ -688,7 +688,7 @@ private void Handle(TrackRecording recording) Report( RecordingStage.Encoding, - recording.Track.ToString(), + recording.Track, recording.Duration, $"Encoding {recording.Track}."); @@ -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."); @@ -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}"); @@ -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}"); @@ -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)); } @@ -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); + } + + /// + /// Emits a progress report, and works out what is playing while it does. + /// + /// + /// + /// The track a report is about is not always the track playing. Encoding, tagging and + /// the save message all describe the previous song and arrive well after the next one + /// has started, because finalising to disk deliberately overlaps the following recording. + /// Consumers that showed 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. + /// + /// + /// 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. + /// + /// + 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)); + /// + /// A track worth naming, or null for one that only stands in for the absence of a track. + /// + /// + /// seeds an empty 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. + /// + private static Track? Named(Track? track) => + track is not null && (!string.IsNullOrEmpty(track.Artist) || !string.IsNullOrEmpty(track.Title)) + ? track + : null; } diff --git a/tests/Offstream.Core.Tests/Recording/RecordingSessionTests.cs b/tests/Offstream.Core.Tests/Recording/RecordingSessionTests.cs index c28a275..667d3ae 100644 --- a/tests/Offstream.Core.Tests/Recording/RecordingSessionTests.cs +++ b/tests/Offstream.Core.Tests/Recording/RecordingSessionTests.cs @@ -715,6 +715,37 @@ await WaitFor( "an elapsed-time report naming the track"); } + /// + /// Every report says what is playing, separately from what the report is about. + /// + /// + /// 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. + /// + [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() { diff --git a/tests/Offstream.UI.Tests/RecordViewModelTests.cs b/tests/Offstream.UI.Tests/RecordViewModelTests.cs index 4988f50..631db1d 100644 --- a/tests/Offstream.UI.Tests/RecordViewModelTests.cs +++ b/tests/Offstream.UI.Tests/RecordViewModelTests.cs @@ -317,6 +317,112 @@ public void NowPlaying_WhenTheSameTrackIsReportedAgain_KeepsTheDetails() Assert.Equal("An Album (2026)", viewModel.Album); } + /// + /// The defect that made every track after the first show nothing but artist and title. + /// + /// + /// A track is encoded, tagged and saved while the next one is already recording, and + /// those reports name the track they are about — the one that finished. Read as the + /// now-playing line, they set the card back to the previous song, which cleared the album, + /// art and destination that enrichment had just supplied, and the next elapsed tick a + /// seventieth of a second later cleared them again on the way back. Nothing re-raises + /// enrichment for a track already recording, so the card stayed bare for the rest of the + /// song. The first track of a session escaped because nothing was finishing behind it. + /// + [Fact] + public async Task Progress_WhileThePreviousTrackFinishes_KeepsTheDetailsOfTheOneRecording() + { + var factory = new FakeSessionFactory(); + var controller = ControllerFor(factory); + var viewModel = new RecordViewModel(new InMemoryLogSink(), controller); + + await viewModel.StartCommand.ExecuteAsync(null); + await DeliverAsync( + factory, + controller, + new RecordingProgress(RecordingStage.Recording, "Someone - Something", NowPlaying: "Someone - Something")); + + // Enrichment lands about a second in, and fills the card. + viewModel.Album = "An Album (2026)"; + viewModel.Destination = @"Someone\An Album\03 Something.mp3"; + + // Now the track before this one reaches disk. Three reports, all naming it, all arriving + // while "Someone - Something" is the song actually playing. + await DeliverAsync( + factory, + controller, + new RecordingProgress( + RecordingStage.Encoding, + "Earlier - Track", + TimeSpan.FromMinutes(4), + "Encoding Earlier - Track.", + NowPlaying: "Someone - Something", + ConcernsNowPlaying: false)); + + await DeliverAsync( + factory, + controller, + new RecordingProgress( + RecordingStage.Tagging, + "Earlier - Track", + NowPlaying: "Someone - Something", + ConcernsNowPlaying: false)); + + await DeliverAsync( + factory, + controller, + new RecordingProgress( + RecordingStage.WaitingForTrack, + "Earlier - Track", + TimeSpan.FromMinutes(4), + @"Saved Earlier\Earlier - Track.mp3", + NowPlaying: "Someone - Something", + ConcernsNowPlaying: false)); + + Assert.Equal("Someone - Something", viewModel.NowPlaying); + Assert.Equal("An Album (2026)", viewModel.Album); + Assert.Equal(@"Someone\An Album\03 Something.mp3", viewModel.Destination); + } + + /// + /// Same reports, the other half of the damage: they carry the finished recording's length and + /// a stage that is not what the session is doing, so the counter jumped to four minutes and + /// the transport claimed the app had stopped writing — both undone by the next tick, which is + /// what made it read as a flicker rather than as a wrong number. + /// + [Fact] + public async Task Progress_WhileThePreviousTrackFinishes_LeavesTheCounterAndTransportAlone() + { + var factory = new FakeSessionFactory(); + var controller = ControllerFor(factory); + var viewModel = new RecordViewModel(new InMemoryLogSink(), controller); + + await viewModel.StartCommand.ExecuteAsync(null); + await DeliverAsync( + factory, + controller, + new RecordingProgress( + RecordingStage.Recording, + "Someone - Something", + TimeSpan.FromSeconds(18), + NowPlaying: "Someone - Something")); + + await DeliverAsync( + factory, + controller, + new RecordingProgress( + RecordingStage.Encoding, + "Earlier - Track", + TimeSpan.FromMinutes(4), + "Encoding Earlier - Track.", + NowPlaying: "Someone - Something", + ConcernsNowPlaying: false)); + + Assert.Equal(TimeSpan.FromSeconds(18), viewModel.Elapsed); + Assert.True(viewModel.IsCapturing); + Assert.Equal(Strings.RecordTransportRecording, viewModel.Transport); + } + [Fact] public void FilterOptions_OfferOneChoicePerFilter() => Assert.Equal( @@ -525,6 +631,45 @@ private static Logger LoggerFor(InMemoryLogSink sink) => /// one report can raise several, and the interesting one is not always first. /// /// + /// + /// Reports progress and waits for it to have reached the view model, whether or not it + /// changed anything. + /// + /// + /// waits on a property, which is no use for a report whose whole + /// point is that it must leave the page alone — the condition is true before the report is + /// delivered and stays true after, so the assertion runs against a page that has not seen it + /// yet and passes for the wrong reason. This waits on the controller forwarding the very + /// instance that was reported. The view model subscribes in its constructor, so it is ahead + /// of this handler on the multicast list and has already applied the report by the time the + /// wait completes. + /// + private static async Task DeliverAsync( + FakeSessionFactory factory, + RecordingController controller, + RecordingProgress progress) + { + var delivered = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + + void OnForwarded(object? sender, RecordingProgress forwarded) + { + if (ReferenceEquals(forwarded, progress)) delivered.TrySetResult(); + } + + controller.Progress += OnForwarded; + + try + { + factory.Progress!.Report(progress); + + await delivered.Task.WaitAsync(TimeSpan.FromSeconds(10)); + } + finally + { + controller.Progress -= OnForwarded; + } + } + private static async Task ReportAsync( FakeSessionFactory factory, RecordViewModel viewModel, diff --git a/tests/Offstream.UI.Tests/ShellViewModelTests.cs b/tests/Offstream.UI.Tests/ShellViewModelTests.cs index a7834b6..2902cff 100644 --- a/tests/Offstream.UI.Tests/ShellViewModelTests.cs +++ b/tests/Offstream.UI.Tests/ShellViewModelTests.cs @@ -60,7 +60,10 @@ public async Task Progress_WithATrack_NamesItInTheTooltip() var tooltip = await TooltipAfter( viewModel, () => factory.Progress!.Report( - new RecordingProgress(RecordingStage.Recording, "Someone - Something"))); + new RecordingProgress( + RecordingStage.Recording, + "Someone - Something", + NowPlaying: "Someone - Something"))); Assert.Equal( string.Format(CultureInfo.CurrentCulture, RecordingFormat, "Someone - Something"), @@ -79,7 +82,10 @@ public async Task Stopping_ForgetsTheTrackItWasNaming() await TooltipAfter( viewModel, () => factory.Progress!.Report( - new RecordingProgress(RecordingStage.Recording, "Someone - Something"))); + new RecordingProgress( + RecordingStage.Recording, + "Someone - Something", + NowPlaying: "Someone - Something"))); await controller.StopAsync();