Skip to content

fix: replace a dead dealer connection within 25 s - #440

Open
leodurandfr wants to merge 2 commits into
devgianlu:masterfrom
leodurandfr:fix/dealer-ping-timeout
Open

leodurandfr wants to merge 2 commits into
devgianlu:masterfrom
leodurandfr:fix/dealer-ping-timeout

Conversation

@leodurandfr

Copy link
Copy Markdown
Contributor

When the network path under the dealer websocket goes away without a FIN or an RST (here, a network change on a dual-homed device), the dealer takes about a minute to notice, and every command sent from another device in the meantime (pause, next...) is lost. This PR brings that down to at most 25 s, without dropping live connections while a slow command is being processed.

What was wrong

pingTicker runs every 30 s and closes the connection only when the last pong is more than 40 s old (pingInterval+timeout). The pong that follows a ping arrives right after the tick, so a connection that dies just after it survives the next tick (30 s old) and is closed at the one after (60 s old). The close then goes through a close handshake that the dead peer never answers, which coder/websocket gives up on after 5 s. So a dead connection is noticed 30 to 60 s after the cut, depending on where the cut falls relative to the ticker, and replaced up to 5 s later. In the test added here, with the cut just after a pong, master replaces it after 1m5s.

On a device (Raspberry Pi 5 on Ethernet and Wi-Fi to the same LAN, nmcli device disconnect eth0 while Wi-Fi keeps LAN and internet, the dealer as on master), the dealer logged did not receive last pong from dealer, 60s passed 59 s after the cut, and failed receiving dealer message 5 s after that, which matches the close handshake's 5 s timeout.

The change

  1. fix: drop a dealer connection whose pong does not come back in 10 s: ping every 15 s, and close the connection a ping was sent on if its pong has not come back within 10 s, with CloseNow (no handshake on a link presumed dead). A connection that goes silent is replaced within 25 s. A new connection counts as an answer to a ping still pending on the old one, replacing the 30 s of grace resetPongDeadline used to give.
  2. fix: count a dealer pong's time only while the dealer is being read: recvLoop reads nothing while handleRequest waits for the player to process a command and reply, which for a transfer means spclient requests of up to 30 s each. A pong that arrives during that time sits unread, so a plain 10 s deadline closes a live connection and loses the command's reply. The pong's time now runs only while recvLoop is reading (from the ping, or from when recvLoop went back to reading if that is later), and a later ping does not restart the deadline of a pending one, so a connection that died during a slow command is still replaced within 25 s once the command is answered.

The cost is one ping every 15 s instead of 30 s.

The second commit also covers a case master already has. I swept the test harness (sweep not included) with one command sent at each whole second of a minute. The table gives the number of alignments at which a live connection was replaced, as a range over five runs. The counts vary because a command and a tick can fall on the same instant of the fake clock, and the scheduler picks their order:

command answered after master first commit only both commits
11 s 0 of 60 3 to 5 of 60 0 of 60
15 s 0 of 60 17 to 21 of 60 0 of 60
20 s 0 of 60 38 to 41 of 60 0 of 60
25 s 0 of 60 59 to 60 of 60 0 of 60
30 s 1 of 60 60 of 60 0 of 60
31 s 1 to 4 of 60 60 of 60 0 of 60
35 s 8 to 11 of 60 60 of 60 0 of 60

Nearly every replacement also lost the command's reply.

