Files
meshcore-analyzer/cmd/server/websocket_test.go
T
efitenandClaude Opus 5 7f8f71e773 fix(live): reconnect when the websocket goes silent (#1074) (#2020)
## Problem

#1074 reports that after a proxy dropped the WebSocket, live updates
only came back 8 to 10 minutes later.

The client only reconnects from `onclose` (`public/app.js:791` on
master). A half-open connection (a proxy or NAT dropping state without a
FIN reaching the browser, a laptop that slept) can keep a WebSocket OPEN
for minutes without `onclose`, and nothing retries in the meantime.

The server does ping every 30s (`cmd/server/websocket.go:252` on
master), but ping frames are answered by the browser below the page and
JS cannot observe them. The only app-level frames are packet broadcasts
(`websocket.go:337, 343, 366`), which stop on a quiet mesh. So the
client had no signal to tell a quiet mesh from a dead socket.

## Change

Server (`cmd/server/websocket.go`):
- On the existing ping tick, `writePump` also writes the text frame
`{"type":"heartbeat"}` (`:283`, bytes at `:80`). One 20-byte frame per
client per 30s, from the goroutine that already writes the ping, no hub
lock.
- The interval moves to `Hub.pingInterval` (default 30s, `:118`) so a
test can shorten it.

Client (`public/app.js`):
- Every frame refreshes `wsLastMessageAt` (`:841`). One timer
(`checkWSLiveness`, `:806`) fires at last message + `WS_STALE_MS` (75s,
one late or lost heartbeat of slack) and replaces the socket if it is
still silent. It is armed at socket creation, so a stuck handshake is
covered too.
- `dropWS` (`:796`) detaches the old socket's handlers before `close()`,
so a late close event cannot schedule a second connection.
- `connectWS` (`:818`) cancels a pending reconnect and drops the
previous socket, so the watchdog, resume checks, `onclose` and
pull-to-reconnect cannot stack sockets. Before this, `pullReconnect` on
a non-open socket left a third socket 3s later. The 3s `WS_RECONNECT_MS`
delay after `onclose` is unchanged (`:837`).
- `visibilitychange` (to visible) and `online` run the check immediately
(`:861`), because a hidden or sleeping tab's timers can run late.
- Heartbeat frames are matched by exact bytes (`:842`) and are not
pulsed or dispatched to `onWS` listeners.

Compatibility: tabs loaded before the deploy dispatch heartbeats to
their listeners until reloaded. Every current listener filters on
`msg.type`, so the visible effect is a logo pulse and a `/stats` cache
refresh every 30s.

Perf: one `Date.now()` and one string compare per WS message on the
client; one extra 20-byte write per client per 30s on the server.

## Tests

- `test-ws-stale-watchdog-1074.js`: real `app.js` in a vm with a fake
clock, timers and WebSocket. 12 tests: silence past the threshold
replaces the socket exactly once; a handshake that never opens is
replaced; heartbeats and packet traffic keep the socket; heartbeats are
not dispatched; resume and `online` after silence reconnect immediately,
with recent traffic they do not, and hiding does not trigger a check;
repeated resume events open one socket; after `onclose` only the
reconnect timer is pending; pull-to-reconnect leaves one socket. 9 of 12
fail on master. 12 of 12 source mutations (threshold, reconnect path,
detaching, timer cleanup, resume wiring, heartbeat filter) are caught.
Registered in `test-all.sh` and the deploy.yml unit step.
- `TestWritePumpSendsAppHeartbeat`: fails with a read timeout without
the heartbeat, even with pings every 20ms. `TestHubDefaultPingInterval`
pins the 30s interval that `WS_STALE_MS` assumes.
- `go test ./...` in `cmd/server` passes; gofmt and go vet are clean.

## Browser validation

On a staging instance (build `139e484e`, together with #1979's branch),
in Chrome, no console errors:

- A `{"type":"heartbeat"}` frame arrived on the open socket within the
observation window.
- Silent socket: after `ws.onmessage = null`, the page replaced the
socket after 76.2s (threshold 75s plus a 250ms poll); the old socket
ended in CLOSED, the new one OPEN.
- Normal close: `ws.close()` led to a new OPEN socket after 4.1s, and
exactly one new `WebSocket` was constructed.

## Not verified

- The reporter's proxy setup was not reproduced; that their delay was a
half-open socket is a hypothesis consistent with the symptom. Hence
`Refs`, not `Fixes`.
- Laptop sleep and the `visibilitychange` / `online` resume path were
only covered by the unit test, not in a browser.
- Behaviour under Chrome's intensive background-timer throttling and
mobile tab freezing was not measured; a frozen but healthy tab may do
one unnecessary reconnect on resume.
- Go tests were run without `-race`.

Refs #1074



## Review follow-up (commit `72e5e906`)

An independent review found no blocking bug: all data writes stay on the
write goroutine, pong-based dead-client detection still works, and no
ordering of onclose, watchdog, resume checks and pull ends with two live
sockets or none. It reproduced the silent-socket case in headless
Chromium through a blackholing TCP proxy (replacement 75.0 s after the
last frame). Changed:

1. **Startup wiring tested.** The first resume test now boots through
the page's real `DOMContentLoaded` listeners, so removing
`setupWSResumeCheck()` from startup makes it fail.
2. **Wall clock stepping back.** If the clock steps back after the last
message, the watchdog no longer re-arms for the size of the step (a 1 h
step used to delay detection by about an hour). A negative silence
reading is treated as stale, so the socket is replaced within
`WS_STALE_MS` of the step (`public/app.js:810-814`). A step in either
direction costs at most one extra reconnect on a healthy socket.
`Date.now()` stays the clock so a tab resumed after sleep is still
checked against real elapsed time.
3. **Pull-to-reconnect at once.** On an OPEN socket, pull-to-reconnect
now replaces it through `connectWS()` instead of closing it and waiting
for onclose, which took 63 s on a half-open connection in the review's
measurement (`public/app.js:927-934`). This was slow on master too; it
is safe now that `connectWS()` detaches the old socket.

Tests: 12 to 16 in `test-ws-stale-watchdog-1074.js`;
`test-pull-to-reconnect.js`, `test-pull-to-reconnect-1091.js` and
`test-live.js` pass.

Correction to the compatibility note: tabs opened before the deploy
treat the heartbeat like any other message. Besides the logo pulse,
`app.js` runs `updateNavStats` on every message and invalidates the
cached `/stats` and `/nodes` responses 5 s later; `packets.js` also
pushes every message into `pauseBuffer` unfiltered (~1310-1313), so an
old tab with Packets paused sees its counter rise by 2 per minute.
Cosmetic: heartbeats are filtered out on replay, and a reload ends it.

Not verified: real hidden-tab or mobile freeze behaviour, Firefox and
Safari, and the reporter's proxy setup.

---------

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-13 19:59:18 +02:00

457 lines
12 KiB
Go

package main
import (
"encoding/json"
"net/http"
"net/http/httptest"
"sort"
"testing"
"time"
"github.com/gorilla/websocket"
)
func TestHubBroadcast(t *testing.T) {
hub := NewHub()
if hub.ClientCount() != 0 {
t.Errorf("expected 0 clients, got %d", hub.ClientCount())
}
// Create a test server with WebSocket endpoint
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
hub.ServeWS(w, r)
}))
defer srv.Close()
// Connect a WebSocket client
wsURL := "ws" + srv.URL[4:] // replace http with ws
conn, _, err := websocket.DefaultDialer.Dial(wsURL, nil)
if err != nil {
t.Fatalf("dial error: %v", err)
}
defer conn.Close()
// Wait for registration
time.Sleep(50 * time.Millisecond)
if hub.ClientCount() != 1 {
t.Errorf("expected 1 client, got %d", hub.ClientCount())
}
// Broadcast a message
hub.Broadcast(map[string]interface{}{
"type": "packet",
"data": map[string]interface{}{"id": 1, "hash": "test123"},
})
// Read the message
conn.SetReadDeadline(time.Now().Add(2 * time.Second))
_, msg, err := conn.ReadMessage()
if err != nil {
t.Fatalf("read error: %v", err)
}
if len(msg) == 0 {
t.Error("expected non-empty message")
}
// Disconnect
conn.Close()
time.Sleep(100 * time.Millisecond)
}
func TestPollerCreation(t *testing.T) {
db := setupTestDB(t)
defer db.Close()
seedTestData(t, db)
hub := NewHub()
poller := NewPoller(db, hub, 100*time.Millisecond)
if poller == nil {
t.Fatal("expected poller")
}
// Start and stop
go poller.Start()
time.Sleep(200 * time.Millisecond)
poller.Stop()
}
func TestHubMultipleClients(t *testing.T) {
hub := NewHub()
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
hub.ServeWS(w, r)
}))
defer srv.Close()
wsURL := "ws" + srv.URL[4:]
// Connect two clients
conn1, _, err := websocket.DefaultDialer.Dial(wsURL, nil)
if err != nil {
t.Fatalf("dial error: %v", err)
}
defer conn1.Close()
conn2, _, err := websocket.DefaultDialer.Dial(wsURL, nil)
if err != nil {
t.Fatalf("dial error: %v", err)
}
defer conn2.Close()
time.Sleep(100 * time.Millisecond)
if hub.ClientCount() != 2 {
t.Errorf("expected 2 clients, got %d", hub.ClientCount())
}
// Broadcast and both should receive
hub.Broadcast(map[string]interface{}{"type": "test", "data": "hello"})
conn1.SetReadDeadline(time.Now().Add(2 * time.Second))
_, msg1, err := conn1.ReadMessage()
if err != nil {
t.Fatalf("conn1 read error: %v", err)
}
if len(msg1) == 0 {
t.Error("expected non-empty message on conn1")
}
conn2.SetReadDeadline(time.Now().Add(2 * time.Second))
_, msg2, err := conn2.ReadMessage()
if err != nil {
t.Fatalf("conn2 read error: %v", err)
}
if len(msg2) == 0 {
t.Error("expected non-empty message on conn2")
}
// Disconnect one
conn1.Close()
time.Sleep(100 * time.Millisecond)
// Remaining client should still work
hub.Broadcast(map[string]interface{}{"type": "test2"})
conn2.SetReadDeadline(time.Now().Add(2 * time.Second))
_, msg3, err := conn2.ReadMessage()
if err != nil {
t.Fatalf("conn2 read error after disconnect: %v", err)
}
if len(msg3) == 0 {
t.Error("expected non-empty message")
}
}
func TestBroadcastFullBuffer(t *testing.T) {
hub := NewHub()
// Create a client with tiny buffer (1)
client := &Client{
send: make(chan []byte, 1),
}
hub.mu.Lock()
hub.clients[client] = true
hub.mu.Unlock()
// Fill the buffer
client.send <- []byte("first")
// This broadcast should drop the message (buffer full)
hub.Broadcast(map[string]interface{}{"type": "dropped"})
// Channel should still only have the first message
select {
case msg := <-client.send:
if string(msg) != "first" {
t.Errorf("expected 'first', got %s", string(msg))
}
default:
t.Error("expected message in channel")
}
// Clean up
hub.mu.Lock()
delete(hub.clients, client)
hub.mu.Unlock()
}
func TestBroadcastMarshalError(t *testing.T) {
hub := NewHub()
// Marshal error: functions can't be marshaled to JSON
hub.Broadcast(map[string]interface{}{"bad": func() {}})
// Should not panic — just log and return
}
func TestPollerBroadcastsNewData(t *testing.T) {
db := setupTestDB(t)
defer db.Close()
seedTestData(t, db)
hub := NewHub()
// Create a client to receive broadcasts
client := &Client{
send: make(chan []byte, 256),
}
hub.mu.Lock()
hub.clients[client] = true
hub.mu.Unlock()
poller := NewPoller(db, hub, 50*time.Millisecond)
go poller.Start()
// Insert new data to trigger broadcast
db.conn.Exec(`INSERT INTO transmissions (raw_hex, hash, first_seen, route_type, payload_type)
VALUES ('EEFF', 'newhash123456789', '2026-01-16T10:00:00Z', 1, 4)`)
time.Sleep(200 * time.Millisecond)
poller.Stop()
// Check if client received broadcast with packet field (fixes #162)
select {
case msg := <-client.send:
if len(msg) == 0 {
t.Error("expected non-empty broadcast message")
}
var parsed map[string]interface{}
if err := json.Unmarshal(msg, &parsed); err != nil {
t.Fatalf("failed to parse broadcast: %v", err)
}
if parsed["type"] != "packet" {
t.Errorf("expected type=packet, got %v", parsed["type"])
}
data, ok := parsed["data"].(map[string]interface{})
if !ok {
t.Fatal("expected data to be an object")
}
// packets.js filters on m.data.packet — must exist
pkt, ok := data["packet"]
if !ok || pkt == nil {
t.Error("expected data.packet to exist (required by packets.js WS handler)")
}
pktMap, ok := pkt.(map[string]interface{})
if !ok {
t.Fatal("expected data.packet to be an object")
}
// Verify key fields exist in nested packet (timestamp required by packets.js)
for _, field := range []string{"id", "hash", "payload_type", "timestamp"} {
if _, exists := pktMap[field]; !exists {
t.Errorf("expected data.packet.%s to exist", field)
}
}
default:
// Might not have received due to timing
}
// Clean up
hub.mu.Lock()
delete(hub.clients, client)
hub.mu.Unlock()
}
func TestPollerBroadcastsMultipleObservations(t *testing.T) {
db := setupTestDB(t)
defer db.Close()
seedTestData(t, db)
hub := NewHub()
client := &Client{
send: make(chan []byte, 256),
}
hub.mu.Lock()
hub.clients[client] = true
hub.mu.Unlock()
defer func() {
hub.mu.Lock()
delete(hub.clients, client)
hub.mu.Unlock()
}()
poller := NewPoller(db, hub, 50*time.Millisecond)
store := NewPacketStore(db, nil)
if err := store.Load(); err != nil {
t.Fatalf("store load failed: %v", err)
}
poller.store = store
go poller.Start()
defer poller.Stop()
// Wait for poller to initialize its lastID/lastObsID cursors before
// inserting new data; otherwise the poller may snapshot a lastID that
// already includes the test data and never broadcast it.
time.Sleep(100 * time.Millisecond)
now := time.Now().UTC().Format(time.RFC3339)
if _, err := db.conn.Exec(`INSERT INTO transmissions (raw_hex, hash, first_seen, route_type, payload_type, decoded_json)
VALUES ('FACE', 'starbursthash237a', ?, 1, 4, '{"pubKey":"aabbccdd11223344","type":"ADVERT"}')`, now); err != nil {
t.Fatalf("insert tx failed: %v", err)
}
var txID int
if err := db.conn.QueryRow(`SELECT id FROM transmissions WHERE hash='starbursthash237a'`).Scan(&txID); err != nil {
t.Fatalf("query tx id failed: %v", err)
}
ts := time.Now().Unix()
if _, err := db.conn.Exec(`INSERT INTO observations (transmission_id, observer_idx, snr, rssi, path_json, timestamp)
VALUES (?, 1, 14.0, -82, '["aa"]', ?),
(?, 2, 10.5, -90, '["aa","bb"]', ?),
(?, 1, 7.0, -96, '["aa","bb","cc"]', ?)`,
txID, ts, txID, ts+1, txID, ts+2); err != nil {
t.Fatalf("insert observations failed: %v", err)
}
deadline := time.After(2 * time.Second)
var dataMsgs []map[string]interface{}
for len(dataMsgs) < 3 {
select {
case raw := <-client.send:
var parsed map[string]interface{}
if err := json.Unmarshal(raw, &parsed); err != nil {
t.Fatalf("unmarshal ws msg failed: %v", err)
}
if parsed["type"] != "packet" {
continue
}
data, ok := parsed["data"].(map[string]interface{})
if !ok {
continue
}
if data["hash"] == "starbursthash237a" {
dataMsgs = append(dataMsgs, data)
}
case <-deadline:
t.Fatalf("timed out waiting for 3 observation broadcasts, got %d", len(dataMsgs))
}
}
if len(dataMsgs) != 3 {
t.Fatalf("expected 3 messages, got %d", len(dataMsgs))
}
paths := make([]string, 0, 3)
observers := make(map[string]bool)
for _, m := range dataMsgs {
hash, _ := m["hash"].(string)
if hash != "starbursthash237a" {
t.Fatalf("unexpected hash %q", hash)
}
p, _ := m["path_json"].(string)
paths = append(paths, p)
if oid, ok := m["observer_id"].(string); ok && oid != "" {
observers[oid] = true
}
}
sort.Strings(paths)
wantPaths := []string{`["aa","bb","cc"]`, `["aa","bb"]`, `["aa"]`}
sort.Strings(wantPaths)
for i := range wantPaths {
if paths[i] != wantPaths[i] {
t.Fatalf("path mismatch at %d: got %q want %q", i, paths[i], wantPaths[i])
}
}
if len(observers) < 2 {
t.Fatalf("expected observations from >=2 observers, got %d", len(observers))
}
}
func TestIngestNewObservationsBroadcast(t *testing.T) {
db := setupTestDB(t)
defer db.Close()
seedTestData(t, db)
store := NewPacketStore(db, nil)
if err := store.Load(); err != nil {
t.Fatalf("store load failed: %v", err)
}
maxObs := db.GetMaxObservationID()
now := time.Now().Unix()
if _, err := db.conn.Exec(`INSERT INTO observations (transmission_id, observer_idx, snr, rssi, path_json, timestamp)
VALUES (1, 2, 6.0, -100, '["aa","zz"]', ?),
(1, 1, 5.0, -101, '["aa","yy"]', ?)`, now, now+1); err != nil {
t.Fatalf("insert new observations failed: %v", err)
}
maps := store.IngestNewObservations(maxObs, 500)
if len(maps) != 2 {
t.Fatalf("expected 2 broadcast maps, got %d", len(maps))
}
for _, m := range maps {
if m["hash"] != "abc123def4567890" {
t.Fatalf("unexpected hash in map: %v", m["hash"])
}
path, ok := m["path_json"].(string)
if !ok || path == "" {
t.Fatalf("missing path_json in map: %#v", m)
}
if _, ok := m["observer_id"]; !ok {
t.Fatalf("missing observer_id in map: %#v", m)
}
}
}
func TestHubRegisterUnregister(t *testing.T) {
hub := NewHub()
client := &Client{
send: make(chan []byte, 256),
}
hub.Register(client)
if hub.ClientCount() != 1 {
t.Errorf("expected 1 client after register, got %d", hub.ClientCount())
}
hub.Unregister(client)
if hub.ClientCount() != 0 {
t.Errorf("expected 0 clients after unregister, got %d", hub.ClientCount())
}
// Unregister again should be safe
hub.Unregister(client)
if hub.ClientCount() != 0 {
t.Errorf("expected 0 clients, got %d", hub.ClientCount())
}
}
// #1074: browsers cannot see protocol-level pings, so a page cannot tell a
// quiet mesh from a dead socket unless the server also sends something the
// page receives. The heartbeat rides the same ticker as the ping.
func TestWritePumpSendsAppHeartbeat(t *testing.T) {
hub := NewHub()
hub.pingInterval = 20 * time.Millisecond
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
hub.ServeWS(w, r)
}))
defer srv.Close()
conn, _, err := websocket.DefaultDialer.Dial("ws"+srv.URL[4:], nil)
if err != nil {
t.Fatalf("dial error: %v", err)
}
defer conn.Close()
conn.SetReadDeadline(time.Now().Add(2 * time.Second))
kind, msg, err := conn.ReadMessage()
if err != nil {
t.Fatalf("expected a heartbeat with no broadcast traffic, got read error: %v", err)
}
if kind != websocket.TextMessage {
t.Fatalf("heartbeat must be a text frame so page JS receives it, got frame type %d", kind)
}
// public/app.js matches these exact bytes to keep heartbeats away from
// page listeners; changing them breaks that match.
if string(msg) != `{"type":"heartbeat"}` {
t.Fatalf("heartbeat bytes changed: %s", msg)
}
}
// The client's stale threshold (WS_STALE_MS in public/app.js, 75s) assumes
// a heartbeat at least every 30s.
func TestHubDefaultPingInterval(t *testing.T) {
if got := NewHub().pingInterval; got != 30*time.Second {
t.Fatalf("pingInterval = %v, want 30s (public/app.js WS_STALE_MS depends on it)", got)
}
}