fix(android): notice when a Sonos stops on its own, and get it going again — #2700
android / Build + lint + test (push) Successful in 3m57s

The 2026-08-16 diagnostics show a session that did not stutter so much
as end. In Doze the 1Hz poll freezes -- 14:22:53 and 14:26:14 report
byte-identical snapshots, and that flat 5000ms sonos-vs-local delta is
the last poll's staleness held still, not drift. When the screen came
back on, the first poll in 3.5 minutes found queue track 10 at 113s,
stopped. The Sonos had advanced, played 1:53 of a flac and quit while
the phone slept. The app then reported that faithfully and did nothing
about it, twice more, until the operator noticed.

A UPnP renderer streams autonomously, which is the whole point of
casting and also why a dead stream is invisible: pollOnce read STOPPED,
called applyTransportStopped and returned. Nothing asked "we meant to
be playing -- why aren't we?"

RemoteStallWatchdog asks. It is pure decision state -- no coroutines, no
SOAP -- so the counting, keying and giving-up is testable without a
renderer, and pollOnce just acts on the verdict.

Conservative by construction:
  - STOPPED or an error status only. PAUSED is left alone: that is
    somebody at the Sonos app or a wall controller, and taking the
    transport back off a person is a fight they always lose. A stream
    that dies stops, it does not pause.
  - Only against play intent. A stop we asked for is not a stall.
  - Three consecutive polls must agree. Sonos passes through STOPPED
    between queue items, so one reading would make every track change
    fight itself.
  - Three attempts per track, 5s apart, then give up -- an unplayable
    file must not become an infinite retry loop against a speaker.
  - Resume seeks back to the last position seen while playing, so a
    stream that died 90s in comes back near there, not at zero.

GetTransportInfo now keeps CurrentTransportStatus, which it previously
parsed and discarded. ERROR_OCCURRED is the only unambiguous way to
tell "the stream died" from "somebody pressed stop", since both land in
STOPPED. Absent or unrecognised reads as OK so a quiet renderer is
never mistaken for a broken one.

Giving up reports kind="stalled" through the existing
PlaybackErrorReporter: snackbar for the user, admin-inbox row for the
operator. That kind has been in migration 0032's CHECK whitelist and
labelled on the admin page since the table was built, and nothing had
ever emitted it.