One behavior change to be aware of: when a receiver never lets go (a player loop stuck on a command, as in #186), master keeps logging did not receive last pong from dealer, Ns passed every 30 s. Closing the connection does not help in that case, since recvLoop cannot reconnect until the receiver returns. With this change the deadline waits for the receiver, so that line is no longer logged. With a command held for 9 minutes in the test harness, master logged it 16 times and this branch did not log it at all; neither reconnected. If you rely on that line to spot a stuck player, I can add a warning when a receiver holds recvLoop longer than some bound.

Tested

  • Unit tests in dealer/ping_test.go, run with testing/synctest against a fake dealer over in-memory connections that can be cut silently:
    • a connection cut just after a pong is replaced within 25 s (fails on master: 1m5s);
    • a connection whose pongs take 5 s is kept for 10 minutes;
    • a live connection is kept, and the reply sent, while a command takes 25 s (fails on the first commit alone);
    • a connection cut during a 25 s command is replaced within 25 s of the command being answered (fails on master: 1m9s).
  • On the device above, I made two Ethernet cuts that took the dealer's connection down, sending commands from the Spotify desktop app as a Connect remote. Both builds also carried feat: report playback on other devices and take it over #420, feat: list the play order in GET /player/queue, and step back without rewinding #421 and an HTTP/2 health check on the shared HTTP client, and the second also carried a fix for dead accesspoint connections. I'm sending those two fixes separately. This PR does not depend on any of them.
    • The dealer logged did not receive pong from dealer within 10s about 16 s and 13 s after the cut, and reconnected over Wi-Fi.
    • In the first run, a pause sent 10 s after the cut, before the dead connection was noticed, was lost. Every command sent after the reconnection was applied, with the player's state changing 0.2 to 0.7 s after the remote's command returned (state polled twice a second). That was 6 play/pause from 45 s on in the first run (a play at 30 s, after the lost pause, had nothing to change), and 8 next, pause and play from 30 s on in the second.
  • gofmt, go vet, build and go test -tags "test_unit test_integration" ./... are clean, for each commit on its own.

🤖 Generated with Claude Code

leodurandfr and others added 2 commits November 7, 2026 14:46
The dealer carries the commands sent from other devices (pause, next...),
so while it sits on a dead connection everything sent to the device is
lost. A dead connection was only noticed by the ping ticker finding the
last pong more than 40 s old, which it checks every 30 s: after a network
loss the connection survived to the second tick after the last pong, up to
60 s, and its close then waited 5 s for a close handshake the dead peer
never answers. Measured on a device after a network change: the dealer
reported "did not receive last pong from dealer, 60s passed" about a
minute after the change.

Ping every 15 s and give each ping 10 s to be answered. An unanswered ping
closes the connection it was sent on without a handshake, so a connection
that went silent is replaced within 25 s. A new connection counts as an
answer to a ping still pending on the old one, which replaces the 30 s of
grace the pong deadline used to start with.

Ten seconds is generous for a pong on a live link, and one ping every 15 s
is a few bytes per second.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The pong deadline added by the previous commit ran from the ping to the
moment recvLoop read the pong. recvLoop reads nothing while it hands a
message or a request over to its receiver, and a request is handed over
until the player has processed the command and replied: a transfer loads
the context and the track over spclient, whose requests may take up to 30 s.
A pong that arrived during that time sat unread, the deadline fired, and a
live connection was closed along with the reply of the command being
processed.

In a test with a fake dealer that sends the command at each whole second
of a minute, a command answered after 11 s cost the connection and its
reply at 5 of the 60 alignments, after 15 s at 20, after 20 s at 41 and
after 25 s at 59. Before the previous commit, the 30 s ticker already
replaced the connection for a command answered after 31 s (4 of 60, the
reply lost each time) or 35 s (11 of 60, 10 replies lost).

Time a pong only while recvLoop is reading: from the ping, or from when
recvLoop went back to reading if that is later, and wait as long as a
receiver holds it. Closing sooner gained nothing anyway, since recvLoop
cannot reconnect before the receiver lets it go. While a ping is still
pending, a later ping no longer restarts its deadline, so a connection that
died during a slow command is still replaced within 25 s once the command is
answered. The same test then replaces no connection and loses no reply for
any command answered within 35 s.

The fake dealer now answers pings from another goroutine, as a socket
buffer would let it, so a device busy with a command does not stall it.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
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.

1 participant