mirror of
https://github.com/Ark0N/Codeman.git
synced 2026-10-02 13:39:41 +02:00
COD-134 fix WS flap loop (undefined onopen call) + reconnect resilience + logging
Root cause of the WS->HTTP->WS flapping: the v1.1.15 input-delivery merge left a call to the now-undefined _flushHttpFallbackQueuesViaWs() in ws.onopen, so every (re)connect threw a TypeError BEFORE _onWsReady() ran -- durable input was never re-flushed over the fresh socket, the 2s redeliver sweep then saw stale unacked frames and force-closed the socket, reconnect, throw again: a self-sustaining flap loop. Remove the dead call (_onWsReady, 10 lines below, is its replacement). Resilience + observability: - Pure CodemanWsReconnect.plan(code, attempt) (constants.js, TDD, 6 tests): <4004 -> fast reconnect (immediate jittered first retry, faster backoff); 4008/unknown->=4004 -> bounded retry-fallback (HTTP no longer sticks until a tab switch); 4004/4009 -> give up (session gone). Wired into onclose. - Redeliver sweep force-closes only a SILENT socket (no recent recv), not one actively delivering output/ACKs -- stops self-inflicted flaps while typing. - Client logs WS close code/reason to crash-diag; server logs [ws] open/close/terminate/4008 (console -> journald; Fastify runs logger:false). Verified: 6/6 unit, tsc 0, frontend-syntax + prettier clean, build; beta WS reaches connected with zero console errors (onopen TypeError gone), _wsLastRecvAt tracked, server [ws] lines emit.
This commit is contained in:
+63
-13
@@ -435,6 +435,11 @@ class CodemanApp {
|
||||
this._ws = null; // WebSocket instance for active session
|
||||
this._wsSessionId = null; // Session ID the WS is connected to
|
||||
this._wsReady = false; // True when WS is open and ready for I/O
|
||||
this._wsState = 'disconnected'; // connecting | connected | reconnecting | fallback | disconnected
|
||||
this._wsLastClose = null; // { code, reason, at } for transport diagnostics
|
||||
this._wsLastRecvAt = 0; // ms timestamp of the last frame received on the active WS
|
||||
this._wsInputSendCount = 0;
|
||||
this._httpFallbackSendCount = 0;
|
||||
|
||||
// Terminal write batching with DEC 2026 sync support
|
||||
this.pendingWrites = [];
|
||||
@@ -1976,6 +1981,7 @@ class CodemanApp {
|
||||
if (this._ws === ws) {
|
||||
this._wsReady = true;
|
||||
this._wsReconnectAttempts = 0;
|
||||
this._updateConnectionIndicator();
|
||||
// Send a typed resize over the fresh socket: syncs PTY dims after
|
||||
// (re)connects AND registers the desktop sizing claim server-side —
|
||||
// selectSession's earlier resizes ran before this WS existed, so they
|
||||
@@ -1990,6 +1996,9 @@ class CodemanApp {
|
||||
|
||||
ws.onmessage = (event) => {
|
||||
if (this._ws !== ws) return;
|
||||
// Mark the socket as alive on every received frame (output, ACK, etc.) so
|
||||
// the redeliver sweep only force-closes a genuinely silent connection.
|
||||
this._wsLastRecvAt = Date.now();
|
||||
try {
|
||||
const msg = JSON.parse(event.data);
|
||||
if (msg.t === 'o') {
|
||||
@@ -2016,18 +2025,53 @@ class CodemanApp {
|
||||
this._wsReady = false;
|
||||
this._stopMobileResizeRetry();
|
||||
|
||||
// Reconnect on unexpected close (server restart, network blip, ping timeout).
|
||||
// Don't reconnect if we intentionally disconnected (_disconnectWs nulls onclose)
|
||||
// or if the server rejected the session (4004=not found, 4008=too many, 4009=terminated).
|
||||
if (event.code < 4004 && this.activeSessionId === sessionId) {
|
||||
const delay = Math.min(1000 * Math.pow(2, this._wsReconnectAttempts || 0), 10000);
|
||||
this._wsReconnectAttempts = (this._wsReconnectAttempts || 0) + 1;
|
||||
this._wsReconnectTimer = setTimeout(() => {
|
||||
this._wsReconnectTimer = null;
|
||||
if (this.activeSessionId === sessionId) {
|
||||
this._connectWs(sessionId);
|
||||
}
|
||||
}, delay);
|
||||
// Decide what to do next from the close code + how many consecutive
|
||||
// reconnects we've already made (pure policy in constants.js):
|
||||
// reconnect → transient (server restart, network blip, ping timeout);
|
||||
// schedule a backoff retry while this session stays active.
|
||||
// retry-fallback → too-many-connections / unknown rejection; show the HTTP
|
||||
// fallback but keep retrying so we return to WS when it clears.
|
||||
// give-up → 4004 (not found) / 4009 (terminated); the session is gone.
|
||||
// _disconnectWs() nulls onclose for intentional disconnects, so we never land here for those.
|
||||
const plan = window.CodemanWsReconnect.plan(event.code, this._wsReconnectAttempts || 0);
|
||||
_crashDiag.log(
|
||||
`WS CLOSE code=${event.code} reason=${event.reason || ''} action=${plan.action} attempts=${this._wsReconnectAttempts || 0}`
|
||||
);
|
||||
|
||||
const stillActive = this.activeSessionId === sessionId;
|
||||
if (plan.action === 'give-up') {
|
||||
this._wsState = stillActive ? 'fallback' : 'disconnected';
|
||||
this._updateConnectionIndicator();
|
||||
} else if (plan.action === 'reconnect') {
|
||||
if (stillActive) {
|
||||
this._wsState = 'reconnecting';
|
||||
this._updateConnectionIndicator();
|
||||
const delay = plan.delayMs + Math.floor(Math.random() * 250); // jitter to de-sync herds
|
||||
this._wsReconnectAttempts = (this._wsReconnectAttempts || 0) + 1;
|
||||
this._wsReconnectTimer = setTimeout(() => {
|
||||
this._wsReconnectTimer = null;
|
||||
if (this.activeSessionId === sessionId) {
|
||||
this._connectWs(sessionId);
|
||||
}
|
||||
}, delay);
|
||||
} else {
|
||||
this._wsState = 'disconnected';
|
||||
this._updateConnectionIndicator();
|
||||
}
|
||||
} else {
|
||||
// retry-fallback: surface the HTTP fallback, but keep trying on a bounded
|
||||
// timer so the transport returns to WS once the transient condition clears.
|
||||
this._wsState = stillActive ? 'fallback' : 'disconnected';
|
||||
this._updateConnectionIndicator();
|
||||
if (stillActive) {
|
||||
this._wsReconnectAttempts = (this._wsReconnectAttempts || 0) + 1;
|
||||
this._wsReconnectTimer = setTimeout(() => {
|
||||
this._wsReconnectTimer = null;
|
||||
if (this.activeSessionId === sessionId) {
|
||||
this._connectWs(sessionId);
|
||||
}
|
||||
}, plan.delayMs);
|
||||
}
|
||||
}
|
||||
};
|
||||
|
||||
@@ -2234,7 +2278,13 @@ class CodemanApp {
|
||||
this._ws && this._ws.readyState === WebSocket.OPEN && this._wsSessionId === sessionId;
|
||||
if (isActiveWs) {
|
||||
const oldest = list[0];
|
||||
if (oldest && oldest.sentAt && Date.now() - oldest.sentAt > this._reliableAckTimeoutMs) {
|
||||
// Only tear the socket down when the oldest unacked frame is stale AND the
|
||||
// socket has been silent for the timeout: a connection still delivering
|
||||
// output/ACKs is alive (the ACK is just behind), so force-closing it would
|
||||
// cause needless WS↔HTTP flapping. A truly half-open socket goes quiet.
|
||||
const stale = oldest && oldest.sentAt && Date.now() - oldest.sentAt > this._reliableAckTimeoutMs;
|
||||
const silent = Date.now() - this._wsLastRecvAt > this._reliableAckTimeoutMs;
|
||||
if (stale && silent) {
|
||||
try {
|
||||
this._ws.close(); // half-open: never recovers on its own — force reconnect
|
||||
} catch {
|
||||
|
||||
@@ -126,12 +126,74 @@ function shouldAutoWrapTabs(input) {
|
||||
return scrollWidth > clientWidth + 1;
|
||||
}
|
||||
|
||||
// COD-122: Monitor "Tmux Sessions" row label policy. A row carries up to three
|
||||
// identifiers — the tab name (user-facing L1 label), the tmux session name
|
||||
// (e.g. "codeman-1fac7304"), and the agent (Claude/Codex) session id. The tab name
|
||||
// must win as the primary label; the other two are secondary metadata shown only
|
||||
// when known and not redundant with the primary, so the row degrades gracefully
|
||||
// when identifiers are missing.
|
||||
function resolveMonitorRowLabels(input) {
|
||||
const clean = (v) => (typeof v === 'string' ? v.trim() : '');
|
||||
const tabName = clean(input && input.tabName);
|
||||
const storedName = clean(input && input.storedName);
|
||||
const muxName = clean(input && input.muxName);
|
||||
const agentId = clean(input && input.agentSessionId);
|
||||
const sessionId = clean(input && input.sessionId);
|
||||
|
||||
// Tab name is the L1 label; fall back through the persisted mux name → tmux name
|
||||
// → a generic placeholder so the primary is never blank.
|
||||
const primary = tabName || storedName || muxName || 'session';
|
||||
|
||||
const secondaries = [];
|
||||
// tmux name — skip when it's already serving as the primary fallback (no dup).
|
||||
if (muxName && muxName !== primary) {
|
||||
secondaries.push({ kind: 'tmux', label: muxName });
|
||||
}
|
||||
// agent session id — show only when genuinely known: non-empty, not the codeman
|
||||
// sessionId placeholder (claudeSessionId is seeded with the session id until a
|
||||
// real agent message arrives), and not redundant with the primary label.
|
||||
if (agentId && agentId !== sessionId && agentId !== primary) {
|
||||
secondaries.push({ kind: 'agent', label: agentId });
|
||||
}
|
||||
return { primary, secondaries };
|
||||
}
|
||||
|
||||
// COD-134 — Terminal WebSocket reconnect policy.
|
||||
//
|
||||
// Decide what to do after a terminal WebSocket closes, given the close `code`
|
||||
// and `attempt` (0-based count of consecutive reconnects already made):
|
||||
// - transient closes (code < 4004: 1000/1001/1005/1006/etc.) → 'reconnect'
|
||||
// with exponential backoff (0 on the first attempt; the caller adds jitter),
|
||||
// 250ms → 500 → 1000 → ... capped at 10s.
|
||||
// - 4004 (session not found) / 4009 (session terminated) → 'give-up': the
|
||||
// session is gone, retrying only wastes connections.
|
||||
// - 4008 (too many connections) and any other code >= 4004 → 'retry-fallback':
|
||||
// show the HTTP fallback but keep retrying on a bounded 5s timer so the
|
||||
// transport returns to WS once the transient condition clears (un-stick).
|
||||
// Pure: no DOM, no side effects.
|
||||
function planWsReconnect(code, attempt) {
|
||||
if (code === 4004 || code === 4009) {
|
||||
return { action: 'give-up', delayMs: 0 };
|
||||
}
|
||||
if (code >= 4004) {
|
||||
return { action: 'retry-fallback', delayMs: 5000 };
|
||||
}
|
||||
const delayMs = attempt <= 0 ? 0 : Math.min(250 * Math.pow(2, attempt - 1), 10000);
|
||||
return { action: 'reconnect', delayMs };
|
||||
}
|
||||
|
||||
if (typeof window !== 'undefined') {
|
||||
window.WEBGL_FALLBACK = WEBGL_FALLBACK;
|
||||
window.evaluateWebGLLongTaskTrip = evaluateWebGLLongTaskTrip;
|
||||
window.CodemanTabOverflow = {
|
||||
shouldAutoWrapTabs,
|
||||
};
|
||||
window.CodemanMonitorLabels = {
|
||||
resolveMonitorRowLabels,
|
||||
};
|
||||
window.CodemanWsReconnect = {
|
||||
plan: planWsReconnect,
|
||||
};
|
||||
}
|
||||
|
||||
// Scheduler API — prioritize terminal writes over background UI updates.
|
||||
|
||||
@@ -83,13 +83,19 @@ export function registerWsRoutes(app: FastifyInstance, ctx: SessionPort, getHost
|
||||
return;
|
||||
}
|
||||
|
||||
// Structured transport logging — surfaces WS open/close/timeout churn so the
|
||||
// tunnel-flap behavior (COD-134) is observable in the server logs. Fastify is
|
||||
// configured logger:false, so we log via console (→ journald under systemd).
|
||||
|
||||
// Enforce per-session connection limit
|
||||
const currentCount = sessionWsCount.get(id) ?? 0;
|
||||
if (currentCount >= MAX_WS_PER_SESSION) {
|
||||
console.warn('[ws] terminal rejected: too many connections', { sessionId: id, wsCount: currentCount });
|
||||
socket.close(4008, 'Too many connections');
|
||||
return;
|
||||
}
|
||||
sessionWsCount.set(id, currentCount + 1);
|
||||
console.info('[ws] terminal open', { sessionId: id, wsCount: currentCount + 1 });
|
||||
|
||||
// Swallow socket errors — cleanup happens in 'close'
|
||||
socket.on('error', () => {});
|
||||
@@ -228,11 +234,12 @@ export function registerWsRoutes(app: FastifyInstance, ctx: SessionPort, getHost
|
||||
if (socket.readyState !== 1) return;
|
||||
socket.ping();
|
||||
pongTimeout = setTimeout(() => {
|
||||
console.warn('[ws] terminal ping timeout — terminating', { sessionId: id });
|
||||
socket.terminate();
|
||||
}, WS_PONG_TIMEOUT_MS);
|
||||
}, WS_PING_INTERVAL_MS);
|
||||
|
||||
socket.on('close', () => {
|
||||
socket.on('close', (code: number, reason: Buffer) => {
|
||||
clearInterval(pingInterval);
|
||||
if (pongTimeout) clearTimeout(pongTimeout);
|
||||
if (batchTimer) clearTimeout(batchTimer);
|
||||
@@ -245,11 +252,13 @@ export function registerWsRoutes(app: FastifyInstance, ctx: SessionPort, getHost
|
||||
|
||||
// Decrement per-session connection count
|
||||
const count = sessionWsCount.get(id) ?? 1;
|
||||
if (count <= 1) {
|
||||
const remaining = count <= 1 ? 0 : count - 1;
|
||||
if (remaining === 0) {
|
||||
sessionWsCount.delete(id);
|
||||
} else {
|
||||
sessionWsCount.set(id, count - 1);
|
||||
sessionWsCount.set(id, remaining);
|
||||
}
|
||||
console.info('[ws] terminal close', { sessionId: id, code, reason: String(reason), wsCount: remaining });
|
||||
});
|
||||
});
|
||||
}
|
||||
|
||||
@@ -0,0 +1,80 @@
|
||||
/**
|
||||
* COD-134 — Terminal WebSocket reconnect policy.
|
||||
*
|
||||
* `CodemanWsReconnect.plan(code, attempt)` is the pure decision behind the
|
||||
* client WS `onclose` handler in app.js: given a WebSocket close code and the
|
||||
* number of consecutive reconnects already attempted, it returns the action to
|
||||
* take (`reconnect` | `retry-fallback` | `give-up`) and a backoff delay. It is
|
||||
* exposed on `window.CodemanWsReconnect` and tested here in a plain node VM
|
||||
* context (no jsdom — jsdom env setup is broken on some hosts), mirroring the
|
||||
* `CodemanMonitorLabels` harness in test/monitor-row-labels.test.ts.
|
||||
*/
|
||||
import { readFileSync } from 'node:fs';
|
||||
import { resolve } from 'node:path';
|
||||
import vm from 'node:vm';
|
||||
import { describe, expect, it } from 'vitest';
|
||||
|
||||
type Plan = { action: 'reconnect' | 'retry-fallback' | 'give-up'; delayMs: number };
|
||||
|
||||
function loadHelper() {
|
||||
const context = vm.createContext({ window: {}, globalThis: {} });
|
||||
const source = readFileSync(resolve(import.meta.dirname, '../src/web/public/constants.js'), 'utf8');
|
||||
vm.runInContext(source, context, { filename: 'constants.js' });
|
||||
return (context.window as { CodemanWsReconnect: { plan: (code: number, attempt: number) => Plan } })
|
||||
.CodemanWsReconnect;
|
||||
}
|
||||
|
||||
describe('COD-134 WS reconnect plan policy', () => {
|
||||
it('reconnects immediately on the first attempt for a transient close', () => {
|
||||
const { plan } = loadHelper();
|
||||
expect(plan(1006, 0)).toEqual({ action: 'reconnect', delayMs: 0 });
|
||||
expect(plan(1000, 0).action).toBe('reconnect');
|
||||
expect(plan(1001, 0).delayMs).toBe(0);
|
||||
expect(plan(1005, 0).delayMs).toBe(0);
|
||||
});
|
||||
|
||||
it('grows the backoff exponentially with a 10s cap for transient closes', () => {
|
||||
const { plan } = loadHelper();
|
||||
expect(plan(1006, 0).delayMs).toBe(0);
|
||||
expect(plan(1006, 1).delayMs).toBe(250);
|
||||
expect(plan(1006, 2).delayMs).toBe(500);
|
||||
expect(plan(1006, 3).delayMs).toBe(1000);
|
||||
expect(plan(1006, 4).delayMs).toBe(2000);
|
||||
expect(plan(1006, 5).delayMs).toBe(4000);
|
||||
expect(plan(1006, 6).delayMs).toBe(8000);
|
||||
expect(plan(1006, 7).delayMs).toBe(10000); // 16000 capped to 10000
|
||||
expect(plan(1006, 8).delayMs).toBe(10000);
|
||||
expect(plan(1006, 50).delayMs).toBe(10000); // stays capped no matter how many attempts
|
||||
// every transient attempt is still a reconnect
|
||||
for (let attempt = 0; attempt < 12; attempt++) {
|
||||
expect(plan(1006, attempt).action).toBe('reconnect');
|
||||
}
|
||||
});
|
||||
|
||||
it('auto-retries the fallback on a too-many-connections (4008) close', () => {
|
||||
const { plan } = loadHelper();
|
||||
expect(plan(4008, 0)).toEqual({ action: 'retry-fallback', delayMs: 5000 });
|
||||
expect(plan(4008, 3)).toEqual({ action: 'retry-fallback', delayMs: 5000 });
|
||||
});
|
||||
|
||||
it('gives up on session-not-found (4004) and session-terminated (4009)', () => {
|
||||
const { plan } = loadHelper();
|
||||
expect(plan(4004, 0)).toEqual({ action: 'give-up', delayMs: 0 });
|
||||
expect(plan(4004, 5)).toEqual({ action: 'give-up', delayMs: 0 });
|
||||
expect(plan(4009, 0)).toEqual({ action: 'give-up', delayMs: 0 });
|
||||
expect(plan(4009, 5)).toEqual({ action: 'give-up', delayMs: 0 });
|
||||
});
|
||||
|
||||
it('auto-retries the fallback for an unknown >=4004 code (e.g. 4010, 4005)', () => {
|
||||
const { plan } = loadHelper();
|
||||
expect(plan(4010, 0)).toEqual({ action: 'retry-fallback', delayMs: 5000 });
|
||||
expect(plan(4005, 2)).toEqual({ action: 'retry-fallback', delayMs: 5000 });
|
||||
expect(plan(4500, 0)).toEqual({ action: 'retry-fallback', delayMs: 5000 });
|
||||
});
|
||||
|
||||
it('treats a sub-4004 close (e.g. 4003 Forbidden) as a transient reconnect', () => {
|
||||
const { plan } = loadHelper();
|
||||
// 4003 is < 4004, so it is NOT a give-up; it follows the transient backoff.
|
||||
expect(plan(4003, 0)).toEqual({ action: 'reconnect', delayMs: 0 });
|
||||
});
|
||||
});
|
||||
Reference in New Issue
Block a user