chore(cli): keep WS lifecycle diagnostic logs
Five info-level log points across the WS lifecycle helper:
ws_open_attempt / ws_open_ok / ws_hello_sent / ws_hello_acked /
ws_closed (with status + close code/reason).
Surfaced during M1 smoke testing — without these the only visible
signal was "presence row missing on broker," which made it hard to
distinguish "WS never opened" / "opened but hello rejected" /
"acked then closed by broker."
Both clients prefix the helper-emitted msg ("session_broker_*",
"broker_*") so log greps stay clean per role.
Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
@@ -143,23 +143,27 @@ export function connectWsWithBackoff(opts: WsLifecycleOptions): Promise<WsLifecy
|
|||||||
if (closed) return Promise.reject(new Error("client_closed"));
|
if (closed) return Promise.reject(new Error("client_closed"));
|
||||||
setStatus("connecting");
|
setStatus("connecting");
|
||||||
|
|
||||||
|
log("info", "ws_open_attempt", { url: opts.url });
|
||||||
const sock = new WebSocket(opts.url);
|
const sock = new WebSocket(opts.url);
|
||||||
ws = sock;
|
ws = sock;
|
||||||
|
|
||||||
return new Promise<void>((resolve, reject) => {
|
return new Promise<void>((resolve, reject) => {
|
||||||
sock.on("open", () => {
|
sock.on("open", () => {
|
||||||
|
log("info", "ws_open_ok", { url: opts.url });
|
||||||
// Build and send the hello inside a microtask so any sync
|
// Build and send the hello inside a microtask so any sync
|
||||||
// throws from buildHello() reject this connect attempt cleanly.
|
// throws from buildHello() reject this connect attempt cleanly.
|
||||||
(async () => {
|
(async () => {
|
||||||
try {
|
try {
|
||||||
const hello = await opts.buildHello();
|
const hello = await opts.buildHello();
|
||||||
sock.send(JSON.stringify(hello));
|
sock.send(JSON.stringify(hello));
|
||||||
|
log("info", "ws_hello_sent", { url: opts.url });
|
||||||
helloTimer = setTimeout(() => {
|
helloTimer = setTimeout(() => {
|
||||||
log("warn", "hello_ack_timeout", { url: opts.url });
|
log("warn", "hello_ack_timeout", { url: opts.url });
|
||||||
try { sock.close(); } catch { /* ignore */ }
|
try { sock.close(); } catch { /* ignore */ }
|
||||||
reject(new Error("hello_ack_timeout"));
|
reject(new Error("hello_ack_timeout"));
|
||||||
}, helloAckTimeoutMs);
|
}, helloAckTimeoutMs);
|
||||||
} catch (e) {
|
} catch (e) {
|
||||||
|
log("warn", "ws_build_hello_threw", { err: String(e) });
|
||||||
reject(e instanceof Error ? e : new Error(String(e)));
|
reject(e instanceof Error ? e : new Error(String(e)));
|
||||||
}
|
}
|
||||||
})();
|
})();
|
||||||
@@ -174,9 +178,8 @@ export function connectWsWithBackoff(opts: WsLifecycleOptions): Promise<WsLifecy
|
|||||||
if (helloTimer) { clearTimeout(helloTimer); helloTimer = null; }
|
if (helloTimer) { clearTimeout(helloTimer); helloTimer = null; }
|
||||||
setStatus("open");
|
setStatus("open");
|
||||||
reconnectAttempt = 0;
|
reconnectAttempt = 0;
|
||||||
|
log("info", "ws_hello_acked", { url: opts.url });
|
||||||
resolve();
|
resolve();
|
||||||
// Don't forward hello_ack to onMessage — both pre-refactor
|
|
||||||
// clients consumed it inline and never delegated.
|
|
||||||
return;
|
return;
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -186,6 +189,7 @@ export function connectWsWithBackoff(opts: WsLifecycleOptions): Promise<WsLifecy
|
|||||||
sock.on("close", (code, reason) => {
|
sock.on("close", (code, reason) => {
|
||||||
if (helloTimer) { clearTimeout(helloTimer); helloTimer = null; }
|
if (helloTimer) { clearTimeout(helloTimer); helloTimer = null; }
|
||||||
const reasonStr = reason.toString("utf8");
|
const reasonStr = reason.toString("utf8");
|
||||||
|
log("warn", "ws_closed", { url: opts.url, code, reason: reasonStr, status });
|
||||||
opts.onBeforeReconnect?.(code, reasonStr);
|
opts.onBeforeReconnect?.(code, reasonStr);
|
||||||
|
|
||||||
if (closed) {
|
if (closed) {
|
||||||
@@ -200,8 +204,6 @@ export function connectWsWithBackoff(opts: WsLifecycleOptions): Promise<WsLifecy
|
|||||||
() => openOnce().catch((err) => log("warn", "ws_reconnect_failed", { url: opts.url, err: String(err) })),
|
() => openOnce().catch((err) => log("warn", "ws_reconnect_failed", { url: opts.url, err: String(err) })),
|
||||||
wait,
|
wait,
|
||||||
);
|
);
|
||||||
// First attempt failure (still in connecting) also rejects the
|
|
||||||
// initial connect promise so callers can surface it.
|
|
||||||
if (status === "connecting" || status === "reconnecting") {
|
if (status === "connecting" || status === "reconnecting") {
|
||||||
reject(new Error(`closed_before_hello_${code}`));
|
reject(new Error(`closed_before_hello_${code}`));
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user