fix: bound module lifecycle shutdown
Nothing bounded shutdown, and a module that failed to start was never cleaned up. `startModules` appended to its rollback set only after `start()` resolved, so a hook that acquired a connection, registered a listener, or recorded partial initialization and then threw had its own `stop()` skipped, while every previously completed module was rolled back correctly. A module now joins the rollback set the moment its start hook is invoked: its own stop hook runs first, then earlier modules in reverse order. The original start issue stays first in the reported issues, and a failure stopping the failing module is appended without preventing the rest of the rollback. The consequence for module authors is explicit and documented — `stop()` may run after a partially completed `start()` and must be safe and idempotent about resources it may or may not hold. Neither stage of shutdown had a deadline. `shutdown()` awaited `server.close()` with no bound, so one open connection could hold it forever, and each stop or rollback hook was awaited without a bound, so a hook that never settled kept the pool open indefinitely. Both now have fixed, non-configurable defaults: 10 seconds per module hook and 30 seconds for the graceful HTTP drain. A hook that reaches its deadline records MODULE_STOP_TIMEOUT or MODULE_ROLLBACK_TIMEOUT and the sequence continues with the next module, so the whole stop sequence is finite in the started module count rather than one global ten-second bound. Timers that lose the race are cleared, the losing promise gets a permanent rejection handler so a late throw cannot become an unhandled rejection, and a timed-out hook is never awaited again. At the drain deadline the platform closes idle and then active connections through Node's own public closeIdleConnections/closeAllConnections, after server.close(), touching no private field, and stops waiting for the close callback. It then runs the bounded module stop sequence and closes the pool, so a drain timeout or a stop failure never skips later cleanup. Both are reported together as an ApiShutdownError carrying only fixed booleans and the already sanitized module error; a forced drain is a shutdown failure, not a success. Stated honestly rather than overstated: a deadline bounds how long the platform waits, not how long module code runs. An in-process promise cannot be canceled, and closing a socket does not prove a handler promise ended. What is guaranteed is that shutdown stops waiting and the pool closes afterwards, so late database work fails. Co-Authored-By: Claude Opus 5 <[email protected]>
This commit is contained in:
co-authored by
Claude Opus 5
parent
800ecfdb92
commit
490b85b07c
@@ -336,6 +336,8 @@ function apiOrigin(running: RunningApi): string {
|
||||
|
||||
interface StartConfiguredApiOptions {
|
||||
readonly clientAddress?: ClientAddressConfigInput;
|
||||
/** Test-only narrowing of the platform's 30-second graceful HTTP drain deadline. */
|
||||
readonly drainTimeoutMsOverride?: number;
|
||||
readonly modulesDirectoryOverride?: string;
|
||||
readonly nodeServerTimeoutOverride?: Partial<NodeServerTimeouts>;
|
||||
/** Defaults to `true`: almost every existing scenario in this suite signs accounts up over HTTP
|
||||
@@ -391,6 +393,9 @@ async function startConfiguredApi(
|
||||
...(options.nodeServerTimeoutOverride === undefined
|
||||
? {}
|
||||
: { nodeServerTimeoutOverride: options.nodeServerTimeoutOverride }),
|
||||
...(options.drainTimeoutMsOverride === undefined
|
||||
? {}
|
||||
: { drainTimeoutMsOverride: options.drainTimeoutMsOverride }),
|
||||
});
|
||||
}
|
||||
|
||||
@@ -2725,3 +2730,114 @@ describe.sequential("live API — Node header/request timeouts and client errors
|
||||
expect(logs.join("\n")).not.toContain("zzz");
|
||||
});
|
||||
});
|
||||
|
||||
/**
|
||||
* Pass 4: shutdown is finite even when HTTP work does not settle.
|
||||
*
|
||||
* These drive a real bound listener and a real socket rather than a mock, because the behavior
|
||||
* under test is what Node's own `server.close()` does and does not do. Every socket, server, and
|
||||
* disposable database is closed in `finally`, and each scenario carries its own outer deadline so
|
||||
* a regression fails rather than hangs.
|
||||
*/
|
||||
describe.sequential("live API — bounded HTTP drain and shutdown", () => {
|
||||
async function withDeadline<T>(operation: Promise<T>, timeoutMs: number): Promise<T> {
|
||||
let timer: ReturnType<typeof setTimeout> | undefined;
|
||||
try {
|
||||
return await Promise.race([
|
||||
operation,
|
||||
new Promise<never>((_resolve, reject) => {
|
||||
timer = setTimeout(
|
||||
() => reject(harnessError("shutdown did not settle in time")),
|
||||
timeoutMs,
|
||||
);
|
||||
}),
|
||||
]);
|
||||
} finally {
|
||||
clearTimeout(timer);
|
||||
}
|
||||
}
|
||||
|
||||
it("serves a real request and then drains cleanly, well inside the deadline", async () => {
|
||||
const database = await createDisposableDatabase("drain_ok");
|
||||
await applyCoreMigrations(database.url);
|
||||
const running = await startConfiguredApi(database.url, { drainTimeoutMsOverride: 5_000 });
|
||||
try {
|
||||
const origin = apiOrigin(running);
|
||||
const response = await fetch(`${origin}/api/v1/principal`);
|
||||
expect(response.status).toBe(200);
|
||||
expect(await response.json()).toEqual({ kind: "anonymous" });
|
||||
|
||||
// Nothing is stalled, so the graceful path completes and shutdown reports success — the
|
||||
// drain deadline is never reached and no connection is force-closed.
|
||||
await expect(withDeadline(running.shutdown(), 20_000)).resolves.toBeUndefined();
|
||||
|
||||
// The listener really is closed afterwards.
|
||||
await expect(fetch(`${origin}/api/v1/principal`)).rejects.toBeTruthy();
|
||||
} finally {
|
||||
await running.shutdown().catch(() => undefined);
|
||||
await dropDatabase(database.name);
|
||||
}
|
||||
});
|
||||
|
||||
it("force-closes a stalled connection at the drain deadline and still reaches pool closure", async () => {
|
||||
const database = await createDisposableDatabase("drain_forced");
|
||||
await applyCoreMigrations(database.url);
|
||||
// A short, test-only drain deadline; production keeps HTTP_DRAIN_TIMEOUT_MS unchanged.
|
||||
const running = await startConfiguredApi(database.url, { drainTimeoutMsOverride: 250 });
|
||||
const address = running.server.address();
|
||||
if (!address || typeof address !== "object") {
|
||||
throw harnessError("The API integration server has no bound address.");
|
||||
}
|
||||
const socket = net.connect({ host: "127.0.0.1", port: address.port });
|
||||
try {
|
||||
// A real, deliberately incomplete request: headers are never finished, so Node keeps the
|
||||
// connection open and `server.close()` alone would wait indefinitely.
|
||||
await new Promise<void>((resolve, reject) => {
|
||||
socket.once("error", reject);
|
||||
socket.on("data", () => undefined);
|
||||
socket.write("GET /api/v1/principal HTTP/1.1\r\nHost: 127.0.0.1\r\n", () => resolve());
|
||||
});
|
||||
|
||||
const closed = new Promise<void>((resolve) => {
|
||||
socket.once("close", () => resolve());
|
||||
});
|
||||
|
||||
let captured: unknown;
|
||||
try {
|
||||
await withDeadline(running.shutdown(), 20_000);
|
||||
} catch (error) {
|
||||
captured = error;
|
||||
}
|
||||
|
||||
// A forced drain is a genuine shutdown failure, never reported as success.
|
||||
expect(captured).toMatchObject({ drainTimedOut: true, name: "ApiShutdownError" });
|
||||
// ...and it still carries nothing about the request, socket, or database.
|
||||
const publicText = `${String(captured)}\n${(captured as Error).stack ?? ""}`;
|
||||
expect(publicText).not.toContain("127.0.0.1");
|
||||
expect(publicText).not.toContain(database.name);
|
||||
// The connection was actually closed by the platform, not left dangling.
|
||||
await withDeadline(closed, 10_000);
|
||||
} finally {
|
||||
socket.destroy();
|
||||
await running.shutdown().catch(() => undefined);
|
||||
await dropDatabase(database.name);
|
||||
}
|
||||
});
|
||||
|
||||
it("shares one memoized shutdown across concurrent callers", async () => {
|
||||
const database = await createDisposableDatabase("drain_once");
|
||||
await applyCoreMigrations(database.url);
|
||||
const running = await startConfiguredApi(database.url, { drainTimeoutMsOverride: 5_000 });
|
||||
try {
|
||||
const [first, second, third] = await withDeadline(
|
||||
Promise.all([running.shutdown(), running.shutdown(), running.shutdown()]),
|
||||
20_000,
|
||||
);
|
||||
expect([first, second, third]).toEqual([undefined, undefined, undefined]);
|
||||
// A later caller observes the same completed result rather than restarting cleanup.
|
||||
await expect(running.shutdown()).resolves.toBeUndefined();
|
||||
} finally {
|
||||
await dropDatabase(database.name);
|
||||
}
|
||||
});
|
||||
});
|
||||
|
||||
@@ -1067,11 +1067,14 @@ describe("Ekklesia API module runtime startup and shutdown", () => {
|
||||
issues: [expect.objectContaining({ code: "MODULE_START_FAILED" })],
|
||||
});
|
||||
|
||||
// The module whose start hook failed is rolled back first through its own stop hook, then the
|
||||
// module that had already started, in reverse order.
|
||||
expect(recorder.events).toEqual([
|
||||
"one:register",
|
||||
"two:register",
|
||||
"one:start",
|
||||
"two:start",
|
||||
"two:stop",
|
||||
"one:stop",
|
||||
]);
|
||||
expect(poolConstructor).toHaveBeenCalledTimes(1);
|
||||
@@ -1177,8 +1180,14 @@ describe("Ekklesia API module runtime startup and shutdown", () => {
|
||||
|
||||
const running = await startApi(validConfig(), { modulesDirectoryOverride: modulesDirectory });
|
||||
|
||||
// Shutdown now aggregates which stages failed; the module-runtime error is carried intact.
|
||||
await expect(running.shutdown()).rejects.toMatchObject({
|
||||
issues: [expect.objectContaining({ code: "MODULE_STOP_FAILED", moduleId: "stop-fails" })],
|
||||
drainTimedOut: false,
|
||||
moduleStopError: {
|
||||
issues: [expect.objectContaining({ code: "MODULE_STOP_FAILED", moduleId: "stop-fails" })],
|
||||
},
|
||||
moduleStopFailed: true,
|
||||
name: "ApiShutdownError",
|
||||
});
|
||||
expect(poolEnd).toHaveBeenCalledTimes(1);
|
||||
});
|
||||
|
||||
@@ -450,8 +450,15 @@ describe.sequential("live API — module database explicit migration ownership",
|
||||
await applyCoreMigrations(database.url);
|
||||
resetRecorder();
|
||||
|
||||
// The module whose `start` failed is now rolled back through its own `stop` hook first. That
|
||||
// hook also writes to the table its missing migration would have created, so it fails too —
|
||||
// which is exactly the documented reason a `stop` hook must tolerate partial initialization.
|
||||
// Both outcomes are reported, in order, and neither is swallowed.
|
||||
await expect(startMigratedApi(database.url, fixtureModulesDirectory)).rejects.toMatchObject({
|
||||
issues: [expect.objectContaining({ code: "MODULE_START_FAILED", moduleId: "db-facade" })],
|
||||
issues: [
|
||||
expect.objectContaining({ code: "MODULE_START_FAILED", moduleId: "db-facade" }),
|
||||
expect.objectContaining({ code: "MODULE_ROLLBACK_FAILED", moduleId: "db-facade" }),
|
||||
],
|
||||
});
|
||||
|
||||
// No schema inference, no automatic table creation as a side effect of the failed attempt.
|
||||
|
||||
Reference in New Issue
Block a user