fix(live): recover the shared WebSocket from silent half-open connections - #140
Conversation
test-issue-117-ws-watchdog.js runs the real app.js with a fake clock, timers and WebSocket: 10 of 15 fail on master (no watchdog for a silent OPEN socket or a stuck handshake, heartbeats dispatched to listeners, no resume/online check, pull-to-reconnect leaving extra sockets). ws_heartbeat_117_test.go: heartbeat on every ping tick next to the unchanged protocol ping, broadcasts unchanged, one writer goroutine, and app.js's threshold/heartbeat bytes in step with the server. Does not compile on master (no Hub.pingInterval, no wsHeartbeat). Relates to #117 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_019TcZHooUiiknVWbECVWzk8
…ect delay (#117) pendingReconnects() now counts only timers whose callback is connectWS itself (the watchdog timer mentions connectWS in its body), and a new case checks that pull-to-reconnect during the configured reconnect delay cancels the pending reconnect. 5 of 16 pass on master. Relates to #117 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_019TcZHooUiiknVWbECVWzk8
…117) Server: writePump writes {"type":"heartbeat"} right after the protocol ping on the same tick (Hub.pingInterval, default 30s), from the one writer goroutine per client. Pong-based dead-client handling and the 60s read deadline are unchanged. Client (app.js): - any frame refreshes the liveness clock, measured from socket creation; a socket silent for WS_STALE_MS (75s) is replaced once; - heartbeats are consumed before the logo pulse, cache invalidation and every onWS listener (so before pause buffers); packets are unchanged; - connectWS() cancels a pending reconnect and detaches + closes the old socket, so onclose, watchdog, resume and pull cannot stack sockets; - visible-tab resume and `online` check at once; the check is inert while a reconnect is scheduled, so ordinary close keeps its configured WS_RECONNECT_MS delay; - a backward wall-clock step is treated as stale; - pull-to-reconnect replaces the socket at once also when it is OPEN. Relates to #117 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_019TcZHooUiiknVWbECVWzk8
Independent review of
|
| Criterion | Result |
|---|---|
| Small heartbeat from the existing single writer loop, with no competing writer and dead-client handling unchanged | Met [F]. The 20-byte text frame is written in writePump right after the ping on the same tick (websocket.go:279-287), under the same 10 s write deadline. The only other conn write is the pre-existing WriteControl in Hub.Close (:166), which gorilla allows concurrently. readPump (60 s deadline plus pong refresh) is unchanged. A mutant with a second heartbeat goroutine was caught (6 DATA RACE reports plus a test failure). |
| Liveness tracked from socket creation, any frame refreshes it, a silent socket or handshake beyond the documented threshold is replaced exactly once | Met [F]. wsLastFrameAt and the watchdog are set in connectWS (app.js:869-870) and refreshed in onmessage (:885). The 75 s threshold is documented at :669-677. Browser: a blackholed OPEN socket was replaced 75.1 s after its last frame, and a hung handshake (server SIGSTOPped) was replaced at 74.8 s after creation. Both were replaced exactly once. |
onclose, watchdog, online, visible resume and pull cannot stack timers or sockets |
Met [F]. There is one module-level wsWatchdogTimer and one wsReconnectTimer. connectWS clears both and calls dropWS() first. checkWSLiveness does nothing while a reconnect is pending (:844). JS tests 10–16 pass; mutants J3, J7 and J12 are caught. In the browser, SPA navigation across #/live, #/nodes, #/map and #/packets after a replacement added no socket. |
| Old handlers detached before intentional replacement | Met [F]. dropWS (:829-838) nulls all four handlers, then calls close(). Mutant J6 is caught. |
Heartbeats consumed before logo pulse, cache invalidation, pause buffers and onWS; packets unchanged |
Met [F]. Exact-byte match at :888, before Logo.pulse. JS test 5 covers it and mutant J1 is caught. Browser: 1 heartbeat frame received, and an onWS listener saw 0 heartbeats. |
| Configured reconnect delay kept for ordinary close; old-tab behaviour documented | Met [F]/[T]. onclose still uses window.WS_RECONNECT_MS || 3000 (:881); JS test 11 passes with 5000. Old-tab behaviour is documented in the PR body [T]. The public API doc is not updated (finding 2). |
Test-first and mutants
test-issue-117-ws-watchdog.js(head version): 5 passed / 11 failed on master, 16/0 on the head. Commit A's own 15-test version gives 5/10 on A. [F]- The test changed only between A and
1d32bb7c(+15/−3): the reconnect counter now counts onlyconnectWStimers, and one pull-during-delay case was added. There were no test changes in the fix commit. The change is justified. [F] ws_heartbeat_117_test.godoes not compile on master (hub.pingInterval undefined). Behavioural red is shown by mutant G1. All 6 pass on the head. [F]
| Mutant (head copy) | Result |
|---|---|
| G1 heartbeat write removed | caught (TestWritePumpSendsHeartbeatOnEveryPingTick_117) |
| G2 protocol ping removed | caught (same test) |
| G3 default interval 40 s | caught (TestHubDefaultPingInterval_117, TestClientStaleThreshold…_117) |
| G4 heartbeat from a second goroutine (competing writer) | caught (test failure + 6× DATA RACE under -race) |
| G5 heartbeat only every other tick | survived → finding 1 (probe catches it) |
| J1 heartbeat filter removed | caught (1 test) |
J2 ws !== sock guard in onclose removed |
survived, equivalent (finding 4) |
| J3 reconnect-pending guard removed | caught |
| J4 frame refresh in onmessage removed | caught (3) |
| J5 negative-silence rule removed | caught |
| J6 handler detach removed | caught |
| J7 cancel of pending reconnect in connectWS removed | caught |
J8 setupWSResumeCheck() wiring removed |
caught (3) |
| J9 watchdog-from-creation removed | caught (3) |
J10 WS_STALE_MS ×10 |
caught (JS resume test); ×0.8 is also pinned by the Go test (G3) |
| J11 onclose keeps the watchdog | survived, equivalent (finding 4) |
J12 dropWS() in connectWS removed |
caught (8) |
| J13 old pull behaviour (close only when OPEN) | caught |
test-pull-to-reconnect.js (6/6) and test-pull-to-reconnect-1091.js (8/8) stayed green on every JS mutant. shasum of app.js and websocket.go in the mutant copy matched git show 40c72e68:<path> after restore. [F]
Suites run locally
- Go, head:
cd cmd/server && go test -race -count=1 -timeout 60m ./...→ok github.com/corescope/server 910.989s, exit 0. [F] readonly_invariant_test.go(4 tests) passes on the head.go vet .is clean. [F]- JS: all 38 non-E2E
test-*.jsfiles that loadpublic/app.js, plustest-packet-filter.jsandtest-aging.js, were run on master and the head, and the per-file results are identical. Pre-existing failures on both:test-frontend-helpers.js705/2,test-packets.js115/13,test-issue-1470-card-bg-contrast.js9/1,test-issue-1648-m3-emoji-scan.jsrc=1,test-rx-coverage-escape.jsrc=1. Everything else passes, includingtest-live.js110/0,test-packet-filter.js92/0,test-aging.js19/0 and both pull-to-reconnect suites. [F] test-e2e-playwright.jsfail-fasts on "Version info lives on Perf dashboard" on both master and the head (known noise). [F]
Browser
Local Chromium (Playwright) against servers built from the head (port 13740) and master (13741) on the freshened e2e fixture. Scripts: r140/halfopen.js, r140/sigstop.js. [F]
- True half-open, head. A TCP proxy in front of the server silently drops all bytes of the established WS connection, forwarding no FIN, while new connections pass through. A heartbeat arrived at 31.4 s, and the
onWSlistener saw 0 heartbeats. The proxy blackholed the socket at 34.7 s. A new socket was created and OPEN at 106.5 s (75 s after the last frame). Browser sockets afterwards were[CLOSING, OPEN]: the old one is detached and waiting for its close handshake. After SPA navigation plus 33 s, a heartbeat arrived on the new socket, no extra socket appeared, there were 0 page errors, and server/api/healthwebsocket.clientswas 1. - True half-open, master. No socket was replaced within 110 s of the blackhole. The page kept one "OPEN" socket while the server reported
clients: 0, which is the fix(live): recover the shared WebSocket from silent half-open connections #117 bug reproduced. - Server SIGSTOP, head. This gives a silent socket and then a hung handshake. The replacement was created at 75.9 s, 74.8 s after the first socket. It stayed CONNECTING while the server was stopped. After SIGCONT it went OPEN within 8 s, browser sockets were
[CLOSED, OPEN], serverclients: 1, and there were 0 page errors.
Performance and security
- Server [F]: one extra 20-byte write per client per
pingInterval(30 s), on the goroutine that already writes the ping, with no hub lock. At 2K clients that is about 67 small writes per second, spread by connect time.Broadcastand the poller are untouched, and the heartbeat bypasses the 256-slotsendchannel, so a busy client cannot drop it. No benchmark is given; none is needed for a claim this structural [A]. - Client [F]: one
Date.now()and one string compare per message, and at most one watchdog timer plus one reconnect timer globally. No per-message allocation is added. - Reconnect storms [F]/[K]: stale replacement is at most one attempt per 75 s per tab. The ordinary-close path keeps the pre-existing fixed
WS_RECONNECT_MSwith no backoff (unchanged, and the issue asks to preserve it). A half-open client's server-side slot is normally already freed by the 60 s pong deadline before the 75 s client watchdog fires, so the WebSocket /ws: per-IP rate limit, conn cap, and source-IP deny list (follow-up to #1793) Kpa-clawbot/CoreScope#1794 per-IP cap is not charged twice. By default the per-IP cap is off and the upgrade rate is 30/min. - Leaks [F]: no new goroutines. The ticker is stopped in the
writePumpdefer as before, and no Go-side timers were added. The client clears the watchdog on replace and on close. A replaced half-open socket lingers in CLOSING until the browser's close timeout, bounded by the browser. - No DOM sinks touched, no new
map[string]interface{}(websocket.gocount 1 on both master and the head), no DB writes, andreadonly_invariant_test.gois green. [F]
Not verified
- Firefox and Safari; mobile tab freeze, bfcache and a real laptop sleep. The PR's "Not verified" section lists the same, and it is honest. [K]
- The PR's claim that "a frozen but healthy tab may do one unnecessary reconnect on resume" follows from the code (
visibilitychangemay run before queuedonmessagetasks). I did not reproduce it. [A] - A rolling deploy with old tabs open. I did not run it; the PR's description matches the master
onmessagecode path. [A] - The full
cmd/serverrace suite was not run on master for comparison, because the head run was green.
…heartbeat # Conflicts: # .github/workflows/deploy.yml # test-all.sh
|
Review feedback addressed (commit
The review nits (the Go cadence assertion, the Generated by Claude Code |
Relates to #117
Plan and design
The user asked for autonomous work, so the plan is written here instead of waiting for sign-off (AGENTS.md rule 5).
Commits:
70fb5659: tests that reproduce the bug (red on master).1d32bb7c: test refinement. The reconnect counter now counts only timers whose callback isconnectWSitself, and one case was added for a pull during the reconnect delay (still red on master).40c72e68: the fix.Server (
cmd/server/websocket.go)writePumpwrites{"type":"heartbeat"}(20 bytes) right after the protocol ping, on the same ticker.Hub.pingInterval(default 30 s) so tests can shorten it.Client (
public/app.js)Liveness:
wsLastFrameAt.WS_STALE_MS= 75 s, measured from socket creation. That is two heartbeat intervals plus slack, so one late or lost heartbeat is tolerated, and a handshake that never completes is caught too.Heartbeat handling:
onmessage, before the logo pulse, the/stats//nodescache invalidation and everyonWSlistener. That includes the Packets pause buffer, which fills from a listener.Reconnect races:
connectWS()cancels a pending reconnect and detaches the old socket's handlers before closing it, so a late close event from a replaced socket cannot schedule another connection.onclose, the watchdog, resume checks and pull-to-reconnect cannot stack timers or sockets.Resume:
visibilitychange(to visible) andonlinerun the check at once, because a hidden or sleeping tab's timers run late.WS_RECONNECT_MSdelay (default 3 s).Clock steps:
Date.now().Pull-to-reconnect:
onclosestill scheduled a reconnect).Differences from upstream
Kpa-clawbot/CoreScope#2020Upstream is read as a reference only; nothing was cherry-picked.
onclosecould bypass the configuredWS_RECONNECT_MS. The issue explicitly asks to keep that delay for ordinary close events.oncloseignores a socket that is no longer current, as an extra guard next to the detach.app.js: a realDOMContentLoadedboot, and a fake WebSocket whose close event arrives late the way a real one does.WS_STALE_MS, the heartbeat bytes and the server interval.Old tabs during a rolling static-asset update
A tab that still runs an
app.jsfrom before this change receives the heartbeat every 30 s as an ordinary message:/statsand/nodesAPI cache is invalidated 5 s later.onWSlisteners seetype: "heartbeat". Every fork listener ignores that type (Live, Map, Nodes, Channels, Observers filter ontype; nav stats just refresh).Nothing breaks, and a reload ends it. Old tabs do not get the watchdog.
Acceptance criteria
TestWritePumpSendsHeartbeatOnEveryPingTick_117,TestHeartbeatDoesNotChangeDeadClientHandling_117,TestBroadcastsUnchangedAlongsideHeartbeats_117app.jsand here (75 s)onclose, watchdog,online, visible resume and pull cannot stack timers or socketsonmessage === nullon the replaced socket, and its late close event does nothing)onWS; packets unchangedTests
test-issue-117-ws-watchdog.jsRuns the real
app.jsin a vm with a fake clock, fake timers and a fake WebSocket, booted throughDOMContentLoaded. Registered intest-all.shand thedeploy.ymlunit step.d264716cThe 5 that pass on master are guards: heartbeats and traffic keep a socket, packets are dispatched, the close delay is kept, and resume during a pending reconnect is covered.
Mutation check: 11 source mutations were each applied once and all 11 were caught:
connectWSremovedGo:
cmd/server/ws_heartbeat_117_test.goapp.js'sWS_STALE_MSexceeds two intervals and thatWS_HEARTBEATequals the server bytes.Hub.pingInterval, nowsHeartbeat); on this branch all pass.go test -race -run "_117|Hub|Broadcast|Poller|WS|WebSocket|CheckOrigin|Limit": ok (27.9 s).-racesuite (cd cmd/server && go test -race -count=1 ./...):ok github.com/corescope/server 1271.906s.Existing suites
test-pull-to-reconnect.jstest-pull-to-reconnect-1091.jstest-live.jstest-packet-filter.jstest-aging.jstest-frontend-helpers.jseslint on
public/app.jsandscripts/check-xss-sinks.sh --diff origin/masterare clean.Browser check
Local Chromium against a server built from this branch on
test-fixtures:{"type":"heartbeat"}frame arrived about 30.5 s after load, and anonWSlistener did not see it.Perf
Date.now()and one string compare per WS message, and one timer per socket.Not verified
Overlap with other open PRs
public/app.js: PR fix(analytics): treat the distance index's 202 as a transient building state #133 (fix(analytics): treat lazy distance-index 202 responses as transient #120, distance 202) changesapi(). This PR changes the WebSocket section. Different functions, no line overlap..github/workflows/deploy.ymlunit step andtest-all.sh: one added line each, next to lines added by PR fix(packets): empty observer/type selections on Clear Filters #132 (fix(packets): Clear Filters must reset observer and type selection state #121), PR fix(analytics): treat the distance index's 202 as a transient building state #133 (fix(analytics): treat lazy distance-index 202 responses as transient #120), PR fix(rx-coverage): honour configured defaults and save an independent viewport #136 (fix(rx-coverage): honor configured defaults and save an independent viewport #124) and PR fix(live): wire every persisted view toggle before Live init awaits #135 (fix(live): wire persisted view toggles before initialization awaits #125).origin/master, in issue order: this branch merges without conflicts.🤖 Generated with Claude Code
https://claude.ai/code/session_019TcZHooUiiknVWbECVWzk8
Generated by Claude Code