Skip to content

WIP: auto re-anchor a sendspin client stuck in error while playing - #351

Closed
tobsch wants to merge 1 commit into
sonn-audio:devfrom
tobsch:wip/sendspin-auto-reanchor-on-client-error
Closed

tobsch wants to merge 1 commit into
sonn-audio:devfrom
tobsch:wip/sendspin-auto-reanchor-on-client-error

Conversation

@tobsch

@tobsch tobsch commented Aug 20, 2026

Copy link
Copy Markdown
Contributor

WIP — opening for direction, not for merge. I can't run the build locally
(container-only), so this is unverified code plus a precise diagnosis. Two open
questions below need a live capture to answer.

Symptom

After Spotify single-active-device switching (playing zone A, then moving the
Spotify account to zone B and back), the room's sendspin client desyncs and plays
nothing — while ALSA reports the substream RUNNING and frames keep flowing.
The reference client logs, in its own journal:

WARNING:sendspin.audio:Audio underflow detected; requesting re-anchor

It re-anchors its own timeline. Usually fine — but sometimes that client-local
re-anchor never converges, and the room stays silent until the
sendspin@room_<x> client process is restarted. Restarting the process is
currently the only known recovery.

Why the server can barely see it

Walking the hook surface (sendspinHookRegistry.ts → buildCombined), the
protocol exposes no inbound re-anchor request or underflow event. The only
signal that could reach the server is a state: 'error' player-state report
via onPlayerState → handleClientState. And handleClientState's dedup guard
(signature === lastClientStateSignature → return) drops identical repeats — so
the server can't even count an error storm; at most it sees the first error
transition. Today that transition is only logged (warn), never acted on.

What this change does

On the first error transition while the output believes it is playing, start a
short debounce (4 s). If the client hasn't recovered to synchronized by then,
force a fresh server anchor — startStream({ preserveAnchor: false }), which is
what a client restart accomplishes without killing the process — guarded by a
per-output cooldown (30 s) so a persistently-erroring client isn't thrashed. If
the client recovers within the debounce, the timer is cancelled.

Minimal and self-contained: two fields + one guarded helper in sendspinOutput.ts.

Open questions (need a live capture during a real desync)

  1. Does the reference client actually report state: 'error' during this
    underflow storm
    , or does it keep saying synchronized and only log the
    re-anchor client-side? If the latter, the server is blind here and the fix must
    live in the client/protocol (surface an underflow/re-anchor event) rather than
    in lox.
  2. Does a server-side fresh anchor converge the client, or is a full client
    restart genuinely required? The proven recovery so far is a process restart,
    which is heavier than startStream.

Happy to adjust the trigger (state value, debounce, cooldown) or move it entirely
once you confirm the client's reporting behaviour.

Interim workaround (in the field, working now)

Until this is settled I run an external journald watchdog on the Pi that counts
requesting re-anchor warnings per sendspin@room_* unit and restarts a client
whose re-anchor is stuck — the process restart being the currently-proven fix.
Reference: https://github.com/tobsch/snappy/tree/master/timelinewatch

After Spotify single-active-device switching, a room's sendspin client can
desync — the reference client logs "Audio underflow detected; requesting
re-anchor" and re-anchors its own timeline, but when that client-local re-anchor
does not converge the room plays nothing while ALSA stays RUNNING. Today the only
recovery is restarting the sendspin@room_<x> client process.

The protocol carries no inbound re-anchor request, so the sole server-visible
signal is a `state: 'error'` player-state report (identical repeats are deduped in
handleClientState, so we act on the first transition, debounced). If the client is
still in `error` after a short debounce while the output believes it is playing,
force a fresh server anchor (startStream preserveAnchor:false) — what a client
restart does, without the restart — guarded by a per-output cooldown.

WIP / unverified: needs a live capture to confirm (a) the reference client reports
`state: 'error'` during this underflow storm and (b) a server-side fresh anchor
converges it rather than needing a full client restart. Opening for direction.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
@tobsch

tobsch commented Aug 20, 2026

Copy link
Copy Markdown
Contributor Author

Field update + upstream context that bears directly on open question 1.

The spec confirms the premise. The Sendspin underrun handshake is
client/state: 'error' → mute → buffer → synchronized (see aiosendspin issue
#251 and the conformance doc
docs/stream-sync-correction.md). So a client that underruns is spec-required to
report state: 'error' to the server — which is exactly the signal
handleClientState receives and this PR keys on. That makes the server-side
re-anchor here spec-aligned rather than a guess. Caveat still worth a live capture:
whether the reference client reliably emits state: 'error' for this particular
stuck-re-anchor case (vs. only for a transient underrun that it recovers from on
its own), and whether a fresh server anchor converges it or a full client restart
is still needed.

Heads-up so two failure modes don't get conflated. Chasing "room goes silent
mid-stream" in the field, the actual cause of several incidents turned out to be a
separate, client-side bug, not this timeline desync: the Python client
(aiosendspin ≤ 5.3.0) has no seek/seek_relative in its MediaCommand enum,
so when this server advertises them in the controller supported_commands (Spotify
Connect, with seek_max_ms) the client fails to deserialize the whole
ServerStateMessage and — in ≤5.3.0 — the parse error kills its reader loop →
connection drop → silence. aiosendspin 6.0.5 wraps from_json in try/except so it
degrades to dropping that one message instead (audio survives), and seek is
already on aiosendspin main. Fixed for us by upgrading the clients. Flagging it
only because its symptom ("silent mid-stream after a Spotify action") overlaps this
one; the reliable discriminator is the client journal: a MediaCommand
InvalidFieldValue traceback = the seek bug, Audio underflow detected; requesting re-anchor with no such traceback = the desync this PR targets.

@tobsch

tobsch commented Aug 21, 2026

Copy link
Copy Markdown
Contributor Author

Live capture answers open question 1 — and it refutes this PR's premise. Recommend not merging as-is.

A watchdog capture during a real underflow storm (reference client, aiosendspin 6.0.5) shows, for the
affected client over a 90s window:

  • Client journal: WARNING:sendspin.audio:Audio underflow detected; requesting re-anchor (x3 in ~2s),
    each followed by Cleared audio queue after underflow and a fresh Stream STARTED. So the client detects
    the underrun and re-anchors its own timeline, entirely locally.
  • lox docker log for the same client, same window (DEBUG level on): Sendspin play → stream started
    → first audio frame sent → Sendspin stop. No Sendspin client state update … state: error line at
    all
    — nor any synchronized. i.e. handleClientState never receives an error for this event.

So the server is blind to this underrun: the client does not emit the spec's client/state: 'error'
handshake over the wire during it (consistent with aiosendspin
#251: "the underrun signal must originate inside the
SDK … today there is no callback" — and evidently the client side doesn't drive it either). The trigger this
PR keys on therefore never fires in the real case.

Recommendation: hold / don't merge this server-side state:'error' reaction — it can't help until the
client actually reports the underrun state (upstream #251). The reliable detector today is external: read the
client's own requesting re-anchor log and restart the stuck client
(timelinewatch). Happy to repurpose this PR
into a spec-compliant path if/when aiosendspin emits client/state: 'error' on underrun — at that point
reacting in handleClientState becomes viable and this is roughly the right shape.

(Also worth noting from the same capture: the storm was a very short TTS alert underflowing at stream start
after a 24k-mono→44.1k-stereo format restart — not the Spotify device-switch case — so short alert clips are
one real source of these underruns, separate from the live-stream lead-runaway desync.)

@tobsch
tobsch marked this pull request as draft August 21, 2026 14:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants