diff options
| author | Adam Malczewski <[email protected]> | 2026-06-28 12:31:18 +0900 |
|---|---|---|
| committer | Adam Malczewski <[email protected]> | 2026-06-28 12:31:18 +0900 |
| commit | d09a4f8ae041536dc7d37a384971058248d7b995 (patch) | |
| tree | 25745f2443699f257eef5d61ab10f33fe60f10a4 | |
| parent | e3a85ab476cdfaa49982078aba3b6792331185cb (diff) | |
| download | dispatch-d09a4f8ae041536dc7d37a384971058248d7b995.tar.gz dispatch-d09a4f8ae041536dc7d37a384971058248d7b995.zip | |
fix(ssh,host-bin): permanent pooled-client error listener + uncaughtException/unhandledRejection guards
Root cause of the live production crash (exit-1 'Timed out while waiting for
handshake'): the pooled ssh2.Client had no permanent 'error' listener after
connect, so a post-connect ssh2 error escaped as an uncaught EventEmitter
'error' with no process-level guard. See notes/crash-investigation-findings.md §1.
- packages/ssh/src/pool.ts: attach a permanent 'error' listener to the pooled
client in buildConnection that sets state=error, logs (alias, message, level),
and does not throw; cleanup() no longer removes it.
- packages/host-bin/src/main.ts: add process.on('uncaughtException') (graceful
shutdown after logging) and process.on('unhandledRejection') (log + continue),
both logging message/stack, memory snapshot, activeConversations count, and
timestamp so the failure site is observable.
| -rw-r--r-- | packages/host-bin/src/main.ts | 35 | ||||
| -rw-r--r-- | packages/ssh/src/pool.test.ts | 176 | ||||
| -rw-r--r-- | packages/ssh/src/pool.ts | 18 |
3 files changed, 229 insertions, 0 deletions
diff --git a/packages/host-bin/src/main.ts b/packages/host-bin/src/main.ts index 29e402e..70d1cb2 100644 --- a/packages/host-bin/src/main.ts +++ b/packages/host-bin/src/main.ts @@ -31,6 +31,7 @@ import { extension as providerOpenaiCompatExt } from "@dispatch/provider-openai- import { extension as providerUmansExt } from "@dispatch/provider-umans"; import { type MemorySample, + memorySampleAttributes, extension as sessionOrchestratorExt, sessionOrchestratorHandle, } from "@dispatch/session-orchestrator"; @@ -243,8 +244,10 @@ async function boot(): Promise<void> { // owns the PERIODIC baseline. All effects are injected (no ambient state); // stop() is cleared on shutdown so timers never leak across a restart. let memoryTelemetry: { stop: () => void } | undefined; + let activeConvCountFn: (() => number) | undefined; try { const orchestrator = host.getHostAPI().getService(sessionOrchestratorHandle); + activeConvCountFn = () => orchestrator.getActiveConversationCount(); memoryTelemetry = startMemoryTelemetry({ logger: logger.child({ extensionId: "mem-telemetry" }), sampleMemory: (): MemorySample => { @@ -280,6 +283,38 @@ async function boot(): Promise<void> { process.on("SIGINT", shutdown); process.on("SIGTERM", shutdown); + const memorySnapshot = () => { + const m = process.memoryUsage(); + return memorySampleAttributes({ + rss: m.rss, + heapUsed: m.heapUsed, + heapTotal: m.heapTotal, + external: m.external, + arrayBuffers: m.arrayBuffers, + }); + }; + + process.on("unhandledRejection", (reason) => { + logger.error("unhandledRejection", { + err: reason, + handler: "unhandledRejection", + activeConversations: activeConvCountFn?.() ?? "unavailable", + timestamp: new Date().toISOString(), + ...memorySnapshot(), + }); + }); + + process.on("uncaughtException", (err) => { + logger.error("uncaughtException", { + err, + handler: "uncaughtException", + activeConversations: activeConvCountFn?.() ?? "unavailable", + timestamp: new Date().toISOString(), + ...memorySnapshot(), + }); + void shutdown(); + }); + logger.info("Dispatch booted"); console.info("Dispatch booted"); } diff --git a/packages/ssh/src/pool.test.ts b/packages/ssh/src/pool.test.ts new file mode 100644 index 0000000..b5d72c8 --- /dev/null +++ b/packages/ssh/src/pool.test.ts @@ -0,0 +1,176 @@ +/** + * Unit tests for the pooled ssh2.Client error lifecycle in pool.ts. + * + * The ssh2.Client (the outermost network edge) is faked via EventEmitter — + * permitted by the constitution (mocking the outermost edge is fine; only + * `@dispatch/*` may not be mocked). These tests prove the permanent + * `'error'` listener survives `cleanup()` (which only removes the connect-time + * onReady/onError) and that a post-connect ssh2 error is captured, logged, and + * non-throwing, with the connection reconnecting on the next acquire. + */ + +import { EventEmitter } from "node:events"; +import type { Logger } from "@dispatch/kernel"; +import type { Computer } from "@dispatch/wire"; +import type { Client } from "ssh2"; +import { afterEach, describe, expect, it } from "vitest"; +import { createSshConnectionPool } from "./pool.js"; + +const computer: Computer = { + alias: "testremote", + hostName: "localhost", + port: 22, + user: "testuser", + identityFile: null, + knownHost: false, +}; + +interface CapturedError { + msg: string; + err: unknown; + alias?: string; + message?: string; + level?: string; + from?: string; + to?: string; +} + +function capturingLogger(calls: CapturedError[]): Logger { + const log: Logger = { + debug: () => undefined, + info: () => undefined, + warn: () => undefined, + error: (msg, attrs) => { + calls.push({ + msg, + err: attrs?.err, + alias: attrs?.alias as string | undefined, + message: attrs?.message as string | undefined, + level: attrs?.level as string | undefined, + from: attrs?.from as string | undefined, + to: attrs?.to as string | undefined, + }); + }, + child: () => log, + span: (name) => ({ + id: name, + log, + setAttributes: () => undefined, + addLink: () => undefined, + child: (n) => ({ id: n, log }) as never, + end: () => undefined, + }), + }; + return log; +} + +/** A fake ssh2.Client: EventEmitter + connect/emd/sftp. `connect` emits 'ready'. */ +function fakeClient(): { client: Client; ee: EventEmitter } { + const ee = new EventEmitter(); + const api = { + connect: () => { + process.nextTick(() => ee.emit("ready")); + }, + end: () => undefined, + sftp: (cb: (err: Error | null, sftp: unknown) => void) => cb(null, {}), + }; + return { client: Object.assign(ee, api) as unknown as Client, ee }; +} + +function makeDeps(client: Client, logger: Logger) { + return { + logger, + homeDir: "/tmp", + knownHostsPath: "/tmp/known_hosts", + readFileText: async (p: string): Promise<string> => { + if (p === "/tmp/known_hosts") return ""; + return "ssh-ed25519 not-encrypted-key"; + }, + appendKnownHosts: async () => undefined, + pathExists: async () => true, + newClient: () => client, + resolveComputer: async () => computer, + }; +} + +describe("SshConnectionPool — permanent pooled-client error listener", () => { + let pool: ReturnType<typeof createSshConnectionPool>; + + afterEach(async () => { + await pool?.closeAll(); + }); + + it("captures a post-connect 'error' without throwing, sets state=error, and logs", async () => { + const errorCalls: CapturedError[] = []; + const { client, ee } = fakeClient(); + pool = createSshConnectionPool(makeDeps(client, capturingLogger(errorCalls))); + + const conn = await pool.acquire("testremote"); + expect(conn.state).toBe("connected"); + + const sshErr = Object.assign(new Error("Timed out while waiting for handshake"), { + level: "socket", + }); + + expect(() => ee.emit("error", sshErr)).not.toThrow(); + + expect(conn.state).toBe("error"); + expect(conn.error).toBe("Timed out while waiting for handshake"); + expect(errorCalls).toHaveLength(1); + expect(errorCalls[0]?.msg).toBe("ssh: pooled client error"); + expect(errorCalls[0]?.alias).toBe("testremote"); + expect(errorCalls[0]?.message).toBe("Timed out while waiting for handshake"); + expect(errorCalls[0]?.level).toBe("socket"); + expect(errorCalls[0]?.from).toBe("connected"); + expect(errorCalls[0]?.to).toBe("error"); + }); + + it("does NOT remove the permanent listener on successful connect (survives cleanup)", async () => { + const errorCalls: CapturedError[] = []; + const { client, ee } = fakeClient(); + pool = createSshConnectionPool(makeDeps(client, capturingLogger(errorCalls))); + + const conn = await pool.acquire("testremote"); + expect(conn.state).toBe("connected"); + + ee.emit("error", new Error("post-connect drop")); + expect(conn.state).toBe("error"); + expect(errorCalls).toHaveLength(1); + }); + + it("reconnects on the next acquire after a post-connect error", async () => { + const { client, ee } = fakeClient(); + pool = createSshConnectionPool(makeDeps(client, capturingLogger([]))); + + const conn = await pool.acquire("testremote"); + expect(conn.state).toBe("connected"); + + ee.emit("error", new Error("post-connect drop")); + expect(conn.state).toBe("error"); + + const conn2 = await pool.acquire("testremote"); + expect(conn2.state).toBe("connected"); + expect(conn2.error).toBeUndefined(); + }); + + it("logs the connect-time error too (permanent listener fires during handshake)", async () => { + const errorCalls: CapturedError[] = []; + const ee = new EventEmitter(); + const api = { + connect: () => { + process.nextTick(() => ee.emit("error", new Error("connect refused"))); + }, + end: () => undefined, + sftp: (cb: (err: Error | null, sftp: unknown) => void) => cb(null, {}), + }; + const client = Object.assign(ee, api) as unknown as Client; + pool = createSshConnectionPool(makeDeps(client, capturingLogger(errorCalls))); + + const conn = await pool.acquire("testremote"); + expect(conn.state).toBe("error"); + expect(conn.error).toBe("connect refused"); + expect(errorCalls).toHaveLength(1); + expect(errorCalls[0]?.msg).toBe("ssh: pooled client error"); + expect(errorCalls[0]?.message).toBe("connect refused"); + }); +}); diff --git a/packages/ssh/src/pool.ts b/packages/ssh/src/pool.ts index 9acae0e..5d1eedd 100644 --- a/packages/ssh/src/pool.ts +++ b/packages/ssh/src/pool.ts @@ -112,6 +112,24 @@ export function createSshConnectionPool(deps: SshPoolDeps): SshConnectionPool { let sftp: import("ssh2").SFTPWrapper | null = null; let connectPromise: Promise<void> | null = null; + // Permanent error listener — without it, a post-connect ssh2 'error' + // (re-key/keepalive timeout) escapes uncaught → process crash. cleanup() + // in doConnect only removes the connect-time onReady/onError; this persists. + client.on("error", (err: unknown) => { + const from = state.value; + state.value = "error"; + state.error = err instanceof Error ? err.message : String(err); + connectPromise = null; + deps.logger.error("ssh: pooled client error", { + err, + alias, + message: state.error, + level: (err as { level?: string } | null)?.level, + from, + to: "error", + }); + }); + const touch = (): void => { const e = entries.get(alias); if (e !== undefined) e.lastUsedAt = Date.now(); |
