refactor(supersync): address round-2 review of WS reconnect cooldown fix

- Replace the `client.refusedChallengers = 0` post-summary reset with a
  dedicated `summaryLogged: boolean` flag. The reset muddied the
  field's documented "lifetime count" semantics for any future reader
  observing the closing socket. The flag dedupes the `ws.on('close')`
  re-entry without lying about the count.
- Refresh the stale `RECONNECT_COOLDOWN_MS` doc that still described
  the non-sliding semantics from before fbdedf597e.
- Short-circuit the WS-429 path normalize on `statusCode === 429` in
  setErrorHandler so the split+replace doesn't run on the 99%+ of
  error responses that aren't 429.
- Drop the redundant `cid.length > 0` guard in `isValidClientId` —
  the trailing regex already requires `+` (≥1 char).
- Route the websocket.routes spec simulator through `isValidClientId`
  so it can't drift from production validation order again.
- Add a heartbeat-path regression test for the storm-summary dedup
  (the explicit-eviction path was already covered by fbdedf597e).
This commit is contained in:
Johannes Millan 2026-05-20 15:38:26 +02:00
parent 0c70e7906f
commit 3fbde60742
5 changed files with 65 additions and 23 deletions

View file

@ -159,9 +159,11 @@ export const createServer = (
// would flood the log without adding info. Downgrade those to debug.
// Exact-match the WS route (allowing trailing slash + querystring) so
// future sibling routes like /api/sync/ws-status do not silently
// inherit the debug-only behavior.
const path = req.url.split('?', 1)[0].replace(/\/+$/, '');
const isWsRateLimit = statusCode === 429 && path === '/api/sync/ws';
// inherit the debug-only behavior. statusCode gate short-circuits the
// path-normalize on the ~99% of error responses that aren't 429.
const isWsRateLimit =
statusCode === 429 &&
req.url.split('?', 1)[0].replace(/\/+$/, '') === '/api/sync/ws';
if (statusCode >= 500) {
Logger.error(logMessage, error.stack);
} else if (isWsRateLimit) {

View file

@ -17,6 +17,14 @@ interface ConnectedClient {
cooldownUntil: number;
/** Count of challengers refused during this incumbent's lifetime. */
refusedChallengers: number;
/**
* Set true after `removeConnection` emits the storm-summary INFO. Guards
* against the inevitable `ws.on('close')` re-entry (triggered by
* removeConnection's own ws.close eviction, heartbeat, closeAll) firing
* the summary a second time. Preferred over zeroing `refusedChallengers`
* because the count remains observably truthful for the life of the object.
*/
summaryLogged: boolean;
}
/**
@ -43,13 +51,15 @@ export class WebSocketConnectionService {
/** Close code sent to a challenger socket refused during the reconnect cooldown */
private static readonly RECONNECT_COOLDOWN_CLOSE_CODE = 4008;
/**
* If a still-OPEN socket for this clientId was accepted less than this long
* ago, a new socket from the same clientId is refused (the incumbent is kept,
* NOT evicted). Breaks the shared-clientId reconnect storm from pre-18.6.0
* clients that reconnect immediately on the 4009 eviction: the incumbent is
* never evicted, so the server stops emitting 4009 and the loop loses its
* fuel. A genuinely dead/closing incumbent bypasses this (see addConnection),
* so a real network-blip reconnect still recovers within the cooldown.
* Sliding-window cooldown. While a still-OPEN incumbent's `cooldownUntil` is
* in the future, a new socket from the same clientId is refused (the
* incumbent is kept, NOT evicted) and `cooldownUntil` is extended by another
* RECONNECT_COOLDOWN_MS. Eviction only resumes after this long of QUIET (no
* challengers). Breaks the shared-clientId reconnect storm from pre-18.6.0
* clients that reconnect immediately on the 4009 eviction: under sustained
* load the gate never expires, so the server stops emitting 4009 and the
* loop loses its fuel. A genuinely dead/closing incumbent bypasses this (see
* addConnection), so a real network-blip reconnect still recovers.
*/
private static readonly RECONNECT_COOLDOWN_MS = 5_000;
@ -145,6 +155,7 @@ export class WebSocketConnectionService {
connectedAt: nowMs,
cooldownUntil: nowMs + WebSocketConnectionService.RECONNECT_COOLDOWN_MS,
refusedChallengers: 0,
summaryLogged: false,
};
userSet.add(client);
@ -200,14 +211,14 @@ export class WebSocketConnectionService {
// Storm summary: the first refusal logged a WARN; the rest were silent.
// When the incumbent finally goes away, log the cumulative count so the
// operator sees the scale of the storm without per-attempt log spam.
// Zero the counter so the eventual `ws.on('close')` re-entry (triggered by
// our own ws.close below) does not double-log this summary.
if (client.refusedChallengers > 0) {
// `summaryLogged` guards against the inevitable `ws.on('close')` re-entry
// (triggered by our own ws.close below) double-logging.
if (client.refusedChallengers > 0 && !client.summaryLogged) {
const incumbentLifetimeMs = Date.now() - client.connectedAt;
Logger.info(
`[ws:user:${userId}:${client.clientId}] Refused ${client.refusedChallengers} reconnect challenger(s) over ${incumbentLifetimeMs}ms incumbent lifetime before removal`,
);
client.refusedChallengers = 0;
client.summaryLogged = true;
}
// Close the WebSocket if still open
if (

View file

@ -11,12 +11,12 @@ export {
/**
* Type-guard for clientId validation. Order matters: cheap length check first
* so an attacker passing a multi-megabyte clientId is rejected before the
* regex scans it. Used by the WS route handler AND the rate-limit
* keyGenerator keep both call sites in sync via this helper.
* regex scans it. The regex already requires `+` (1 char), so an explicit
* non-empty check is redundant. Used by the WS route handler AND the
* rate-limit keyGenerator keep both call sites in sync via this helper.
*/
export const isValidClientId = (cid: unknown): cid is string =>
typeof cid === 'string' &&
cid.length > 0 &&
cid.length <= SUPER_SYNC_MAX_CLIENT_ID_LENGTH &&
SUPER_SYNC_CLIENT_ID_REGEX.test(cid);

View file

@ -323,6 +323,35 @@ describe('WebSocketConnectionService', () => {
expect(summaryCalls).toHaveLength(1);
});
it('should emit the storm summary exactly once when an incumbent with refusals is reaped by the heartbeat', () => {
// Regression: heartbeat-dead-connection removal also calls
// removeConnection -> ws.close -> 'close' event -> removeConnection
// re-entry. summaryLogged must dedupe that path too.
const incumbent = createMockWs();
service.addConnection(1, 'client-a', incumbent as any);
for (let i = 0; i < 4; i++) {
const challenger = createMockWs();
service.addConnection(1, 'client-a', challenger as any);
}
vi.mocked(Logger.info).mockClear();
service.startHeartbeat();
// Two ping cycles with no pong → heartbeat removes the incumbent.
vi.advanceTimersByTime(30_000);
vi.advanceTimersByTime(30_000);
// The heartbeat's ws.close() would in real ws fire the close handler,
// re-entering removeConnection.
incumbent._emitClose();
const summaryCalls = vi
.mocked(Logger.info)
.mock.calls.filter((c) =>
String(c[0]).includes('Refused 4 reconnect challenger(s)'),
);
expect(summaryCalls).toHaveLength(1);
});
it('should not emit a storm summary when no challengers were refused', () => {
const ws = createMockWs();
service.addConnection(1, 'client-a', ws as any);

View file

@ -1,5 +1,9 @@
import { describe, it, expect, beforeEach, vi } from 'vitest';
import { CLIENT_ID_REGEX, MAX_CLIENT_ID_LENGTH } from '../src/sync/sync.const';
import {
CLIENT_ID_REGEX,
MAX_CLIENT_ID_LENGTH,
isValidClientId,
} from '../src/sync/sync.const';
import {
WS_CONNECTION_RATE_LIMIT_MAX,
WS_CONNECTION_RATE_LIMIT_WINDOW,
@ -59,11 +63,7 @@ async function simulateWsHandler(
return 'rejected';
}
if (
!clientId ||
!CLIENT_ID_REGEX.test(clientId) ||
clientId.length > MAX_CLIENT_ID_LENGTH
) {
if (!isValidClientId(clientId)) {
socket.close(4001, 'Invalid clientId');
return 'rejected';
}