mirror of
https://github.com/Kpa-clawbot/meshcore-analyzer.git
synced 2026-09-25 19:03:36 +00:00
## 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>
457 lines
12 KiB
Go
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)
|
|
}
|
|
}
|