This does not explain WHY the stream died -- see #2700 for the
hairpin-routing lead. It does mean a dropout is a recoverable hiccup
instead of the end of the session.
This commit is contained in:
2026-08-16 12:43:17 -04:00
parent a31b672b14
commit d9238ec5be
6 changed files with 456 additions and 2 deletions
@@ -15,6 +15,7 @@ import com.fabledsword.minstrel.connectivity.ServerHealth
import com.fabledsword.minstrel.player.output.ActiveUpnp
import com.fabledsword.minstrel.player.output.ActiveUpnpHolder
import com.fabledsword.minstrel.player.output.upnp.SoapFaultException
import com.fabledsword.minstrel.player.output.upnp.TransportInfo
import com.fabledsword.minstrel.player.output.upnp.TransportState
import java.io.IOException
import kotlin.math.abs
@@ -71,12 +72,18 @@ class MinstrelForwardingPlayer(
private val castNetworkLock: CastNetworkLock,
private val networkStatus: NetworkStatusController,
private val onDrop: (routeName: String) -> Unit,
private val onStalled: (trackId: String) -> Unit = {},
) : ForwardingPlayer(delegate) {
private val scope = CoroutineScope(SupervisorJob() + Dispatchers.IO)
private val handler = Handler(delegate.applicationLooper)
private var pollJob: Job? = null
// Watches for the renderer stopping without being asked to. A UPnP
// renderer streams on its own, so a stream that dies looks like silence
// and nothing else in the app would notice -- see [RemoteStallWatchdog].
private val stallWatchdog = RemoteStallWatchdog()
// Tracks consecutive non-PLAYING poll observations so a single transient
// PAUSED_PLAYBACK / STOPPED tick during a Sonos track transition does not
// flip the play/pause button. Manual pause still feels instant because it
@@ -492,6 +499,9 @@ class MinstrelForwardingPlayer(
} else {
castNetworkLock.release()
remoteState.reset()
// The next cast starts with a clean attempt budget; a stall on the
// route we just left says nothing about the next one.
stallWatchdog.reset()
}
}
@@ -584,9 +594,63 @@ class MinstrelForwardingPlayer(
}
TransportState.TRANSITIONING, TransportState.UNKNOWN -> Unit
}
checkForStall(active, info.trackUri, transport)
notifyRemoteStateChanged()
}
/**
* Ask the watchdog what to make of this poll, and act on its answer.
*
* Recovery re-issues Play and then seeks back to the last position the
* renderer was observed playing, so a stream that died 90 seconds into a
* track resumes near there rather than restarting it. The seek is
* best-effort and deliberately after the play: a renderer that refuses
* the seek is still better off playing from zero than silent.
*/
private suspend fun checkForStall(
active: ActiveUpnp,
trackUri: String,
transport: TransportInfo,
) {
val decision = stallWatchdog.onPoll(
trackUri = trackUri,
state = transport.state,
statusOk = transport.statusOk,
playIntent = remoteState.lastPlayIntent,
positionMs = remoteState.positionMs,
nowMs = SystemClock.elapsedRealtime(),
)
when (decision) {
is RemoteStallWatchdog.Decision.Resume -> {
Timber.w(
"UPnP stall on %s: renderer stopped unasked (status_ok=%b), " +
"resume attempt %d at %dms",
active.routeName, transport.statusOk, decision.attempt, decision.resumeAtMs,
)
runCatching {
retryTransport { active.avTransport.play() }
if (decision.resumeAtMs > 0L) {
retryTransport { active.avTransport.seek(decision.resumeAtMs) }
}
}.onFailure {
// Leave the streak alone: a failed recovery is more
// evidence of a stall, and the next poll re-decides.
Timber.w(it, "UPnP stall: resume attempt failed on %s", active.routeName)
}
}
RemoteStallWatchdog.Decision.GiveUp -> {
Timber.w(
"UPnP stall on %s: giving up after repeated resume attempts",
active.routeName,
)
// Tell the user and the admin inbox. Silence here would be the
// original bug: playback simply ends and nobody finds out.
trackIdFromStreamUri(trackUri)?.let { handler.post { onStalled(it) } }
}
RemoteStallWatchdog.Decision.None -> Unit
}
}
/**
* Align the paused local delegate cursor to the track the renderer is
* actually playing, so the un-overridden current-item getters
@@ -128,6 +128,28 @@ class PlayerController @Inject constructor(
*/
private var queueRefs: List<TrackRef> = emptyList()
init {
// A remote stall that survived the watchdog's retries is a playback
// failure like any other: the user gets the snackbar and the operator
// gets an admin-inbox row, via the same reporter that handles dead
// files. Without this the session just ends in silence -- the exact
// failure the watchdog exists to surface.
scope.launch {
playerFactory.stallEvents.collect { trackId ->
val title = queueRefs.firstOrNull { it.id == trackId }?.title
?.takeIf { it.isNotEmpty() } ?: "Track"
playbackErrorEventsChannel.trySend(
PlaybackErrorEvent(
trackId = trackId,
kind = "stalled",
title = title,
detail = "remote renderer stopped and would not resume",
),
)
}
}
}
/**
* Completes when [mediaController] is non-null and the listener has
* been attached. Used by [awaitReady] so cold-boot callers like
@@ -75,6 +75,15 @@ class PlayerFactory @Inject constructor(
)
val dropEvents: SharedFlow<String> = dropEventsInternal.asSharedFlow()
// Track ids whose remote playback stalled and could not be resumed. Same
// buffering rationale as dropEvents: a burst is one problem, not N.
private val stallEventsInternal = MutableSharedFlow<String>(
replay = 0,
extraBufferCapacity = 1,
onBufferOverflow = BufferOverflow.DROP_OLDEST,
)
val stallEvents: SharedFlow<String> = stallEventsInternal.asSharedFlow()
fun build(): Player {
val exo = buildExoPlayer()
return MinstrelForwardingPlayer(
@@ -84,6 +93,7 @@ class PlayerFactory @Inject constructor(
castNetworkLock = CastNetworkLock(context),
networkStatus = serverHealth,
onDrop = { name -> emitDrop(name) },
onStalled = { trackId -> stallEventsInternal.tryEmit(trackId) },
)
}
@@ -0,0 +1,159 @@
package com.fabledsword.minstrel.player
import com.fabledsword.minstrel.player.output.upnp.TransportState
/**
* Notices when a UPnP renderer has stopped playing without being asked, and
* decides whether to try getting it going again.
*
* The gap this closes (diagnostics 2026-08-16): a Sonos playing from the
* server stopped by itself mid-track while the phone was in Doze. The poll
* loop was frozen, so nothing saw it; when the screen came back on the app
* faithfully reported "queue track 10, position 113s, not playing" and then
* sat there. Playback was over and no part of the app considered that a
* problem. A renderer streams autonomously, which is exactly why a failed
* stream is invisible without something watching for it.
*
* Deliberately conservative about what counts as a stall:
*
* - Only STOPPED (or a transport reporting an error) triggers recovery.
* PAUSED is left alone: the likely cause is a person pausing from the
* Sonos app or a wall controller, and fighting them for the transport is
* obnoxious. A stream that dies stops, it does not pause.
* - Only when the operator's last intent was to play. A stop we asked for
* is not a stall.
* - Only after [STALL_CONFIRM_POLLS] consecutive polls agree, so a single
* reading during a track change (Sonos passes through STOPPED and
* TRANSITIONING between queue items) never trips it.
* - At most [MAX_RESUME_ATTEMPTS] per track, spaced by
* [RETRY_SPACING_MS]. A genuinely unplayable file must not become an
* infinite retry loop against the renderer.
*
* Pure decision state, no coroutines and no SOAP: the caller owns the poll
* loop and performs the transport calls, this only says what should happen.
* That keeps the awkward part — counting, keying and giving up — testable
* without a renderer.
*/
class RemoteStallWatchdog {
sealed interface Decision {
/** Nothing to do. */
data object None : Decision
/**
* Ask the renderer to play again. [resumeAtMs] is the last position
* observed while it was actually playing, so the caller can seek back
* to roughly where the listener was rather than restarting the track.
*/
data class Resume(val attempt: Int, val resumeAtMs: Long) : Decision
/** Attempts are exhausted. Report it and stop trying for this track. */
data object GiveUp : Decision
}
private var trackKey: String = ""
private var lastPlayingPositionMs: Long = 0L
private var stoppedStreak: Int = 0
private var attempts: Int = 0
private var lastAttemptAtMs: Long = 0L
private var gaveUp: Boolean = false
/**
* Feed one poll result in, get the action out.
*
* @param trackUri the renderer's current track URI — identity for the
* per-track attempt budget, so moving to the next track forgives a
* previous one's failures.
* @param statusOk the transport's own status flag: false means the
* renderer is reporting an error rather than merely being stopped.
* @param playIntent the operator's last play/pause intent.
* @param nowMs a monotonic clock (SystemClock.elapsedRealtime), passed in
* so tests can drive time.
*/
@Suppress("ReturnCount") // early returns per state are clearer than nesting
fun onPoll(
trackUri: String,
state: TransportState,
statusOk: Boolean,
playIntent: Boolean,
positionMs: Long,
nowMs: Long,
): Decision {
if (trackUri != trackKey) {
// New track: a fresh attempt budget, and no inherited stall state.
trackKey = trackUri
resetStall()
attempts = 0
gaveUp = false
lastPlayingPositionMs = 0L
}
if (!playIntent) {
// Stopped because we asked. Not a stall, and the next genuine one
// should start from a clean budget.
resetStall()
attempts = 0
gaveUp = false
return Decision.None
}
if (state == TransportState.PLAYING && statusOk) {
lastPlayingPositionMs = positionMs
resetStall()
// A track that recovered and is playing again has earned back its
// budget; a later, unrelated stall on the same track should get
// the full set of attempts rather than the remainder.
attempts = 0
return Decision.None
}
val stalled = state == TransportState.STOPPED || !statusOk
if (!stalled) {
// PAUSED (someone else's doing) or TRANSITIONING/UNKNOWN (in
// flight). Neither is a stall; drop the streak so a mid-track
// transition doesn't accumulate toward one.
resetStall()
return Decision.None
}
stoppedStreak += 1
if (stoppedStreak < STALL_CONFIRM_POLLS) return Decision.None
if (gaveUp) return Decision.None
if (attempts >= MAX_RESUME_ATTEMPTS) {
gaveUp = true
return Decision.GiveUp
}
if (attempts > 0 && nowMs - lastAttemptAtMs < RETRY_SPACING_MS) return Decision.None
attempts += 1
lastAttemptAtMs = nowMs
return Decision.Resume(attempt = attempts, resumeAtMs = lastPlayingPositionMs)
}
/** Forget everything — call when the route changes or playback is torn down. */
fun reset() {
trackKey = ""
lastPlayingPositionMs = 0L
resetStall()
attempts = 0
lastAttemptAtMs = 0L
gaveUp = false
}
private fun resetStall() {
stoppedStreak = 0
}
private companion object {
// At the 1s poll cadence this is ~3s of agreement. Sonos passes
// through STOPPED between queue items, so one or two readings mean
// nothing on their own.
const val STALL_CONFIRM_POLLS = 3
// Three tries at ~5s spacing covers a server blip or a dropped
// connection without hammering a renderer whose file is simply bad.
const val MAX_RESUME_ATTEMPTS = 3
const val RETRY_SPACING_MS = 5_000L
}
}
@@ -225,7 +225,14 @@ class AVTransportClient(
"TRANSITIONING" -> TransportState.TRANSITIONING
else -> TransportState.UNKNOWN
}
return TransportInfo(state)
// CurrentTransportStatus is the renderer's own verdict on whether it is
// healthy, and it is the one unambiguous way to tell "the stream died"
// from "somebody pressed stop" — both of which land in STOPPED. The
// spec defines OK and ERROR_OCCURRED; anything unrecognised (or absent,
// which some renderers do) is read as OK so a quiet device is never
// treated as a broken one.
val statusOk = result["CurrentTransportStatus"]?.let { it != "ERROR_OCCURRED" } ?: true
return TransportInfo(state, statusOk)
}
private fun buildDidlLite(uri: String, mime: String, title: String): String {
@@ -293,4 +300,9 @@ data class PositionInfo(
enum class TransportState { PLAYING, PAUSED, STOPPED, TRANSITIONING, UNKNOWN }
data class TransportInfo(val state: TransportState)
/**
* [statusOk] is CurrentTransportStatus, defaulted true so the many call sites
* that only care about [state] read unchanged and an older/quieter renderer is
* never mistaken for a failing one.
*/
data class TransportInfo(val state: TransportState, val statusOk: Boolean = true)
@@ -0,0 +1,187 @@
package com.fabledsword.minstrel.player
import com.fabledsword.minstrel.player.output.upnp.TransportState
import org.junit.jupiter.api.Test
import kotlin.test.assertEquals
import kotlin.test.assertIs
import kotlin.test.assertTrue
class RemoteStallWatchdogTest {
private val uri = "http://server/api/tracks/t-1/stream.flac"
private val other = "http://server/api/tracks/t-2/stream.flac"
/** Feed one poll, defaulting everything to "playing normally". */
private fun RemoteStallWatchdog.poll(
trackUri: String = uri,
state: TransportState = TransportState.PLAYING,
statusOk: Boolean = true,
playIntent: Boolean = true,
positionMs: Long = 0L,
nowMs: Long = 0L,
) = onPoll(trackUri, state, statusOk, playIntent, positionMs, nowMs)
/** Drive [n] stopped polls and return the last decision. */
private fun RemoteStallWatchdog.stopFor(
n: Int,
nowMs: Long = 0L,
): RemoteStallWatchdog.Decision {
var last: RemoteStallWatchdog.Decision = RemoteStallWatchdog.Decision.None
repeat(n) { last = poll(state = TransportState.STOPPED, nowMs = nowMs) }
return last
}
@Test
fun `playing normally asks for nothing`() {
val w = RemoteStallWatchdog()
repeat(10) { assertIs<RemoteStallWatchdog.Decision.None>(w.poll(positionMs = it * 1000L)) }
}
@Test
fun `a stop we asked for is not a stall`() {
val w = RemoteStallWatchdog()
repeat(10) {
assertIs<RemoteStallWatchdog.Decision.None>(
w.poll(state = TransportState.STOPPED, playIntent = false),
)
}
}
/**
* Sonos passes through STOPPED between queue items. One or two readings
* must never trigger a resume or every track change would fight itself.
*/
@Test
fun `a brief stop during a track transition is ignored`() {
val w = RemoteStallWatchdog()
assertIs<RemoteStallWatchdog.Decision.None>(w.stopFor(2))
}
@Test
fun `a sustained unrequested stop asks for a resume`() {
val w = RemoteStallWatchdog()
val decision = w.stopFor(3)
assertIs<RemoteStallWatchdog.Decision.Resume>(decision)
assertEquals(1, decision.attempt)
}
/** The point of the resume: come back where the listener was. */
@Test
fun `resume carries the last position seen while playing`() {
val w = RemoteStallWatchdog()
w.poll(state = TransportState.PLAYING, positionMs = 113_000L)
val decision = w.stopFor(3)
assertIs<RemoteStallWatchdog.Decision.Resume>(decision)
assertEquals(113_000L, decision.resumeAtMs)
}
/**
* Someone pausing from the Sonos app or a wall controller owns the
* transport. Grabbing it back would be a fight the user always loses.
*/
@Test
fun `a pause from elsewhere is left alone`() {
val w = RemoteStallWatchdog()
repeat(10) {
assertIs<RemoteStallWatchdog.Decision.None>(w.poll(state = TransportState.PAUSED))
}
}
@Test
fun `transitioning is not treated as a stall`() {
val w = RemoteStallWatchdog()
repeat(10) {
assertIs<RemoteStallWatchdog.Decision.None>(
w.poll(state = TransportState.TRANSITIONING),
)
}
}
/**
* A renderer reporting ERROR_OCCURRED is the unambiguous signal, and it
* should not have to also say STOPPED before we act.
*/
@Test
fun `a transport reporting an error counts as a stall`() {
val w = RemoteStallWatchdog()
var last: RemoteStallWatchdog.Decision = RemoteStallWatchdog.Decision.None
repeat(3) { last = w.poll(state = TransportState.PLAYING, statusOk = false) }
assertIs<RemoteStallWatchdog.Decision.Resume>(last)
}
@Test
fun `retries are spaced out rather than fired every poll`() {
val w = RemoteStallWatchdog()
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(3, nowMs = 0L))
// Immediately after, still stopped: too soon to try again.
assertIs<RemoteStallWatchdog.Decision.None>(w.stopFor(1, nowMs = 1_000L))
assertIs<RemoteStallWatchdog.Decision.None>(w.stopFor(1, nowMs = 4_999L))
// Past the spacing, the next attempt goes out.
val second = w.stopFor(1, nowMs = 5_000L)
assertIs<RemoteStallWatchdog.Decision.Resume>(second)
assertEquals(2, second.attempt)
}
/**
* The failure this guards against is an unplayable file turning into an
* endless retry loop against the renderer.
*/
@Test
fun `attempts are capped and then it gives up exactly once`() {
val w = RemoteStallWatchdog()
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(3, nowMs = 0L))
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(1, nowMs = 5_000L))
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(1, nowMs = 10_000L))
assertIs<RemoteStallWatchdog.Decision.GiveUp>(w.stopFor(1, nowMs = 15_000L))
// Reported once; after that it stays quiet instead of spamming.
repeat(20) {
assertIs<RemoteStallWatchdog.Decision.None>(w.stopFor(1, nowMs = 20_000L + it * 5_000L))
}
}
@Test
fun `moving to another track restores the attempt budget`() {
val w = RemoteStallWatchdog()
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(3, nowMs = 0L))
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(1, nowMs = 5_000L))
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(1, nowMs = 10_000L))
assertIs<RemoteStallWatchdog.Decision.GiveUp>(w.stopFor(1, nowMs = 15_000L))
// A different track is a different problem.
w.poll(trackUri = other, state = TransportState.PLAYING, nowMs = 16_000L)
w.poll(trackUri = other, state = TransportState.STOPPED, nowMs = 20_000L)
w.poll(trackUri = other, state = TransportState.STOPPED, nowMs = 20_000L)
// Held in a val: a var mutated inside a lambda can't be smart-cast.
val onNewTrack = w.poll(trackUri = other, state = TransportState.STOPPED, nowMs = 20_000L)
assertIs<RemoteStallWatchdog.Decision.Resume>(onNewTrack)
assertEquals(1, onNewTrack.attempt)
}
/**
* A track that stalls, recovers and stalls again later gets the full
* budget the second time — otherwise one bad patch early in a long track
* would leave it defenceless for the rest.
*/
@Test
fun `recovering to playing restores the attempt budget`() {
val w = RemoteStallWatchdog()
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(3, nowMs = 0L))
w.poll(state = TransportState.PLAYING, positionMs = 60_000L, nowMs = 6_000L)
val again = w.stopFor(3, nowMs = 30_000L)
assertIs<RemoteStallWatchdog.Decision.Resume>(again)
assertEquals(1, again.attempt)
assertEquals(60_000L, again.resumeAtMs)
}
@Test
fun `reset forgets everything`() {
val w = RemoteStallWatchdog()
assertIs<RemoteStallWatchdog.Decision.Resume>(w.stopFor(3, nowMs = 0L))
w.reset()
val afterReset = w.stopFor(3, nowMs = 1_000L)
assertIs<RemoteStallWatchdog.Decision.Resume>(afterReset)
assertEquals(1, afterReset.attempt)
assertTrue(afterReset.resumeAtMs == 0L)
}
}