From 04fc7c157017e3d34a5930902b60e76bd10fd546 Mon Sep 17 00:00:00 2001 From: MAC Date: Fri, 26 Jun 2026 01:27:44 +0100 Subject: [PATCH] fix(api): bound WS draining + alert webhook so shutdown's HTTP drain is never skipped [BUG-102] MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit shutdown()'s overall force-exit timer (SHUTDOWN_TIMEOUT_MS = 10s) fires process.exit(1) immediately when it elapses — skipping server.close() (the HTTP drain) entirely if it hasn't been reached yet. But `await wss.close()` can be blocked far longer than 10s: the `ws` library's own per-socket close-handshake timeout defaults to 30s, and wss.close() doesn't resolve until every client has closed. A single slow/unresponsive WS client during a rolling deploy could make the 10s force-exit fire before server.close() is ever called, hard-killing in-flight HTTP requests on every such deploy. Separately, sendInfoAlert (unlike flushSentry, which already caps at 2000ms) has no internal timeout on its webhook call — a hanging webhook could also consume the same limited budget before WS/HTTP draining even starts. Extracted two helpers into a new src/utils/shutdown.ts (testable in isolation, since index.ts itself has real side effects on import and isn't unit-tested anywhere in this codebase): - drainWebSocketClients(clients, timeoutMs): asks every client to close cleanly, then force-terminates any still open after timeoutMs (3s), bounding this phase regardless of client behavior. - withTimeout(promise, ms): races a promise against a timeout, resolving either way rather than rejecting, for best-effort steps that must not block shutdown. Applied both in index.ts's shutdown(): the alert send is now bounded to 2s, and WS draining is now bounded to 3s before wss.close() is called — leaving the full 10s budget reliably available for server.close() to run. Added tests for both helpers using fake timers, including the exact BUG-102 scenario (a client that never acks close still gets force-terminated within the bound). Verified by temporarily breaking the implementation (removing the terminate() fallback) and confirming the tests fail, then restoring the fix. Co-authored-by: Claude Sonnet 4.6 --- src/index.ts | 46 +++++++++----- src/utils/shutdown.ts | 43 +++++++++++++ tests/utils/shutdown.test.ts | 115 +++++++++++++++++++++++++++++++++++ 3 files changed, 190 insertions(+), 14 deletions(-) create mode 100644 src/utils/shutdown.ts create mode 100644 tests/utils/shutdown.test.ts diff --git a/src/index.ts b/src/index.ts index bc78b89..354bd2a 100644 --- a/src/index.ts +++ b/src/index.ts @@ -27,6 +27,7 @@ import { docsRoutes } from "./routes/docs.js"; import { adlRoutes } from "./routes/adl.js"; import { setupWebSocket, cleanupPriceUpdateTimers, cleanupEventBusListeners } from "./routes/ws.js"; import { OraclePriceBroadcaster } from "./services/OraclePriceBroadcaster.js"; +import { drainWebSocketClients, withTimeout } from "./utils/shutdown.js"; import { readRateLimit, writeRateLimit } from "./middleware/rate-limit.js"; import { ipBlocklist } from "./middleware/ip-blocklist.js"; import { cacheMiddleware } from "./middleware/cache.js"; @@ -337,6 +338,18 @@ oraclePriceBroadcaster.start().catch((err) => { }); const SHUTDOWN_TIMEOUT_MS = 10_000; +// Bound on waiting for WS clients to ack a clean close handshake before this +// process force-terminates them. The `ws` library's own per-socket +// close-handshake timeout defaults to 30s — far longer than +// SHUTDOWN_TIMEOUT_MS — so without an explicit, shorter bound here, a single +// slow/unresponsive client can leave `wss.close()` below still pending when +// the overall force-exit timer fires, which calls process.exit(1) BEFORE +// server.close() (the HTTP drain) is ever reached. +const WS_DRAIN_TIMEOUT_MS = 3_000; +// sendInfoAlert (unlike flushSentry, which already caps at 2000ms below) has +// no internal timeout — a hanging webhook would otherwise consume an +// unbounded slice of the already-tight SHUTDOWN_TIMEOUT_MS budget. +const SHUTDOWN_ALERT_TIMEOUT_MS = 2_000; async function shutdown(signal: string): Promise { logger.info("Shutdown initiated", { signal }); @@ -347,15 +360,19 @@ async function shutdown(signal: string): Promise { process.exit(1); }, SHUTDOWN_TIMEOUT_MS); forceExit.unref(); - + try { // Flush Sentry events before shutting down await flushSentry(2000); - - // Send shutdown alert - await sendInfoAlert("API service shutting down", [ - { name: "Signal", value: signal, inline: true }, - ]); + + // Send shutdown alert — bounded so a hanging webhook can't eat the rest + // of the shutdown budget (see SHUTDOWN_ALERT_TIMEOUT_MS comment above). + await withTimeout( + sendInfoAlert("API service shutting down", [ + { name: "Signal", value: signal, inline: true }, + ]), + SHUTDOWN_ALERT_TIMEOUT_MS, + ); // Clean up pending price update timers and unsubscribe shared eventBus // listeners before closing connections, so they don't keep stale state @@ -363,11 +380,12 @@ async function shutdown(signal: string): Promise { cleanupPriceUpdateTimers(); cleanupEventBusListeners(); - // Terminate all active WebSocket connections so they don't hold the server open - for (const client of wss.clients) { - client.close(1001, "Server shutting down"); - } - + // Ask every WS client to close cleanly, then force-terminate any that + // haven't within WS_DRAIN_TIMEOUT_MS (see comment above) — this bounds + // how long this phase can take regardless of client behavior, so + // wss.close() right after is never left waiting on a stuck client. + await drainWebSocketClients(wss.clients, WS_DRAIN_TIMEOUT_MS); + // Close WebSocket server (stops accepting new connections) logger.info("Closing WebSocket server"); await new Promise((resolve, reject) => { @@ -377,7 +395,7 @@ async function shutdown(signal: string): Promise { }); }); logger.info("WebSocket server closed"); - + // Close HTTP server (stops accepting new requests) logger.info("Closing HTTP server"); await new Promise((resolve, reject) => { @@ -387,9 +405,9 @@ async function shutdown(signal: string): Promise { }); }); logger.info("HTTP server closed"); - + // Note: Supabase client doesn't need explicit cleanup (connection pooling handled automatically) - + logger.info("Shutdown complete"); process.exit(0); } catch (err) { diff --git a/src/utils/shutdown.ts b/src/utils/shutdown.ts new file mode 100644 index 0000000..6c64e43 --- /dev/null +++ b/src/utils/shutdown.ts @@ -0,0 +1,43 @@ +/** + * Shutdown helpers extracted from index.ts so the bounded-draining logic is + * independently unit-testable — index.ts itself has real side effects on + * import (starts the HTTP server, registers signal handlers) and is not + * unit-tested anywhere in this codebase. + */ + +interface DrainableClient { + close(code: number, reason: string): void; + terminate(): void; +} + +/** + * Ask every client to close cleanly, then force-terminate any that haven't + * within `timeoutMs`. Bounds how long WS draining can take regardless of + * client behavior — the `ws` library's own per-socket close-handshake + * timeout defaults to 30s, which would otherwise be free to block a + * caller's own (typically much shorter) overall shutdown budget. + */ +export async function drainWebSocketClients( + clients: Iterable, + timeoutMs: number, +): Promise { + for (const client of clients) { + client.close(1001, "Server shutting down"); + } + await new Promise((resolve) => setTimeout(resolve, timeoutMs)); + for (const client of clients) { + client.terminate(); + } +} + +/** + * Await `promise`, but never wait longer than `ms` — resolves either way + * rather than rejecting on timeout, since callers use this to bound a + * best-effort step (e.g. a webhook call) that shouldn't block shutdown. + */ +export async function withTimeout(promise: Promise, ms: number): Promise { + await Promise.race([ + promise, + new Promise((resolve) => setTimeout(resolve, ms)), + ]); +} diff --git a/tests/utils/shutdown.test.ts b/tests/utils/shutdown.test.ts new file mode 100644 index 0000000..ff0a715 --- /dev/null +++ b/tests/utils/shutdown.test.ts @@ -0,0 +1,115 @@ +/** + * Tests for the shutdown-draining helpers, including BUG-102: the `ws` + * library's own per-socket close-handshake timeout defaults to 30s — far + * longer than this process's overall SHUTDOWN_TIMEOUT_MS (10s in index.ts). + * drainWebSocketClients must force-terminate stuck clients within its own + * bounded window so a single slow/unresponsive client can't make the + * caller's wss.close() block past the overall shutdown budget. + */ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { drainWebSocketClients, withTimeout } from "../../src/utils/shutdown.js"; + +function makeClient(opts: { selfCloses?: boolean } = {}) { + const client = { + close: vi.fn(() => { + if (opts.selfCloses) client.terminate(); + }), + terminate: vi.fn(), + }; + return client; +} + +describe("drainWebSocketClients", () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it("asks every client to close, then force-terminates any still present after timeoutMs", async () => { + const stuckClient = makeClient({ selfCloses: false }); + const promise = drainWebSocketClients([stuckClient], 3000); + + expect(stuckClient.close).toHaveBeenCalledWith(1001, "Server shutting down"); + expect(stuckClient.terminate).not.toHaveBeenCalled(); + + await vi.advanceTimersByTimeAsync(3000); + await promise; + + // Force-terminated because it never acked the close handshake (BUG-102's + // exact scenario — without this, a real `ws` socket would still be open + // 30s later, well past the 3s bound here). + expect(stuckClient.terminate).toHaveBeenCalledTimes(1); + }); + + it("unconditionally terminates every client after the timeout, even one that already closed cleanly (a real ws socket's terminate() is a documented no-op when already closed)", async () => { + const fastClient = makeClient({ selfCloses: true }); + const promise = drainWebSocketClients([fastClient], 3000); + + await vi.advanceTimersByTimeAsync(3000); + await promise; + + expect(fastClient.close).toHaveBeenCalledTimes(1); + expect(fastClient.terminate).toHaveBeenCalled(); + }); + + it("does not block longer than timeoutMs regardless of how many clients are passed", async () => { + const clients = Array.from({ length: 50 }, () => makeClient({ selfCloses: false })); + const promise = drainWebSocketClients(clients, 3000); + + await vi.advanceTimersByTimeAsync(2999); + // Not yet resolved — timer hasn't fired. + let resolved = false; + promise.then(() => { resolved = true; }); + await Promise.resolve(); + expect(resolved).toBe(false); + + await vi.advanceTimersByTimeAsync(1); + await promise; + for (const c of clients) { + expect(c.terminate).toHaveBeenCalledTimes(1); + } + }); +}); + +describe("withTimeout", () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it("resolves as soon as the promise resolves, without waiting for the timeout", async () => { + let resolved = false; + const fast = Promise.resolve().then(() => { resolved = true; }); + + await withTimeout(fast, 2000); + expect(resolved).toBe(true); + }); + + it("resolves anyway once ms elapses, even if the promise never settles (BUG-102: sendInfoAlert has no internal timeout)", async () => { + const hanging = new Promise(() => {}); // never resolves/rejects + const promise = withTimeout(hanging, 2000); + + await vi.advanceTimersByTimeAsync(2000); + await expect(promise).resolves.toBeUndefined(); + }); + + it("does not reject even if the underlying promise eventually rejects", async () => { + const willReject = new Promise((_, reject) => { + setTimeout(() => reject(new Error("boom")), 5000); + }); + const promise = withTimeout(willReject, 2000); + + await vi.advanceTimersByTimeAsync(2000); + await expect(promise).resolves.toBeUndefined(); + // Let the rejection actually fire so it doesn't leak as an unhandled + // rejection into a later test — attach a no-op catch. + await vi.advanceTimersByTimeAsync(3000); + await willReject.catch(() => undefined); + }); +});