From 87ab6fe692c0941da5162d7932558f6060046d8a Mon Sep 17 00:00:00 2001 From: Igor Baranov Date: Mon, 14 Sep 2026 17:21:26 -0700 Subject: [PATCH 1/4] Fix ALSA playback clock after device recovery --- src/alsa_sink.cpp | 62 +++++++++++++++++++++++------------- src/sink_recovery.cpp | 14 ++++++++ src/sink_recovery.h | 12 +++++++ tests/sink_recovery_test.cpp | 21 ++++++++++++ 4 files changed, 86 insertions(+), 23 deletions(-) diff --git a/src/alsa_sink.cpp b/src/alsa_sink.cpp index 7992381..1b16f22 100644 --- a/src/alsa_sink.cpp +++ b/src/alsa_sink.cpp @@ -612,7 +612,11 @@ size_t AlsaAudioSink::write(const uint8_t* data, size_t length, uint32_t timeout ? this->bytes_per_frame_ : static_cast(this->last_format_.channels) * (static_cast(this->last_format_.bit_depth) / 8U); - return (frame == 0) ? length : length - (length % frame); + const size_t consumed = (frame == 0) ? length : length - (length % frame); + if (frame != 0) { + this->recovery_.discard_frames(static_cast(consumed / frame)); + } + return consumed; } bytes_per_frame = this->bytes_per_frame_; @@ -797,13 +801,15 @@ void AlsaAudioSink::poll(int64_t now_ms) { return; } - const std::lock_guard lock(this->device_mutex_); - if (this->last_format_.sample_rate == 0) { - return; // nothing was ever configured, so there is nothing to reopen at - } - if (!this->recovery_.rescan_due(now_ms)) { - return; - } + uint32_t discarded_frames = 0; + { + const std::lock_guard lock(this->device_mutex_); + if (this->last_format_.sample_rate == 0) { + return; // nothing was ever configured, so there is nothing to reopen at + } + if (!this->recovery_.rescan_due(now_ms)) { + return; + } // The expensive half of recovery, on the main loop because snd_pcm_open() cannot be bounded // and write() has a deadline to keep. It is also the attempt a *replugged* device needs, @@ -811,28 +817,38 @@ void AlsaAudioSink::poll(int64_t now_ms) { // the device name at open, so `hw:CARD=NAME` finds a card that has come back even on a // different index -- but only once it has come back, which an immediate retry is too early // for. - const StreamFormat format = this->last_format_; - this->close_device_(); // idempotent; recover_() has normally closed it already - if (!this->open_device_(format.sample_rate, format.channels, format.bit_depth)) { + const StreamFormat format = this->last_format_; + this->close_device_(); // idempotent; recover_() has normally closed it already + if (!this->open_device_(format.sample_rate, format.channels, format.bit_depth)) { // Reported as a failure, which is what buys another attempt behind a longer delay -- a // device still absent now may be back in a few seconds. open_device_() has already said // why, so this only has to say what happens next: quiet while more attempts are coming, // because each is a normal step of a replug, and loud once when the budget is gone. - this->recovery_.rescan_done(false); - const bool retrying = this->recovery_.pending(); - cli_log(retrying ? LogLevel::DEBUG : LogLevel::WARN, "alsa: '%s' is not back%s", - this->device_.c_str(), - retrying ? " -- trying again shortly" : " -- discarding until the next stream"); - return; - } - if (this->stopping_.load()) { + this->recovery_.rescan_done(false); + const bool retrying = this->recovery_.pending(); + cli_log(retrying ? LogLevel::DEBUG : LogLevel::WARN, "alsa: '%s' is not back%s", + this->device_.c_str(), retrying ? " -- trying again shortly" + : " -- discarding until the next stream"); + return; + } + if (this->stopping_.load()) { // stop() latches before it takes device_mutex_, so it can arrive while the open above is // running. Hand the device straight back rather than leave a live one for the destructor. - this->recovery_.rescan_done(true); // shutting down; there is nothing left to retry for - this->close_device_(); - return; + this->recovery_.rescan_done(true); // shutting down; nothing is left to retry for + this->close_device_(); + return; + } + this->recovery_.rescan_done(true); + discarded_frames = this->recovery_.take_discarded_frames(); + } + + // write() deliberately consumed audio while there was no device, keeping the sync task from + // spinning. Retire those frames before its first real post-recovery write: otherwise they + // remain in the task's buffered-frame count, and that first device timestamp projects the + // playhead ahead by the whole outage. Fire outside device_mutex_, like write()'s callback. + if (discarded_frames > 0 && this->on_frames_played) { + this->on_frames_played(discarded_frames, now_us()); } - this->recovery_.rescan_done(true); cli_log(LogLevel::INFO, "alsa: '%s' is back -- recovered without waiting for the next stream", this->device_.c_str()); } diff --git a/src/sink_recovery.cpp b/src/sink_recovery.cpp index 1b26ee5..9de4b15 100644 --- a/src/sink_recovery.cpp +++ b/src/sink_recovery.cpp @@ -14,6 +14,8 @@ #include "sink_recovery.h" +#include + namespace sendspin_cli { bool SinkRecovery::reopen_due() { @@ -86,6 +88,17 @@ bool SinkRecovery::pending() const { return this->rescan_owed_.load(std::memory_order_relaxed); } +void SinkRecovery::discard_frames(uint32_t frames) { + const uint32_t room = std::numeric_limits::max() - this->discarded_frames_; + this->discarded_frames_ += (frames < room) ? frames : room; +} + +uint32_t SinkRecovery::take_discarded_frames() { + const uint32_t frames = this->discarded_frames_; + this->discarded_frames_ = 0; + return frames; +} + void SinkRecovery::reset() { this->reopen_spent_ = false; this->rescan_spent_ = false; @@ -93,6 +106,7 @@ void SinkRecovery::reset() { this->rescan_attempts_ = 0; this->rescan_owed_.store(false, std::memory_order_relaxed); this->rescan_at_ms_ = NOT_STAMPED; + this->discarded_frames_ = 0; } void SinkRecovery::escalate_() { diff --git a/src/sink_recovery.h b/src/sink_recovery.h index 6f7bba1..b44175d 100644 --- a/src/sink_recovery.h +++ b/src/sink_recovery.h @@ -166,6 +166,17 @@ class SinkRecovery { /// as an errand for the main loop. bool pending() const; + /// Records frames the sink accepted only to discard while its device was absent. + /// + /// A sink normally reports playback progress as its device consumes frames. During an + /// outage it must keep accepting audio so the producer does not spin, but those accepted + /// frames still enter the producer's buffered-frame accounting. The count is returned when + /// the device comes back so the sink can retire that gap before reporting real playback. + void discard_frames(uint32_t frames); + + /// Returns and clears the frames accumulated by discard_frames(). + uint32_t take_discarded_frames(); + /// @brief Puts both attempts back in hand, for a configure() that really opened a stream. void reset(); @@ -197,6 +208,7 @@ class SinkRecovery { bool rescan_in_flight_{false}; /// How many second attempts have been handed out for this configured stream. int rescan_attempts_{0}; + uint32_t discarded_frames_{0}; /// Read by the main loop without the sink's lock; see pending(). std::atomic rescan_owed_{false}; int64_t rescan_at_ms_{NOT_STAMPED}; diff --git a/tests/sink_recovery_test.cpp b/tests/sink_recovery_test.cpp index 326df73..41e6b2b 100644 --- a/tests/sink_recovery_test.cpp +++ b/tests/sink_recovery_test.cpp @@ -25,6 +25,7 @@ #include #include +#include namespace sendspin_cli { namespace { @@ -88,6 +89,26 @@ TEST(SinkRecovery, AFailedReopenEscalatesToTheRescan) { EXPECT_TRUE(recovery.pending()); } +TEST(SinkRecovery, ReturnsTheDiscardedGapOnceWhenADeviceComesBack) { + SinkRecovery recovery; + escalate(recovery); + + // Fourteen seconds at the reporter's 48 kHz: these writes were accepted to prevent the + // producer spinning, but no DAC played them. + recovery.discard_frames(14U * 48'000U); + + EXPECT_EQ(recovery.take_discarded_frames(), 672'000U); + EXPECT_EQ(recovery.take_discarded_frames(), 0U); +} + +TEST(SinkRecovery, DiscardedGapSaturatesInsteadOfWrapping) { + SinkRecovery recovery; + recovery.discard_frames(std::numeric_limits::max() - 10U); + recovery.discard_frames(100U); + + EXPECT_EQ(recovery.take_discarded_frames(), std::numeric_limits::max()); +} + TEST(SinkRecovery, EveryFurtherWriteOfTheOutageIsToldToDiscard) { SinkRecovery recovery; escalate(recovery); From 0dfadde7162983b8828557356ce688f184dbecc8 Mon Sep 17 00:00:00 2001 From: Chris Uthe Date: Tue, 15 Sep 2026 14:10:44 -0500 Subject: [PATCH 2/4] Let SinkRecovery drop the discarded gap without touching the budget --- src/sink_recovery.cpp | 4 +++ src/sink_recovery.h | 15 ++++++++-- tests/sink_recovery_test.cpp | 57 ++++++++++++++++++++++++++++++++++++ 3 files changed, 74 insertions(+), 2 deletions(-) diff --git a/src/sink_recovery.cpp b/src/sink_recovery.cpp index 9de4b15..cb3ff76 100644 --- a/src/sink_recovery.cpp +++ b/src/sink_recovery.cpp @@ -99,6 +99,10 @@ uint32_t SinkRecovery::take_discarded_frames() { return frames; } +void SinkRecovery::forget_discarded_frames() { + this->discarded_frames_ = 0; +} + void SinkRecovery::reset() { this->reopen_spent_ = false; this->rescan_spent_ = false; diff --git a/src/sink_recovery.h b/src/sink_recovery.h index b44175d..bd8d17c 100644 --- a/src/sink_recovery.h +++ b/src/sink_recovery.h @@ -170,13 +170,22 @@ class SinkRecovery { /// /// A sink normally reports playback progress as its device consumes frames. During an /// outage it must keep accepting audio so the producer does not spin, but those accepted - /// frames still enter the producer's buffered-frame accounting. The count is returned when - /// the device comes back so the sink can retire that gap before reporting real playback. + /// frames still enter the producer's buffered-frame accounting. The count stays pending -- + /// through a rescan that recovers, too -- until the sink's first write with a real device + /// timestamp takes it and retires it in that same report. A reopen alone has no timestamp to + /// retire it against. Saturates rather than wraps. void discard_frames(uint32_t frames); /// Returns and clears the frames accumulated by discard_frames(). uint32_t take_discarded_frames(); + /// @brief Drops the discarded-frame count without touching the recovery budget. + /// + /// For a stream that ended or was replaced before its gap could be retired: the producer + /// starts the next one from zero buffered frames, so the old gap is owed to nobody. Not + /// reset(), because a flush is not a configure() that got a device running. + void forget_discarded_frames(); + /// @brief Puts both attempts back in hand, for a configure() that really opened a stream. void reset(); @@ -208,6 +217,8 @@ class SinkRecovery { bool rescan_in_flight_{false}; /// How many second attempts have been handed out for this configured stream. int rescan_attempts_{0}; + /// Frames accepted with no device to play them and not yet retired; see discard_frames(). + /// Under the sink's lock like the rest, so a write() takes it atomically with its timestamp. uint32_t discarded_frames_{0}; /// Read by the main loop without the sink's lock; see pending(). std::atomic rescan_owed_{false}; diff --git a/tests/sink_recovery_test.cpp b/tests/sink_recovery_test.cpp index 41e6b2b..96b1215 100644 --- a/tests/sink_recovery_test.cpp +++ b/tests/sink_recovery_test.cpp @@ -109,6 +109,63 @@ TEST(SinkRecovery, DiscardedGapSaturatesInsteadOfWrapping) { EXPECT_EQ(recovery.take_discarded_frames(), std::numeric_limits::max()); } +TEST(SinkRecovery, TheDiscardedGapOutlivesARecoveredRescanUntilTaken) { + SinkRecovery recovery; + escalate(recovery); + recovery.discard_frames(48'000U); + ASSERT_GE(rescan_fires_at(recovery, T0, T0 + 10 * SINK_RESCAN_DELAY_MS), T0); + + // The reopen has no device timestamp to retire the gap against; the first timed write does. + recovery.rescan_done(true); + + EXPECT_EQ(recovery.take_discarded_frames(), 48'000U); + EXPECT_EQ(recovery.take_discarded_frames(), 0U); +} + +TEST(SinkRecovery, ForgettingTheDiscardedGapLeavesTheBudgetAlone) { + SinkRecovery recovery; + escalate(recovery); + recovery.discard_frames(48'000U); + + // What a flush does with no device open. A flush is not a stream that got a device running, + // so the outage it happened in is still owed exactly what it was before. + recovery.forget_discarded_frames(); + + EXPECT_EQ(recovery.take_discarded_frames(), 0U); + EXPECT_TRUE(recovery.pending()); + EXPECT_FALSE(recovery.reopen_due()); + EXPECT_EQ(rescan_fires_at(recovery, T0, T0 + 10 * SINK_RESCAN_DELAY_MS), + T0 + SINK_RESCAN_DELAY_MS); +} + +TEST(SinkRecovery, ForgettingTheDiscardedGapDoesNotRefillASpentBudget) { + SinkRecovery recovery; + escalate(recovery); + int64_t now = T0; + for (int attempt = 0; attempt < SINK_RESCAN_ATTEMPTS; ++attempt) { + now = rescan_fires_at(recovery, now, now + 100 * SINK_RESCAN_DELAY_MS); + ASSERT_GT(now, 0) << "attempt " << attempt << " never fired"; + recovery.rescan_done(false); + } + recovery.discard_frames(48'000U); + + recovery.forget_discarded_frames(); + + EXPECT_FALSE(recovery.pending()); + EXPECT_FALSE(recovery.reopen_due()); + EXPECT_EQ(rescan_fires_at(recovery, now, now + 100 * SINK_RESCAN_DELAY_MS), -1); +} + +TEST(SinkRecovery, ResetClearsTheDiscardedGap) { + SinkRecovery recovery; + escalate(recovery); + recovery.discard_frames(48'000U); + + recovery.reset(); + + EXPECT_EQ(recovery.take_discarded_frames(), 0U); +} + TEST(SinkRecovery, EveryFurtherWriteOfTheOutageIsToldToDiscard) { SinkRecovery recovery; escalate(recovery); From a6b1c233148851cf7d1ebab733faf879f5bf028c Mon Sep 17 00:00:00 2001 From: Chris Uthe Date: Tue, 15 Sep 2026 14:10:44 -0500 Subject: [PATCH 3/4] Retire the ALSA outage gap with the first timed write poll() reported the gap after releasing the lock, so the sync task's first real write could report first and still carry the whole outage. Take the gap with the first device timestamp instead and report both in one call. Also drop the gap on clear() and configure(), and count frames written just before the device was lost. --- src/alsa_sink.cpp | 86 ++++++++++++++++++++++++++++------------------- 1 file changed, 51 insertions(+), 35 deletions(-) diff --git a/src/alsa_sink.cpp b/src/alsa_sink.cpp index 1b16f22..7843154 100644 --- a/src/alsa_sink.cpp +++ b/src/alsa_sink.cpp @@ -27,6 +27,7 @@ #include #include #include +#include #include #include #include @@ -544,6 +545,9 @@ bool AlsaAudioSink::configure(uint32_t sample_rate, uint8_t channels, uint8_t bi // Before anything below can fail: this is the format the player is about to send audio in // whether or not a device takes it, which is the question poll() asks when it reopens. this->last_format_ = {sample_rate, channels, bits_per_sample}; + // A new stream starts the producer from zero buffered frames, so an outage gap left over from + // the last one is owed to nobody. Here rather than beside reset(), which a failed open skips. + this->recovery_.forget_discarded_frames(); if (this->pcm_ != nullptr && this->rate_ == sample_rate && this->channels_ == channels && this->bits_ == bits_per_sample) { @@ -590,6 +594,7 @@ size_t AlsaAudioSink::write(const uint8_t* data, size_t length, uint32_t timeout size_t bytes_per_frame = 0; int64_t finish_us = 0; bool have_timing = false; + uint32_t gap_frames = 0; { const std::lock_guard lock(this->device_mutex_); @@ -721,15 +726,31 @@ size_t AlsaAudioSink::write(const uint8_t* data, size_t length, uint32_t timeout if (snd_pcm_delay(this->pcm_, &delay) == 0 && delay >= 0) { finish_us = now_us() + ((static_cast(delay) * 1000000) / this->rate_); have_timing = true; + // Taken with the timestamp, under the same lock, so no report can land between the + // outage being retired and the first real playback being reported. + gap_frames = this->recovery_.take_discarded_frames(); } } + + // recover_() closed the device after the loop had already written part of the buffer. + // Those bytes are returned as consumed but no timestamp will report them, so they join + // the outage's gap. + if (frames_done > 0 && this->pcm_ == nullptr) { + this->recovery_.discard_frames(static_cast(frames_done)); + } } // Fired outside the lock: notify_audio_played() runs the player's own bookkeeping, and // holding the device mutex across a callback is how a future callback that touches the // sink would deadlock. + // + // One report for the outage gap and this write together, carrying the device's finish time. + // The player sums frames across reports it has not read yet but keeps only the last + // timestamp, so a separate gap report could only lose that timestamp or arrive too late. if (have_timing && this->on_frames_played) { - this->on_frames_played(static_cast(frames_done), finish_us); + const uint64_t played = static_cast(gap_frames) + frames_done; + const uint64_t ceiling = std::numeric_limits::max(); + this->on_frames_played(static_cast(std::min(played, ceiling)), finish_us); } return frames_done * bytes_per_frame; @@ -748,6 +769,11 @@ void AlsaAudioSink::clear() { // discriminator is the threading model, not the audio: do not harmonise the two. this->current_multiplier_ = this->target_multiplier_.load(std::memory_order_relaxed); + // Also before the early return: the stream an outage gap belonged to is over, and the player + // zeroes its buffered-frame count with it. Only the gap goes -- the recovery budget is + // configure()'s to refill. + this->recovery_.forget_discarded_frames(); + if (this->pcm_ == nullptr) { return; } @@ -801,15 +827,13 @@ void AlsaAudioSink::poll(int64_t now_ms) { return; } - uint32_t discarded_frames = 0; - { - const std::lock_guard lock(this->device_mutex_); - if (this->last_format_.sample_rate == 0) { - return; // nothing was ever configured, so there is nothing to reopen at - } - if (!this->recovery_.rescan_due(now_ms)) { - return; - } + const std::lock_guard lock(this->device_mutex_); + if (this->last_format_.sample_rate == 0) { + return; // nothing was ever configured, so there is nothing to reopen at + } + if (!this->recovery_.rescan_due(now_ms)) { + return; + } // The expensive half of recovery, on the main loop because snd_pcm_open() cannot be bounded // and write() has a deadline to keep. It is also the attempt a *replugged* device needs, @@ -817,38 +841,30 @@ void AlsaAudioSink::poll(int64_t now_ms) { // the device name at open, so `hw:CARD=NAME` finds a card that has come back even on a // different index -- but only once it has come back, which an immediate retry is too early // for. - const StreamFormat format = this->last_format_; - this->close_device_(); // idempotent; recover_() has normally closed it already - if (!this->open_device_(format.sample_rate, format.channels, format.bit_depth)) { + const StreamFormat format = this->last_format_; + this->close_device_(); // idempotent; recover_() has normally closed it already + if (!this->open_device_(format.sample_rate, format.channels, format.bit_depth)) { // Reported as a failure, which is what buys another attempt behind a longer delay -- a // device still absent now may be back in a few seconds. open_device_() has already said // why, so this only has to say what happens next: quiet while more attempts are coming, // because each is a normal step of a replug, and loud once when the budget is gone. - this->recovery_.rescan_done(false); - const bool retrying = this->recovery_.pending(); - cli_log(retrying ? LogLevel::DEBUG : LogLevel::WARN, "alsa: '%s' is not back%s", - this->device_.c_str(), retrying ? " -- trying again shortly" - : " -- discarding until the next stream"); - return; - } - if (this->stopping_.load()) { + this->recovery_.rescan_done(false); + const bool retrying = this->recovery_.pending(); + cli_log(retrying ? LogLevel::DEBUG : LogLevel::WARN, "alsa: '%s' is not back%s", + this->device_.c_str(), + retrying ? " -- trying again shortly" : " -- discarding until the next stream"); + return; + } + if (this->stopping_.load()) { // stop() latches before it takes device_mutex_, so it can arrive while the open above is // running. Hand the device straight back rather than leave a live one for the destructor. - this->recovery_.rescan_done(true); // shutting down; nothing is left to retry for - this->close_device_(); - return; - } - this->recovery_.rescan_done(true); - discarded_frames = this->recovery_.take_discarded_frames(); - } - - // write() deliberately consumed audio while there was no device, keeping the sync task from - // spinning. Retire those frames before its first real post-recovery write: otherwise they - // remain in the task's buffered-frame count, and that first device timestamp projects the - // playhead ahead by the whole outage. Fire outside device_mutex_, like write()'s callback. - if (discarded_frames > 0 && this->on_frames_played) { - this->on_frames_played(discarded_frames, now_us()); + this->recovery_.rescan_done(true); // shutting down; there is nothing left to retry for + this->close_device_(); + return; } + // The outage's discarded frames stay pending: write() retires them with its first device + // timestamp. Reporting them from here would race that write for the player's bookkeeping. + this->recovery_.rescan_done(true); cli_log(LogLevel::INFO, "alsa: '%s' is back -- recovered without waiting for the next stream", this->device_.c_str()); } From c5b52797b1a53fafbdb7197b64a3d040fd0866c4 Mon Sep 17 00:00:00 2001 From: Chris Uthe Date: Tue, 15 Sep 2026 21:45:05 -0500 Subject: [PATCH 4/4] Trim the gap tests' comments to one line each --- tests/sink_recovery_test.cpp | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/tests/sink_recovery_test.cpp b/tests/sink_recovery_test.cpp index 4c81400..3ecc696 100644 --- a/tests/sink_recovery_test.cpp +++ b/tests/sink_recovery_test.cpp @@ -80,8 +80,7 @@ TEST(SinkRecovery, ReturnsTheDiscardedGapOnceWhenADeviceComesBack) { SinkRecovery recovery; escalate(recovery); - // Fourteen seconds at the reporter's 48 kHz: these writes were accepted to prevent the - // producer spinning, but no DAC played them. + // Fourteen seconds at 48 kHz, accepted while no DAC played them. recovery.discard_frames(14U * 48'000U); EXPECT_EQ(recovery.take_discarded_frames(), 672'000U); @@ -114,8 +113,7 @@ TEST(SinkRecovery, ForgettingTheDiscardedGapLeavesTheBudgetAlone) { escalate(recovery); recovery.discard_frames(48'000U); - // What a flush does with no device open. A flush is not a stream that got a device running, - // so the outage it happened in is still owed exactly what it was before. + // What a flush does with no device open: the outage is still owed what it was. recovery.forget_discarded_frames(); EXPECT_EQ(recovery.take_discarded_frames(), 0U);