From d8465ca2a85dab13f1430034e0b6d48823491f1e Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Thu, 3 Sep 2026 22:04:24 +0300 Subject: [PATCH 01/11] fix(persistence-test): eliminate forced database teardown race MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `withDatabase` ended its pool and then immediately ran `DROP DATABASE ... WITH (FORCE)`. That produced intermittent `terminating connection due to administrator command` failures in `postgres integration (persistence)`, on a different test each run. `pool.end()` does not wait for its clients to close. In pg 8.22.0 `_pulseQueue` reaches the end callback in the same synchronous turn in which `_remove` filters the last client out of `_clients`, while `client.end()` has only queued the Terminate byte. Measured here: zero of four `remove` events had fired at the moment `end()` resolved. The drop could therefore still find a backend attached; FORCE terminated it, and the FATAL arrived on a socket whose pool still had `idleListener` attached — `_remove` never detaches it — so pg re-emitted it as `pool.emit('error')`. With no listener that is an uncaught exception, which node:test attributes to whichever test is running rather than to the teardown that caused it. FORCE was not required, and was the harm. Measured against PostgreSQL 16.14 with a backend deliberately held open: plain `DROP DATABASE` fails with SQLSTATE 55006 and leaves that connection untouched, where FORCE succeeds by killing it. Teardown now waits for the database to be genuinely unused and drops it ordinarily — a loud, harmless failure in place of a quiet, harmful success. FORCE survives only on the emergency path, after teardown has already given up, so no database is leaked. The protocol moves into `withTestDatabase`, exported from the new `@chess-platform/persistence/test-support` subpath rather than from the driver-facing `./pg` surface. Both isolated-database call sites use it. `auth-signin-schema.integration.test.ts` had absorbed SQLSTATE 57P01 with a `pool.on('error', ...)` listener when this race surfaced there first; that listener is deleted, because the corrected lifecycle never terminates a connection and a real connection failure in those tests should stay as loud as it was. Teardown is bounded — `pool.end()` included, since a client checked out and never released leaves it pending indefinitely (measured past a three-second bound) — names the lingering backends when it gives up, and never lets a cleanup failure replace the assertion the test failed on. Seven regression tests pin the contract against a real server. None asserts on elapsed wall-clock time: the waiting test releases its lingering connection from the quiescence callback, so it is a latch rather than a sleep. Seven of nine mutations are killed, including restoring the immediate FORCE drop, making the predicate unconditional, dropping before the pool is ended, and removing the bound. No production code changes: `createPool` and `migrate` are untouched, and migration order, SQL, checksums, transaction and advisory-lock semantics are all unchanged. No migration was added. Signature B is a separate defect and remains UNRESOLVED. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- docs/PROJECT_STATE.md | 50 ++- docs/ROADMAP.md | 1 + .../auth-signin-schema.integration.test.ts | 136 +++----- packages/persistence/package.json | 4 + .../persistence/src/test-support/database.ts | 309 ++++++++++++++++++ .../test/test-database.integration.test.ts | 270 +++++++++++++++ .../variant-migrations.integration.test.ts | 40 +-- 7 files changed, 696 insertions(+), 114 deletions(-) create mode 100644 packages/persistence/src/test-support/database.ts create mode 100644 packages/persistence/test/test-database.integration.test.ts diff --git a/docs/PROJECT_STATE.md b/docs/PROJECT_STATE.md index 1ca55efa..0c2f571b 100644 --- a/docs/PROJECT_STATE.md +++ b/docs/PROJECT_STATE.md @@ -4,7 +4,55 @@ > to read **only this file** and continue immediately. Updated after every > milestone and every significant architectural step. -_Last updated: 2026-09-03 — M15 Increment 44: Signature B parent-side termination evidence._ +_Last updated: 2026-09-03 — M15 Increment 45: PostgreSQL isolated-database teardown race._ + + +## M15 Increment 45 — PostgreSQL isolated-database teardown race + +The intermittent `postgres integration (persistence)` failure recorded during Increment 44 — +`terminating connection due to administrator command`, arriving as an uncaught exception attributed +to whichever test happened to be running — is closed. It was a lifecycle defect in the test helpers, +not in migration logic: migration order, SQL, checksums, transaction semantics and advisory-lock +semantics are all untouched, and no migration was added. + +**Mechanism, measured rather than assumed.** `withDatabase` ended its pool and then immediately ran +`DROP DATABASE ... WITH (FORCE)`. `pool.end()` does not wait for its clients to close: in pg 8.22.0 +`_pulseQueue` reaches the end callback in the same synchronous turn in which `_remove` filters the +last client out of `_clients`, while `client.end()` has only queued the Terminate byte. Instrumented +here, **zero of four `remove` events had fired at the moment `end()` resolved**. A drop issued +straight afterwards could therefore still find a backend attached; `FORCE` terminated it, and the +`FATAL` landed on a socket whose pool still had `idleListener` attached — `_remove` never detaches +it — so `pg` re-emitted it as `pool.emit('error')`, an unhandled EventEmitter error. + +**`WITH (FORCE)` was not required, and was the harm.** Measured against PostgreSQL 16.14 with a +backend deliberately held open: plain `DROP DATABASE` fails with SQLSTATE 55006 and leaves that +connection untouched, where `WITH (FORCE)` succeeds by killing it. The fix trades a quiet, harmful +success for a loud, harmless failure — teardown waits for the database to be genuinely unused, then +drops it ordinarily. FORCE survives only on the emergency path, where teardown has already given up +and is removing the database so nothing leaks. + +**Shared helper.** `packages/persistence/src/test-support/database.ts` exposes `withTestDatabase` +through the new `@chess-platform/persistence/test-support` subpath, kept off the driver-facing `./pg` +surface. Both isolated-database call sites use it: `variant-migrations.integration.test.ts` and +`packages/api/test/auth-signin-schema.integration.test.ts`. The latter previously carried a +`pool.on('error', ...)` listener absorbing SQLSTATE 57P01 — a symptom fix for this same race, added +when it surfaced there first. **That listener is deleted**: the corrected lifecycle never terminates +a connection, so there is nothing to absorb, and a real connection failure in those tests is once +again as loud as it should be. `createPool` and `migrate` are unchanged; no production code moved. + +Teardown is bounded — `pool.end()` included, because a client checked out and never released leaves +it pending indefinitely (measured past a three-second bound) — names the lingering backends when it +gives up, never leaks a database on any path, and never lets a cleanup failure replace the assertion +the test actually failed on. Seven regression tests pin the contract against a real server; none +asserts on elapsed wall-clock time, which would measure the machine rather than the guarantee. + +**Found while validating, not fixed here:** the persistence suite is not idempotent against a reused +database. A second consecutive run against the same server fails — 12 tests on `b95065f`, 9 with +this change — in the achievements, identity-tokens and tournaments repositories, which share +`chess_test` rather than taking a database of their own. CI provisions a fresh server every run, so +it has never surfaced there. Pre-existing, and out of scope for this increment. + +**Signature B remains UNRESOLVED.** It is a separate defect and nothing here touches it. ## M15 Increment 44 — Signature B parent-side termination evidence diff --git a/docs/ROADMAP.md b/docs/ROADMAP.md index 7bce2f42..1682f8ee 100644 --- a/docs/ROADMAP.md +++ b/docs/ROADMAP.md @@ -1350,6 +1350,7 @@ Debt observed during M14. Each states what is known, not what is planned; items - **The search surface was not gated on `capabilities.search`, so an absolute kill switch still showed a search box (RESOLVED in M15 Increment 24 / ADR-0132 §5).** `SEARCH_ENABLED=0` — the chart's `search.enabled: false`, an absolute kill switch per ADR-0055 — leaves `searchRepository` unconstructed and `GET /v1/search` answering 503 on every mode, keyword included. The entry point was the persistent header form in `packages/web/index.html`, present on every page; being a `
` rather than an `a[data-route]`, `NAV_CAPABILITY_MAP` could not reach it, which is why the first pass at Increment 24 gated the semantic and hybrid *modes* and left keyword ungated — the same defect class one mode over. Raised by the Qodo review of PR #155. **Fixed in the same increment rather than deferred:** the form now ships `hidden` and is revealed by `applySearchCapability` only on an explicit `search: true`; the route renders an honest unavailable notice and issues no request; and keyword search waits for the capability answer, reversing this increment's own earlier latency decision, because knowing whether a request is pointless requires having asked. A markup-contract test pins the `hidden` attribute, since the gate depends on it and every other test passes without it. - **Clicking a search mode discarded text typed since the page loaded (RESOLVED in a follow-up to M15 Increment 24 / ADR-0132).** `createModeInput` in `packages/web/src/app/search-mount.ts` closed over the query captured when the route mounted, so `navigateToSearchMode` navigated with the old term and the remount reset the input to match it. Type a new term into the header field, click **Semantic** without pressing enter, and the typed text was gone with no indication it had been discarded. Pre-existing — the closure predated Increment 24 and was untouched by it — and found by the adversarial review of PR #155 while reviewing the capability gate wrapped around the same control. **Resolved:** the query is now a `() => string` read when a mode is chosen rather than a string captured when the selector renders, matching what `main.ts`'s submit handler already does, and falling back to the mounted query only where the document has no header input. Two regression tests, one of which fails against the exact pre-fix closure. - **`startHarness` drew ports `fetch` refuses (RESOLVED in ADR-0140); the unexplained whole-file failure is still open.** Two signatures were filed here, deliberately not as one cause, and that judgement held. **Signature A is resolved.** WHATWG Fetch blocks eighty-two ports and undici enforces the list on the port number alone, before opening a socket — so `server.listen(0)` could bind, listen and answer raw TCP while `fetch` still refused, surfacing as `TypeError: fetch failed` / `Error: bad port` at the harness’s first request rather than at the listen that caused it. Whether it can happen at all is a property of the host’s dynamic port range: a typical Linux CI range (32768–60999) contains no blocked port, while the Windows range in use here (1024–15000) contains nineteen, which is the whole of "green on CI, flaky locally". The guard that already existed was incomplete in a way that still failed — its hand-observed set of eighteen ports was the spec list intersected with one machine’s range **minus `6679`** — and it retried unboundedly, had no behaviour on exhaustion, and had been copy-pasted into `auth-signin-schema.integration.test.ts`, so the missing port had to be found twice. `packages/api/test/listen.ts` now owns port acquisition for both sites: the spec-complete eighty-two ports (verified by sweeping all 65535 through the real `fetch` on Node v24.15.0), a bounded twenty attempts, each rejected listener closed before the next is asked for, a guarded `address()` read in place of the `as AddressInfo` cast, and an exhaustion error naming the attempts and rejected ports and nothing else. **Signature B is not resolved and was not folded in.** A file still fails with `'test failed'`, no assertion, no stack and none of its own tests reported. Twenty consecutive full runs gave five failures: on pre-fix code one signature A (`auth.test.js`) and three signature B; on post-fix code one signature B and no signature A. The port fix removes A and leaves B exactly where it was, which is the evidence that they are two defects. Four different files were hit (`move-explanation-route`, `tournament-commentary-route`, `bot-detection-analyze`, `anti-cheat-analysis`), sharing no import beyond `./helpers`; each died in 589–703 ms with no test of its own reporting and no stderr. Refuted with evidence: ephemeral-port exhaustion (113 sockets in TIME_WAIT against a 13977-port range), a `Promise.race` loser becoming an unhandled rejection (`race` subscribes to every promise, confirmed on v24.15.0), a throwing `after`/`afterEach` hook (the affected files use none), and a double `close()` rejecting (awaited in a `finally`, it would be attributed to that test with a stack). A second bounded pass — twelve more full runs under the TAP reporter with a preload recording `uncaughtException`, `unhandledRejection` and any non-zero exit — produced twelve clean runs and captured nothing at the time. **A follow-up increment (`claude/node-test-signature-b`) then captured the defect directly, three more times, on three files never previously implicated** (`rate-limit-atomicity`, `dependency-parity`, `studies-api`) — seven distinct files observed with this symptom to date. Occurrences across seven distinct files make a shared or cross-cutting path more plausible and make a defect confined to one test file less likely, but do not exclude file-specific inputs or lifecycle interactions. An instrumented preload (`packages/api/test/diagnostics/signature-b-preload.cjs`) hooking process-level events — `process.exit`, `process.abort`, `process.kill`, `uncaughtExceptionMonitor` (passively observing uncaught exceptions and fatal unhandled rejections), `warning`, `beforeExit`, and Node’s own unconditional `exit` — showed **none of the hooks active at the time fired** on any of the three historical captures (though `process.abort()` was not wrapped in those initial runs and is now covered for future occurrences). A synthetic `process.exit(1)`-before-registration fixture reproduces the identical silent shape; every other synthetic mechanism tried (a post-test async throw, an emitter `'error'` with its listener removed, a synchronous module-load throw, a delayed `SIGKILL`) prints a visibly different diagnostic line, stack, or partial test output that the real defect never shows. This narrows the investigated possibilities while leaving the root cause unresolved: the per-file child process (`node --test` spawns one per file, confirmed by distinct PIDs) was not terminated by `process.exit`, uncaught exceptions, or fatal unhandled rejections, and future runs with `process.abort` instrumentation will record whether abort was called through JS; an absent record narrows in-runtime JS termination but cannot alone prove external termination without corroborating child exit status/signal data or OS-level crash evidence (e.g. distinguishing an external kill or uncatchable signal from a native C++/V8 crash). The machine had roughly 2.5 GB of 15.7 GB RAM free at capture time with several other agents’ processes concurrently running, which is circumstantially consistent with resource contention, but no crash was recorded in the Windows Application or System event logs in that window, so the exact external trigger is still not established. No fix was invented — the forbidden responses (sleeps, whole-file retries, lowering concurrency) would only hide the unresolved root cause, whose origin is not yet established. **A further increment then crossed the parent/child boundary the earlier work stopped at, and found the evidence had been there all along:** Node's runner attaches the child's `exitCode` and `signal` to the `ERR_TEST_FAILURE` it throws, and the `spec` reporter discards them — `formatError` replaces the error with `error.cause`, the bare string `'test failed'` — while the built-in `tap` reporter serializes them, so running `spec` to stdout and `tap` to a file recovers the exit status with no custom reporter and no patched internals. Exit codes were measured on this platform rather than assumed: `process.abort()` gives `134`, `Stop-Process -Force` gives `4294967295`, NTSTATUS faults surface as raw unsigned values such as `3221225477` (`0xC0000005`) — and `1` is produced alike by an uncaught exception, `process.exit(1)`, `taskkill /F` and `process.kill`, so it identifies nothing on its own and is classified `inconclusive`. `signature-b-correlate.cjs` joins the parent's TAP record to the child's JSONL log on the test file path (which also yields the child PID) and states what the pair does and does not establish; where the exit code is ambiguous, a child that reached `preload-installed` and then logged nothing still excludes `process.exit` and an uncaught exception, because both would have left a record and fired Node's `exit` event. A bounded pass of 20 runs under this instrumentation produced 0 captures — which bounds the rate and proves nothing: treating the historical ~1-in-5 as an independent per-run rate, zero captures in 20 runs has probability `(4/5)^20 ≈ 1.2%`, and independence is an assumption rather than an established fact; it ran at 3084–3834 MB free against roughly 2.5 GB at the historical captures, consistent with the resource-contention hypothesis but not evidence for it. **Signature B stays UNRESOLVED**; what changed is that the next occurrence is readable rather than silent. See ADR-0140 §4. +- **Isolated-database test teardown dropped databases out from under connections that had not finished closing (RESOLVED in M15 Increment 45).** `withDatabase` in `packages/persistence/test/variant-migrations.integration.test.ts` ended its pool and then immediately ran `DROP DATABASE ... WITH (FORCE)`. `pool.end()` does not wait for its clients to close: in pg 8.22.0 `_pulseQueue` reaches the end callback in the same synchronous turn in which `_remove` filters the last client out of `_clients`, while `client.end()` has only queued the Terminate byte — instrumentation recorded **zero of four `remove` events fired at the moment `end()` resolved**. The drop could therefore still find a backend attached; `FORCE` terminated it, and the resulting `FATAL` arrived on a socket whose pool still had `idleListener` attached, which `pg` re-emitted as `pool.emit('error')` — an unhandled EventEmitter error that `node:test` attributed to whichever test was running rather than to the teardown that caused it. It surfaced as intermittent `terminating connection due to administrator command` failures in `postgres integration (persistence)` during M15 Increment 44, on a different test each run, which is the signature of a race rather than a broken assertion. The same shape existed in `packages/api/test/auth-signin-schema.integration.test.ts`, which had absorbed SQLSTATE 57P01 with a `pool.on('error', ...)` listener — a symptom fix for the same cause. **Resolved in Increment 45:** a shared `withTestDatabase` helper (`@chess-platform/persistence/test-support`) ends the pool under a bound, waits for `pg_stat_activity` to report the database unused, and drops it *without* `FORCE`. Measured on PostgreSQL 16.14, a plain drop against a still-attached backend fails with SQLSTATE 55006 and leaves that connection untouched, where `FORCE` succeeds by killing it — so the change trades a quiet, harmful success for a loud, harmless failure. FORCE remains only on the emergency path that guarantees no database is leaked once teardown has already failed. The 57P01 absorber is deleted, because the corrected lifecycle never causes one. `createPool` and `migrate` are unchanged, and no migration was added. - **`ApiServer.listen` registered no `'error'` handler, so a failed bind hung and raised an uncaught event (RESOLVED in ADR-0140 §5).** `packages/api/src/server.ts` resolved its promise from the `listening` callback only and built it with no reject path. A bind failing asynchronously (`EADDRINUSE`, `EMFILE`) left the promise pending forever and, with no `'error'` listener on the `http.Server`, was re-raised as an uncaught exception. Found while investigating ADR-0140 and independently raised by the Qodo review of PR #21. **Resolved in the same increment** rather than deferred, because ADR-0140 §2's bounded, diagnosable acquisition is not true without it — the retry can only report a bind error if the listener it is handed rejects. A one-shot `'error'` listener now rejects and is removed once listening, so later server errors keep their previous semantics rather than being swallowed by a `reject` on a settled promise. The regression test fails against the exact pre-fix code, through an uncaught `ERR_UNHANDLED_ERROR`. - **`main.ts`'s controller-disposal list is manual, untested, and silently incomplete when a section is added (RESOLVED in Increment 25 / ADR-0092).** `run()` in `packages/web/src/main.ts` disposes the previous route's controllers by name, and its own comment says doing so "is what makes re-bootstrapping safe" — but adding a section to `bootstrap` and forgetting to add it there compiles, passes every gate, and leaks. Increment 23 shipped exactly that omission for `LearningController` and it was caught in PR review, not by a test. `main.ts` has no test coverage of any kind, so no section's disposal is verified. A structural fix (bootstrap returning its disposables as a collection, or a type-level exhaustiveness check keyed off the result type) would make the next omission a compile error; it is a refactor across ~15 return sites and belongs in its own increment. **Resolved in Increment 25 (ADR-0092):** extracted `createLifecycle` run loop in `lifecycle.ts`, defined `BootstrappedDisposables` and `DisposableKey` driving `DISPOSABLE_TEARDOWN_MAP: Record` for compile-time exhaustiveness, normalised `.dispose()` verb across all disposables, and cascaded `GameController.stop()` to `gameSync.stop()`. - **`stepView` sends the answers to the learner (RESOLVED in Increment 29 / ADR-0095).** `packages/api/src/presenters.ts` emits `expectedSan` on a move step and `correctIndex` on a quiz step, and `GET /v1/lessons/:id/steps` is the route the learner's own lesson page calls. Increment 23 omits both from the client-side types (`packages/web/src/api/models.ts`), so the app cannot render or grade against them and a future edit that tries becomes a compile error — but the fields are still on the wire and readable in devtools. The authoring routes legitimately need them returned to the author, so the fix is a learner-scoped step view (or a caller-dependent projection), not a deletion: an API contract decision with its own ADR. Nothing rated or rewarded depends on step progress today, so this is a wart rather than a breach. **Resolved in Increment 29 (ADR-0095):** added `LearnerStepView` / `learnerStepView` in `packages/api/src/presenters.ts` omitting `expectedSan` and `correctIndex`. `GET /v1/lessons/:id/steps` and `GET /v1/steps/:id` now check course authorship via `repo.getLesson` / `repo.getCourse`, returning full `stepView` to the author and `learnerStepView` to learners and anonymous callers. Updated OpenAPI schema and web model comments. The first attempt resolved authorship with a separate `getLesson` + `getCourse` after the step read, which doubled both routes from 3 SQL queries to 6 because `listSteps` / `getStep` had already made those reads internally and discarded the course; caught in the PR #92 review and fixed by adding `getStepWithCourse` / `listStepsWithCourse` to `LearningRepository`, which return what was already loaded. Both routes now make exactly one repository call, pinned by a counting-proxy test. diff --git a/packages/api/test/auth-signin-schema.integration.test.ts b/packages/api/test/auth-signin-schema.integration.test.ts index 6c376edb..98427e61 100644 --- a/packages/api/test/auth-signin-schema.integration.test.ts +++ b/packages/api/test/auth-signin-schema.integration.test.ts @@ -35,12 +35,12 @@ import { join } from 'node:path'; import type { Server } from 'node:http'; import { closeServer, listenOnFetchablePort } from './listen'; import { - createPool, migrate, migrationFiles, missingMigrations, migrationsDir, } from '@chess-platform/persistence/pg'; +import { withTestDatabase } from '@chess-platform/persistence/test-support'; import type { Pool } from 'pg'; import { createPgApiServer } from '../src/bootstrap'; import { JsonLogger } from '../src/ports/logger'; @@ -54,21 +54,6 @@ const TEST_SECRET = 'test-access-token-secret-0123456789abcdef'; /** The loopback address this suite binds; also the host in the `baseUrl` it hands to `run`. */ const SERVER_HOST = '127.0.0.1'; -/** SQLSTATE 57P01 — `admin_shutdown`: the backend was terminated by `pg_terminate_backend`. */ -const ADMIN_SHUTDOWN = '57P01'; - -/** - * Absorb the one failure a forced database drop is expected to cause, and nothing else. - * - * Re-throwing restores the previous behaviour for every other error — an uncaught exception that - * stops the run — which is what an unexpected connection failure in these tests deserves. - */ -function rethrowUnlessForcedTermination(error: Error): void { - if ((error as { code?: string }).code === ADMIN_SHUTDOWN) return; - if (error.message.includes('terminating connection due to administrator command')) return; - throw error; -} - /** * A directory holding the first `count` migrations, copied byte-for-byte from the real ones. * @@ -93,79 +78,64 @@ interface Fixture { migrateTo(dir: string): Promise; } -/** The same server, same credentials, a different database name. */ -function databaseUrlFor(name: string): string { - const url = new URL(DATABASE_URL!); - url.pathname = `/${name}`; - return url.toString(); -} - /** * Run one case against an API server whose entire world is a private PostgreSQL database, created * for the test and dropped after it. */ async function withSchema(run: (fixture: Fixture) => Promise): Promise { - // Both pools are capped well below `pg`'s default of ten. This file runs inside a suite that - // already holds a great many connections against one server, and a test that quietly opened twenty - // more would push the next file over `max_connections` — which surfaces as that file failing, not - // this one. Two is the floor rather than one: `migrate` holds the advisory lock on a dedicated - // client and runs its statements on another, so a single-connection pool deadlocks against itself. - const admin = createPool({ connectionString: DATABASE_URL, max: 2 }); - const database = `signin_${Date.now().toString(36)}_${Math.floor(Math.random() * 1e9).toString(36)}`; - await admin.query(`CREATE DATABASE "${database}"`); - - const pool = createPool({ connectionString: databaseUrlFor(database), max: 4 }); - - // Dropping a database WITH (FORCE) terminates whatever backends are still attached to it, and a - // `pg` pool with no `error` listener re-emits that as an *uncaught exception* — which node:test - // attributes to whichever test happens to be running, not to the teardown that caused it. That is - // exactly how this arrived: "terminating connection due to administrator command", surfacing in CI - // as a failure of the next test along, while three local runs never raced. + // The pool is capped well below `pg`'s default of ten. This file runs inside a suite that already + // holds a great many connections against one server, and a test that quietly opened twenty more + // would push the next file over `max_connections` — which surfaces as that file failing, not this + // one. Two is the floor rather than one: `migrate` holds the advisory lock on a dedicated client + // and runs its statements on another, so a single-connection pool deadlocks against itself. // - // Only that one error is absorbed. A listener that swallowed everything would also hide a real - // connection failure in these tests, which is the opposite of what they are for — so anything else - // is re-thrown and stays as loud as it was before. The SQLSTATE is the test rather than the - // message, because `lc_messages` can translate the text and cannot translate `57P01`. - pool.on('error', rethrowUnlessForcedTermination); - admin.on('error', rethrowUnlessForcedTermination); - // Errors only: a deliberately broken database is about to be exercised, and the point of these - // tests is the status codes, not a wall of expected failure logging. - const logger = new JsonLogger({}, { level: 'error', sink: () => {} }); - - const savedEnv = { NODE_ENV: process.env['NODE_ENV'], EMAIL_PROVIDER: process.env['EMAIL_PROVIDER'] }; - process.env['NODE_ENV'] = 'test'; - process.env['EMAIL_PROVIDER'] = 'console'; - - let http: Server | undefined; - let shutdownAnalysis: (() => Promise) | undefined; - try { - const composed = createPgApiServer({ pool, logger, config: { accessTokenSecret: TEST_SECRET } }); - shutdownAnalysis = composed.shutdownAnalysis; - - const listening = await listenOnFetchablePort( - (p, h) => composed.server.listen(p, h), - SERVER_HOST, - ); - http = listening.server; - - await run({ - baseUrl: `http://${SERVER_HOST}:${listening.port}`, - pool, - migrateTo: (dir) => migrate(pool, dir), - }); - } finally { - if (http) await closeServer(http); - if (shutdownAnalysis) await shutdownAnalysis(); - // Every connection to the database has to be gone before it can be dropped, and the admin pool - // is deliberately connected to a different one. - await pool.end(); - await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); - await admin.end(); - for (const [key, value] of Object.entries(savedEnv)) { - if (value === undefined) delete process.env[key]; - else process.env[key] = value; - } - } + // This used to absorb SQLSTATE 57P01 on both pools, because ending the pool and immediately + // dropping the database WITH (FORCE) terminated backends the pool had not finished closing, and + // `pg` re-emitted that FATAL as an uncaught exception attributed to an unrelated test. That + // listener treated the symptom. `withTestDatabase` waits for the database to be genuinely unused + // and then drops it without FORCE, so nothing is terminated and there is no error to absorb — and + // a real connection failure in these tests is once again as loud as it should be. + await withTestDatabase( + async ({ pool }) => { + // Errors only: a deliberately broken database is about to be exercised, and the point of these + // tests is the status codes, not a wall of expected failure logging. + const logger = new JsonLogger({}, { level: 'error', sink: () => {} }); + + const savedEnv = { NODE_ENV: process.env['NODE_ENV'], EMAIL_PROVIDER: process.env['EMAIL_PROVIDER'] }; + process.env['NODE_ENV'] = 'test'; + process.env['EMAIL_PROVIDER'] = 'console'; + + let http: Server | undefined; + let shutdownAnalysis: (() => Promise) | undefined; + try { + const composed = createPgApiServer({ pool, logger, config: { accessTokenSecret: TEST_SECRET } }); + shutdownAnalysis = composed.shutdownAnalysis; + + const listening = await listenOnFetchablePort( + (p, h) => composed.server.listen(p, h), + SERVER_HOST, + ); + http = listening.server; + + await run({ + baseUrl: `http://${SERVER_HOST}:${listening.port}`, + pool, + migrateTo: (dir) => migrate(pool, dir), + }); + } finally { + // The server and the analysis worker both hold this pool, so they have to be shut down + // before the callback returns — teardown ends the pool the moment it does, and anything + // still using it would fail with "Cannot use a pool after calling end on the pool". + if (http) await closeServer(http); + if (shutdownAnalysis) await shutdownAnalysis(); + for (const [key, value] of Object.entries(savedEnv)) { + if (value === undefined) delete process.env[key]; + else process.env[key] = value; + } + } + }, + { connectionString: DATABASE_URL, max: 4 }, + ); } /** diff --git a/packages/persistence/package.json b/packages/persistence/package.json index bedc4c39..2bc6f23c 100644 --- a/packages/persistence/package.json +++ b/packages/persistence/package.json @@ -13,6 +13,10 @@ "./pg": { "types": "./dist/pg/index.d.ts", "default": "./dist/pg/index.js" + }, + "./test-support": { + "types": "./dist/test-support/database.d.ts", + "default": "./dist/test-support/database.js" } }, "files": [ diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts new file mode 100644 index 00000000..76b786a6 --- /dev/null +++ b/packages/persistence/src/test-support/database.ts @@ -0,0 +1,309 @@ +/** + * @packageDocumentation + * `@chess-platform/persistence/test-support` — a disposable PostgreSQL database per test. + * + * Test-only. Nothing under `src/pg` imports this and no production entry point re-exports it; it is + * a separate subpath so the driver-facing surface does not grow a test harness. + */ + +import type { Pool } from 'pg'; +import { createPool } from '../pg/pool'; + +/** A backend still attached to the disposable database when teardown wanted to drop it. */ +export interface LingeringBackend { + readonly pid: number; + readonly state: string | null; + readonly applicationName: string | null; +} + +/** What the callback is handed: an isolated database and a pool bound to it. */ +export interface TestDatabase { + readonly pool: Pool; + readonly database: string; + readonly connectionString: string; +} + +export interface TestDatabaseOptions { + /** Server to create the disposable database on. Defaults to `DATABASE_URL`. */ + readonly connectionString?: string; + /** + * Pool size handed to the callback. + * + * Two is the floor rather than one: `migrate` holds its advisory lock on a dedicated client and + * runs its statements on another, so a single-connection pool deadlocks against itself. + */ + readonly max?: number; + /** Total budget for teardown, measured from the moment the callback returns. */ + readonly teardownTimeoutMs?: number; + /** Gap between quiescence checks. */ + readonly pollIntervalMs?: number; + /** + * Called once per quiescence check with whatever is still attached. + * + * This exists so a regression test can prove teardown *waited* by observing a check that saw a + * backend, rather than asserting on elapsed wall-clock time — which measures the machine rather + * than the contract. + */ + readonly onQuiescenceCheck?: (backends: readonly LingeringBackend[]) => void; +} + +/** Teardown could not reach a state where the database was safe to drop within its budget. */ +export class DatabaseTeardownTimeoutError extends Error { + readonly database: string; + readonly lingering: readonly LingeringBackend[]; + + constructor(database: string, timeoutMs: number, lingering: readonly LingeringBackend[]) { + const who = + lingering.length > 0 + ? lingering + .map((b) => `pid ${b.pid} (${b.applicationName ?? 'unnamed'}, ${b.state ?? 'unknown state'})`) + .join(', ') + : 'nothing was visible on the server, so the pool itself never finished closing'; + super( + `database "${database}" was still in use ${timeoutMs}ms after its pool was closed: ${who}. ` + + 'It has been dropped so nothing leaks, but something held a connection it did not own.', + ); + this.name = 'DatabaseTeardownTimeoutError'; + this.database = database; + this.lingering = lingering; + } +} + +/** SQLSTATE 55006 — `DROP DATABASE` refusing because a backend is still attached. */ +const OBJECT_IN_USE = '55006'; + +/** Reads the SQLSTATE off an unknown thrown value, or null when it carries none. */ +function sqlState(error: unknown): string | null { + if (typeof error !== 'object' || error === null) return null; + const code = (error as { code?: unknown }).code; + return typeof code === 'string' ? code : null; +} + +/** Replaces the database in a connection URL, leaving credentials and host alone. */ +function urlForDatabase(connectionString: string, database: string): string { + const url = new URL(connectionString); + url.pathname = `/${database}`; + return url.toString(); +} + +/** Sleeps, as the gap between two quiescence checks. */ +function delay(ms: number): Promise { + return new Promise((resolve) => setTimeout(resolve, ms)); +} + +/** + * Resolve once no backend is attached to `database`, or return what is still there at the deadline. + * + * The admin pool is deliberately attached to a different database, so it never counts itself; the + * `pid <> pg_backend_pid()` guard covers a caller who points the admin connection at the target + * anyway. Filtering on `datname` is what keeps two concurrent isolated databases from ever seeing + * each other. + */ +async function waitForQuiescence( + admin: Pool, + database: string, + deadline: number, + pollIntervalMs: number, + onCheck: ((backends: readonly LingeringBackend[]) => void) | undefined, +): Promise { + for (;;) { + const { rows } = await admin.query<{ + pid: number; + state: string | null; + application_name: string | null; + }>( + `SELECT pid, state, application_name + FROM pg_stat_activity + WHERE datname = $1 AND pid <> pg_backend_pid()`, + [database], + ); + const lingering: LingeringBackend[] = rows.map((row) => ({ + pid: row.pid, + state: row.state, + applicationName: row.application_name, + })); + onCheck?.(lingering); + if (lingering.length === 0 || Date.now() >= deadline) return lingering; + await delay(pollIntervalMs); + } +} + +/** + * End a pool, but never wait forever for it. + * + * `pool.end()` closes only *idle* clients: one checked out and never released leaves it pending + * indefinitely — measured against pg 8.22.0, where a leased client kept `end()` unresolved past a + * three-second bound. Teardown has to fail with a diagnostic rather than hang the suite, so the wait + * is bounded and a leaked lease falls through to the quiescence check, which can name the culprit. + */ +async function endPoolWithin(pool: Pool, timeoutMs: number): Promise { + let timer: NodeJS.Timeout | undefined; + try { + await Promise.race([ + pool.end(), + new Promise((resolve) => { + timer = setTimeout(resolve, timeoutMs); + }), + ]); + } catch { + // A rejecting end() still leaves the quiescence check as the authority on whether the database + // can be dropped, and that check reports the situation far better than this error would. + } finally { + if (timer !== undefined) clearTimeout(timer); + } +} + +/** + * Drop the database, tolerating one specific lost race and nothing else. + * + * Quiescence is established with a query, and a backend can attach between that answer and the drop + * — autovacuum being the realistic case. PostgreSQL reports exactly that as 55006, so the drop is + * retried inside the deadline the caller already granted. Every other SQLSTATE propagates untouched: + * this absorbs a *scheduling* outcome, never a database error. + */ +async function dropWhenFree( + admin: Pool, + database: string, + deadline: number, + pollIntervalMs: number, + onCheck: ((backends: readonly LingeringBackend[]) => void) | undefined, +): Promise { + for (;;) { + try { + await admin.query(`DROP DATABASE IF EXISTS "${database}"`); + return; + } catch (error) { + if (sqlState(error) !== OBJECT_IN_USE || Date.now() >= deadline) throw error; + const lingering = await waitForQuiescence(admin, database, deadline, pollIntervalMs, onCheck); + if (lingering.length > 0 && Date.now() >= deadline) { + throw new DatabaseTeardownTimeoutError(database, 0, lingering); + } + } + } +} + +/** + * Make the database safe to drop, then drop it. + * + * Split out so the lifecycle above reads as create/run/tear-down rather than as one long block: the + * ordering here is the contract, and it is easier to check when it is not interleaved with the + * bookkeeping that decides which error to throw. + * + * Returns nothing and throws on failure, so the caller can record the failure without having to + * distinguish "cleaned up" from "reported". + */ +async function tearDown( + admin: Pool, + pool: Pool, + database: string, + teardownTimeoutMs: number, + pollIntervalMs: number, + onCheck: ((backends: readonly LingeringBackend[]) => void) | undefined, +): Promise { + const deadline = Date.now() + teardownTimeoutMs; + await endPoolWithin(pool, Math.max(0, deadline - Date.now())); + + const lingering = await waitForQuiescence(admin, database, deadline, pollIntervalMs, onCheck); + if (lingering.length > 0) { + // Something outlived its owner. Drop the database anyway so the server is not littered with + // abandoned test databases, then say precisely what was holding it. + await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); + throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); + } + await dropWhenFree(admin, database, deadline, pollIntervalMs, onCheck); +} + +/** + * Run `body` against a database created for it alone, and take that database away afterwards. + * + * **Why this is not simply `DROP DATABASE ... WITH (FORCE)`.** `pool.end()` resolves before its + * clients have closed. In pg 8.22.0, `_pulseQueue` reaches the end callback in the same synchronous + * turn in which `_remove` filters the last client out of `_clients`, while `client.end()` has only + * queued the Terminate byte — measured here as zero of four `remove` events having fired at the + * moment `end()` resolved. A drop issued straight afterwards can therefore still find a backend + * attached, and `FORCE` then does exactly what it promises: it terminates that backend, and the + * resulting `FATAL` arrives on a socket whose pool still has `idleListener` attached, because + * `_remove` never detaches it. The error re-emits as `pool.emit('error')` — an unhandled + * EventEmitter error, which `node:test` attributes to whichever test happens to be running rather + * than to the teardown that caused it. Absorbing SQLSTATE 57P01 hides that; it does not fix it. + * + * A plain `DROP DATABASE` cannot do the same damage. Measured against PostgreSQL 16.14: with a + * backend still attached it fails with 55006 and leaves that connection untouched, where `FORCE` + * succeeds by killing it. So teardown waits for the database to be genuinely unused and then drops + * it ordinarily — trading a quiet, harmful success for a loud, harmless failure. + * + * Teardown always runs and always removes the database. It never replaces the callback's own error: + * when both fail, the callback's error is thrown with the teardown failure attached as its `cause`. + */ +export async function withTestDatabase( + body: (db: TestDatabase) => Promise, + options: TestDatabaseOptions = {}, +): Promise { + const connectionString = options.connectionString ?? process.env['DATABASE_URL']; + if (connectionString === undefined || connectionString === '') { + throw new Error('withTestDatabase: no connectionString was given and DATABASE_URL is not set'); + } + + const teardownTimeoutMs = options.teardownTimeoutMs ?? 10_000; + const pollIntervalMs = options.pollIntervalMs ?? 25; + // Generated here and never supplied by a caller, which is what makes it safe to interpolate into + // the DDL below: PostgreSQL has no bound-parameter form for an identifier, so `CREATE DATABASE` + // and `DROP DATABASE` cannot be parameterised. Both radix strings emit only `[0-9a-z]`, so the + // result matches `[a-z0-9_]+` and there is nothing to escape. It is also ~25 characters against + // PostgreSQL's 63-byte identifier limit, so two concurrent databases cannot be truncated to the + // same name — which would let one run's teardown drop another run's database. + const suffix = `${Date.now().toString(36)}_${Math.floor(Math.random() * 0xffffffff).toString(16)}`; + const database = `test_db_${suffix}`; + + const admin = createPool({ connectionString, max: 2 }); + let dropped = false; + let bodyError: unknown; + let teardownError: unknown; + let result!: T; + + try { + await admin.query(`CREATE DATABASE "${database}"`); + const databaseUrl = urlForDatabase(connectionString, database); + const pool = createPool({ connectionString: databaseUrl, max: options.max ?? 4 }); + try { + result = await body({ pool, database, connectionString: databaseUrl }); + } catch (error) { + bodyError = error; + } finally { + try { + await tearDown(admin, pool, database, teardownTimeoutMs, pollIntervalMs, options.onQuiescenceCheck); + dropped = true; + } catch (error) { + teardownError = error; + // `tearDown` drops the database on the path where it reports lingering backends, so this + // only leaves work for the net below when the drop itself was what failed. + dropped = error instanceof DatabaseTeardownTimeoutError; + } + } + } catch (error) { + // Reached only when CREATE DATABASE itself failed, so there is no database to drop and the + // callback never ran. + teardownError ??= error; + dropped = true; + } finally { + try { + if (!dropped) await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); + } catch { + // A last-resort drop that fails leaves the error already in flight, which describes the real + // problem better than this one would. + } finally { + await admin.end(); + } + } + + if (bodyError !== undefined) { + // The test's own failure is the one worth reading. A teardown failure rides along as its cause + // rather than replacing it: losing the assertion that actually failed would be the worse trade. + if (teardownError !== undefined && bodyError instanceof Error && bodyError.cause === undefined) { + bodyError.cause = teardownError; + } + throw bodyError; + } + if (teardownError !== undefined) throw teardownError; + return result; +} diff --git a/packages/persistence/test/test-database.integration.test.ts b/packages/persistence/test/test-database.integration.test.ts new file mode 100644 index 00000000..06000494 --- /dev/null +++ b/packages/persistence/test/test-database.integration.test.ts @@ -0,0 +1,270 @@ +/** + * The teardown contract for a disposable PostgreSQL database. + * + * This file exists because of a reproduced CI failure, not a hypothesis. `withDatabase` in + * `variant-migrations.integration.test.ts` ended its pool and then immediately ran + * `DROP DATABASE ... WITH (FORCE)`. Measured against pg 8.22.0: `pool.end()` resolves in the same + * synchronous turn that `_remove` filters the last client out of `_clients`, while `client.end()` + * has only queued the Terminate byte — zero of four `remove` events had fired at the moment `end()` + * resolved. A drop issued straight afterwards could still find a backend attached, `FORCE` + * terminated it, and the FATAL arrived on a socket whose pool still had `idleListener` attached. + * `pg` re-emitted it as `pool.emit('error')`, which with no listener is an uncaught exception — + * attributed by `node:test` to whichever test was running, never to the teardown that caused it. + * + * Measured against PostgreSQL 16.14, the two drops differ in exactly the way that matters: with a + * backend still attached, plain `DROP DATABASE` fails with 55006 and leaves that connection + * untouched, where `WITH (FORCE)` succeeds by killing it. The fix is therefore to wait for the + * database to be unused and drop it ordinarily — a loud, harmless failure instead of a quiet, + * harmful success. + * + * Nothing here asserts on elapsed wall-clock time. A test that waits 250ms and checks the clock is + * measuring the machine; these observe the quiescence checks themselves, which is the contract. + */ + +import test from 'node:test'; +import assert from 'node:assert/strict'; +import { Client } from 'pg'; +import type { Pool } from 'pg'; +import { + DatabaseTeardownTimeoutError, + withTestDatabase, + type LingeringBackend, +} from '../src/test-support/database'; + +const DATABASE_URL = process.env['DATABASE_URL']; +const skip = DATABASE_URL ? false : 'DATABASE_URL not set'; + +/** Opens an admin connection to the configured server, never to a disposable database. */ +async function admin(): Promise { + const client = new Client({ connectionString: DATABASE_URL }); + await client.connect(); + return client; +} + +/** Whether the server still has a database of this name. */ +async function databaseExists(name: string): Promise { + const client = await admin(); + try { + const { rowCount } = await client.query('SELECT 1 FROM pg_database WHERE datname = $1', [name]); + return rowCount === 1; + } finally { + await client.end(); + } +} + +test('test database: a successful callback leaves no database behind', { skip }, async () => { + let name = ''; + await withTestDatabase(async ({ pool, database }) => { + name = database; + await pool.query('SELECT 1'); + assert.equal(await databaseExists(database), true, 'the database exists while the callback runs'); + }); + + assert.notEqual(name, ''); + assert.equal(await databaseExists(name), false, 'and is gone once the callback returns'); +}); + +test('test database: a throwing callback still loses its database, and its own error', { skip }, async () => { + let name = ''; + const thrown = new Error('the assertion this test actually cares about'); + + await assert.rejects( + withTestDatabase(async ({ pool, database }) => { + name = database; + await pool.query('SELECT 1'); + throw thrown; + }), + (error: unknown) => { + // The callback's failure is the one worth reading. Teardown must not replace it. + assert.equal(error, thrown, 'the callback error is rethrown unchanged, not a cleanup error'); + return true; + }, + ); + + assert.equal(await databaseExists(name), false, 'cleanup runs on the failure path too'); +}); + +test('test database: teardown waits for a lingering backend instead of terminating it', { skip }, async () => { + // A backend that is deterministically still attached when teardown begins: not a race to win, a + // connection this test holds open on purpose. Teardown must observe it, wait, and only drop once + // it has gone — rather than killing it, which is what FORCE did. + const checks: Array = []; + let lingering: Client | undefined; + let lingeringErrored: unknown; + let name = ''; + + await withTestDatabase( + async ({ pool, connectionString, database }) => { + name = database; + await pool.query('SELECT 1'); + + lingering = new Client({ connectionString, application_name: 'lingering-on-purpose' }); + await lingering.connect(); + // If teardown terminated this connection, `pg` would deliver the FATAL here. Recording it + // rather than letting it go unhandled is what makes the assertion below meaningful — and + // keeps this test from becoming the uncaught-exception source it is testing for. + lingering.on('error', (error) => { + lingeringErrored = error; + }); + }, + { + onQuiescenceCheck: (backends) => { + checks.push(backends); + // Release the connection the first time teardown reports seeing it. This is a latch, not a + // sleep: teardown cannot proceed until the backend is gone, and it only goes because a + // check observed it. + if (backends.length > 0 && lingering !== undefined) { + const closing = lingering; + lingering = undefined; + void closing.end(); + } + }, + }, + ); + + const sawIt = checks.some((backends) => + backends.some((backend) => backend.applicationName === 'lingering-on-purpose'), + ); + assert.equal(sawIt, true, 'teardown observed the lingering backend rather than dropping through it'); + assert.deepEqual(checks.at(-1), [], 'and only stopped waiting once nothing was attached'); + assert.equal( + lingeringErrored, + undefined, + 'the lingering connection was never terminated — no FORCE, so no 57P01 to absorb', + ); + assert.equal(await databaseExists(name), false, 'and the database was dropped'); +}); + +test('test database: a backend that never leaves is bounded, named, and not leaked', { skip }, async () => { + // The failure path: something holds a connection it does not own and never lets go. Teardown must + // give up on a bound rather than hang the suite, say what was holding the database, and still not + // leave the database behind. + let held: Client | undefined; + let name = ''; + + try { + await assert.rejects( + withTestDatabase( + async ({ pool, connectionString, database }) => { + name = database; + await pool.query('SELECT 1'); + held = new Client({ connectionString, application_name: 'never-leaves' }); + await held.connect(); + held.on('error', () => { + // Emergency cleanup drops this database WITH (FORCE) precisely because this connection + // refused to go, so this client is expected to be terminated. Swallowing it here is + // this test tidying up after itself, not the helper hiding a failure. + }); + }, + { teardownTimeoutMs: 400, pollIntervalMs: 25 }, + ), + (error: unknown) => { + assert.ok(error instanceof DatabaseTeardownTimeoutError, 'teardown fails loudly on the bound'); + assert.equal(error.database, name); + assert.ok(error.lingering.length > 0, 'and reports what was still attached'); + assert.ok( + error.lingering.some((backend) => backend.applicationName === 'never-leaves'), + 'naming the culprit by application_name, so the owner is findable', + ); + return true; + }, + ); + } finally { + if (held) await held.end().catch(() => undefined); + } + + assert.equal( + await databaseExists(name), + false, + 'a database is never leaked, even when teardown could not do it the safe way', + ); +}); + +test('test database: when both the callback and teardown fail, the callback error wins', { skip }, async () => { + // The case the naive try/finally gets wrong. A teardown failure thrown from `finally` would + // replace the assertion that actually failed, leaving the author reading a cleanup error instead + // of their own test. Both halves fail here on purpose: a throwing callback that also leaves a + // connection behind, so teardown times out too. + const thrown = new Error('the assertion that must survive teardown'); + let held: Client | undefined; + let name = ''; + + try { + await assert.rejects( + withTestDatabase( + async ({ pool, connectionString, database }) => { + name = database; + await pool.query('SELECT 1'); + held = new Client({ connectionString, application_name: 'held-through-failure' }); + await held.connect(); + held.on('error', () => { + // Expected: emergency cleanup terminates this one. + }); + throw thrown; + }, + { teardownTimeoutMs: 300, pollIntervalMs: 25 }, + ), + (error: unknown) => { + assert.equal(error, thrown, 'the callback error is what surfaces'); + assert.ok( + (error as Error).cause instanceof DatabaseTeardownTimeoutError, + 'and the teardown failure rides along as its cause rather than replacing it', + ); + return true; + }, + ); + } finally { + if (held) await held.end().catch(() => undefined); + } + + assert.equal(await databaseExists(name), false, 'and the database still went away'); +}); + +test('test database: two isolated databases do not see each other', { skip }, async () => { + // Concurrency: the quiescence predicate filters on `datname`, so one test's backends must be + // invisible to the other's teardown. If it filtered on anything looser, these would deadlock + // against each other or drop the wrong database. + const names: string[] = []; + const observed: Array = []; + + const one = withTestDatabase( + async ({ pool, database }) => { + names.push(database); + // Hold real work open across the other test's teardown. + await pool.query('SELECT pg_sleep(0.35)'); + }, + { onQuiescenceCheck: (backends) => observed.push(backends) }, + ); + + const two = withTestDatabase( + async ({ pool, database }) => { + names.push(database); + await pool.query('SELECT 1'); + }, + { onQuiescenceCheck: (backends) => observed.push(backends) }, + ); + + await Promise.all([one, two]); + + assert.equal(names.length, 2); + assert.notEqual(names[0], names[1], 'each run gets its own database'); + for (const name of names) assert.equal(await databaseExists(name), false, `${name} was dropped`); + assert.ok( + observed.every((backends) => backends.length === 0), + 'neither teardown ever saw the other database’s backends', + ); +}); + +test('test database: a real query failure is not swallowed by teardown', { skip }, async () => { + // The helper absorbs exactly one thing — 55006 while retrying its own drop. A genuine SQL error + // from the callback has to arrive unchanged, or these tests stop being able to fail. + await assert.rejects( + withTestDatabase(async ({ pool }: { pool: Pool }) => { + await pool.query('SELECT * FROM a_table_that_does_not_exist'); + }), + (error: unknown) => { + assert.equal((error as { code?: string }).code, '42P01', 'undefined_table reaches the caller'); + return true; + }, + ); +}); diff --git a/packages/persistence/test/variant-migrations.integration.test.ts b/packages/persistence/test/variant-migrations.integration.test.ts index daae0865..2881a75e 100644 --- a/packages/persistence/test/variant-migrations.integration.test.ts +++ b/packages/persistence/test/variant-migrations.integration.test.ts @@ -5,8 +5,8 @@ import { copyFileSync, mkdtempSync, rmSync } from 'node:fs'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; import type { Pool } from 'pg'; -import { createPool } from '../src/pg/pool'; import { migrate, migrationFiles, migrationsDir } from '../src/pg/migrate'; +import { withTestDatabase } from '../src/test-support/database'; const DATABASE_URL = process.env['DATABASE_URL']; const skip = DATABASE_URL ? false : 'DATABASE_URL not set'; @@ -40,13 +40,6 @@ function isConstraintViolation(error: unknown, code: string, constraint: string) return pgError.code === code && pgError.constraint === constraint; } -/** Replaces the database path in the configured PostgreSQL connection URL. */ -function databaseUrlFor(database: string): string { - const url = new URL(DATABASE_URL!); - url.pathname = `/${database}`; - return url.toString(); -} - /** Copies migrations through the requested version into a disposable directory. */ function migrationsThrough(version: number): { readonly dir: string; cleanup(): void } { const dir = mkdtempSync(join(tmpdir(), `variant-migrations-${version}-`)); @@ -57,29 +50,16 @@ function migrationsThrough(version: number): { readonly dir: string; cleanup(): return { dir, cleanup: () => rmSync(dir, { recursive: true, force: true }) }; } -/** Runs a callback in an isolated database and always releases its pools and database. */ +/** + * Runs a callback in an isolated database and always releases its pools and database. + * + * The teardown protocol itself lives in {@link withTestDatabase}. This file used to end its pool and + * then immediately `DROP DATABASE ... WITH (FORCE)`, which terminated backends the pool had not yet + * finished closing and delivered the resulting FATAL to a live socket — surfacing as an uncaught + * error that `node:test` attributed to whichever test happened to run next. + */ async function withDatabase(run: (pool: Pool) => Promise): Promise { - const admin = createPool({ connectionString: DATABASE_URL, max: 2 }); - const database = `variant_migration_${randomUUID().replaceAll('-', '')}`; - let databaseCreated = false; - try { - await admin.query(`CREATE DATABASE "${database}"`); - databaseCreated = true; - const pool = createPool({ connectionString: databaseUrlFor(database), max: 4 }); - try { - await run(pool); - } finally { - await pool.end(); - } - } finally { - try { - if (databaseCreated) { - await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); - } - } finally { - await admin.end(); - } - } + await withTestDatabase(async ({ pool }) => run(pool), { connectionString: DATABASE_URL, max: 4 }); } /** Reads one named constraint from PostgreSQL's catalog. */ From 873f37dc534d14a17719d0e14c27cf4b85c4fc69 Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Thu, 3 Sep 2026 22:48:23 +0300 Subject: [PATCH 02/11] fix(persistence-test): own the termination the emergency drop causes MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Seven review findings, all real. Two were database leaks and one would have reintroduced the exact uncaught error this branch removes. The emergency `WITH (FORCE)` drop — the one place FORCE survives, taken only after teardown has already failed — can terminate a client the callback checked out and never released. That lease is what makes `pool.end()` time out in the first place, so the two always arrive together. A leased client is not idle, so `pg` has removed `idleListener` from it and the pool never sees its error: the FATAL had no listener anywhere and Node raised it as an uncaught exception, attributed to an unrelated test. Exactly the failure this branch exists to remove, reintroduced by its own cleanup. The regression test for it leaks a pool client and attaches nothing of its own, and it failed before this fix. Clients are now tracked through pg's public `connect`/`remove` events, and the emergency path attaches a listener to the pool and to every live client before dropping. That listener re-throws anything it did not cause, so it is not the absorber this branch deleted from the API test: that one sat on every run and hid a race in the normal path. Two leaks. `dropWhenFree` threw its timeout without dropping, and the caller then treated `DatabaseTeardownTimeoutError` as proof the database was gone — so the last-resort drop was skipped and the database stayed on the server. The create-path catch also set `dropped = true` on the assumption that only `CREATE DATABASE` could fail there, when the URL rewrite and pool construction after it can fail with the database already created. `undefined` was both the no-error sentinel and a legal rejection value, so `throw undefined` from a callback resolved as success with an uninitialised result. Separate booleans record failure now. The budget bounded only `pool.end()`; every later admin query was awaited unbounded, so a stalled connection could sit past it with nothing to interrupt it. Each teardown step is bounded now. The bound is deliberately not a `statement_timeout` on the admin pool, which would also have applied to the `CREATE DATABASE` that runs before teardown — with `teardownTimeoutMs: 300` in two tests, that would have starved creation on a slower machine. The concurrency test asserted that no quiescence check ever saw a backend, which is flaky for the very reason this helper exists and proved nothing about isolation anyway, since the query already filters by database. It now proves the short run finishes while the long one still holds its own database open. Also fixed a coverage gap the mutations exposed rather than a reviewer: removing `endPoolWithin` was only caught by tests running fifty times slower, because pg's 10s `idleTimeoutMillis` drains the pool on its own. A successful run now asserts the pool was already ended, using pg's documented "Called end on pool more than once". 10 of 13 mutations killed. The three survivors are named in the PR rather than padded out: each is a defensive branch that needs a contrived fixture to reach. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- docs/PROJECT_STATE.md | 7 +- .../persistence/src/test-support/database.ts | 171 ++++++++++++++++-- .../test/test-database.integration.test.ts | 151 ++++++++++++++-- 3 files changed, 293 insertions(+), 36 deletions(-) diff --git a/docs/PROJECT_STATE.md b/docs/PROJECT_STATE.md index 0c2f571b..5a907186 100644 --- a/docs/PROJECT_STATE.md +++ b/docs/PROJECT_STATE.md @@ -43,8 +43,11 @@ again as loud as it should be. `createPool` and `migrate` are unchanged; no prod Teardown is bounded — `pool.end()` included, because a client checked out and never released leaves it pending indefinitely (measured past a three-second bound) — names the lingering backends when it gives up, never leaks a database on any path, and never lets a cleanup failure replace the assertion -the test actually failed on. Seven regression tests pin the contract against a real server; none -asserts on elapsed wall-clock time, which would measure the machine rather than the guarantee. +the test actually failed on. Ten regression tests pin the contract against a real server; none asserts on +elapsed wall-clock time, which would measure the machine rather than the guarantee. The emergency +path owns the termination it causes: it attaches a listener to the pool *and* to every live client +before force-dropping, because a client the callback checked out and never released is not idle, so +`pg` has removed its `idleListener` and the pool would never see its FATAL at all. **Found while validating, not fixed here:** the persistence suite is not idempotent against a reused database. A second consecutive run against the same server fails — 12 tests on `b95065f`, 9 with diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts index 76b786a6..46613ede 100644 --- a/packages/persistence/src/test-support/database.ts +++ b/packages/persistence/src/test-support/database.ts @@ -6,7 +6,7 @@ * a separate subpath so the driver-facing surface does not grow a test harness. */ -import type { Pool } from 'pg'; +import type { Pool, PoolClient } from 'pg'; import { createPool } from '../pg/pool'; /** A backend still attached to the disposable database when teardown wanted to drop it. */ @@ -33,7 +33,15 @@ export interface TestDatabaseOptions { * runs its statements on another, so a single-connection pool deadlocks against itself. */ readonly max?: number; - /** Total budget for teardown, measured from the moment the callback returns. */ + /** + * Budget for teardown, measured from the moment the callback returns. + * + * It bounds each teardown step rather than their sum: the wait for quiescence, the drop, and the + * last-resort drop are separately capped, so a server that stops answering costs a small multiple + * of this rather than the unbounded wait a between-await deadline check would allow. It is not + * applied as a `statement_timeout` on the admin pool, because that pool also runs the + * `CREATE DATABASE` this budget has nothing to do with. + */ readonly teardownTimeoutMs?: number; /** Gap between quiescence checks. */ readonly pollIntervalMs?: number; @@ -72,6 +80,9 @@ export class DatabaseTeardownTimeoutError extends Error { /** SQLSTATE 55006 — `DROP DATABASE` refusing because a backend is still attached. */ const OBJECT_IN_USE = '55006'; +/** SQLSTATE 57P01 — `admin_shutdown`: the backend was terminated by `pg_terminate_backend`. */ +const ADMIN_SHUTDOWN = '57P01'; + /** Reads the SQLSTATE off an unknown thrown value, or null when it carries none. */ function sqlState(error: unknown): string | null { if (typeof error !== 'object' || error === null) return null; @@ -79,6 +90,19 @@ function sqlState(error: unknown): string | null { return typeof code === 'string' ? code : null; } +/** + * Whether an error is a connection dying because something terminated its backend. + * + * Two shapes, because the client sees whichever arrives first: the `FATAL` message, which carries + * SQLSTATE 57P01, or the socket simply closing underneath it, which `pg` reports with no code at + * all. Both were observed against PostgreSQL 16.14 while measuring a forced drop. + */ +function isForcedTermination(error: unknown): boolean { + if (sqlState(error) === ADMIN_SHUTDOWN) return true; + const message = error instanceof Error ? error.message : ''; + return message.includes('Connection terminated'); +} + /** Replaces the database in a connection URL, leaving credentials and host alone. */ function urlForDatabase(connectionString: string, database: string): string { const url = new URL(connectionString); @@ -91,6 +115,34 @@ function delay(ms: number): Promise { return new Promise((resolve) => setTimeout(resolve, ms)); } +/** + * Run `work`, but stop waiting for it after `timeoutMs`. + * + * Checking `Date.now()` between awaits does not bound the awaits themselves: an established + * connection that stops answering would sit past the deadline with nothing to interrupt it, which + * would make the budget advisory rather than real. Every teardown step therefore goes through here. + * + * A step that times out is abandoned rather than cancelled — PostgreSQL is still holding whatever it + * was given — so the caller goes on to end the admin pool, which is what actually drops the sockets + * those queries are waiting on. + */ +async function withDeadline(work: Promise, timeoutMs: number, what: string): Promise { + let timer: NodeJS.Timeout | undefined; + try { + return await Promise.race([ + work, + new Promise((_resolve, reject) => { + timer = setTimeout( + () => reject(new Error(`withTestDatabase: ${what} exceeded its ${timeoutMs}ms budget`)), + timeoutMs, + ); + }), + ]); + } finally { + if (timer !== undefined) clearTimeout(timer); + } +} + /** * Resolve once no backend is attached to `database`, or return what is still there at the deadline. * @@ -153,6 +205,51 @@ async function endPoolWithin(pool: Pool, timeoutMs: number): Promise { } } +/** + * Every connection the pool has open, tracked through public events only. + * + * The emergency drop below can terminate a client that is *checked out* — a lease the callback never + * returned, which is the very thing that made `pool.end()` time out. A leased client is not idle, so + * `pg` has removed `idleListener` from it and the pool never sees its errors: attaching to the pool + * alone leaves that FATAL with no listener at all, and Node raises it as an uncaught exception. So + * the clients have to be reachable individually, and `connect`/`remove` are the documented events + * that bracket their lifetime. + */ +function trackClients(pool: Pool): ReadonlySet { + const live = new Set(); + pool.on('connect', (client: PoolClient) => { live.add(client); }); + pool.on('remove', (client: PoolClient) => { live.delete(client); }); + return live; +} + +/** + * Take the database away from connections that would not let go, and own the consequence. + * + * This is the only place `WITH (FORCE)` survives, and it is reached only once teardown has already + * failed — the caller is about to throw either way. It is still a deliberate termination, so the + * connections it is about to kill get a listener *first*, on the pool and on every live client. + * + * That listener is not the absorber this change deleted from the API test. That one sat on every + * run and hid a race in the normal path. This one is installed only where this code itself issues + * the termination, one statement later, on connections already being abandoned — and it re-throws + * anything it did not cause, so a genuine connection failure stays exactly as loud as it was. + */ +async function forceDropAbandoned( + admin: Pool, + pool: Pool, + clients: ReadonlySet, + database: string, +): Promise { + const absorbOwnTermination = (error: Error): void => { + if (isForcedTermination(error)) return; + throw error; + }; + pool.on('error', absorbOwnTermination); + for (const client of clients) client.on('error', absorbOwnTermination); + + await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); +} + /** * Drop the database, tolerating one specific lost race and nothing else. * @@ -163,8 +260,11 @@ async function endPoolWithin(pool: Pool, timeoutMs: number): Promise { */ async function dropWhenFree( admin: Pool, + pool: Pool, + clients: ReadonlySet, database: string, deadline: number, + teardownTimeoutMs: number, pollIntervalMs: number, onCheck: ((backends: readonly LingeringBackend[]) => void) | undefined, ): Promise { @@ -176,7 +276,10 @@ async function dropWhenFree( if (sqlState(error) !== OBJECT_IN_USE || Date.now() >= deadline) throw error; const lingering = await waitForQuiescence(admin, database, deadline, pollIntervalMs, onCheck); if (lingering.length > 0 && Date.now() >= deadline) { - throw new DatabaseTeardownTimeoutError(database, 0, lingering); + // Giving up here still has to leave the server clean: reporting the timeout without dropping + // would leak the database, which is the one outcome teardown must never produce. + await forceDropAbandoned(admin, pool, clients, database); + throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); } } } @@ -195,6 +298,7 @@ async function dropWhenFree( async function tearDown( admin: Pool, pool: Pool, + clients: ReadonlySet, database: string, teardownTimeoutMs: number, pollIntervalMs: number, @@ -207,10 +311,10 @@ async function tearDown( if (lingering.length > 0) { // Something outlived its owner. Drop the database anyway so the server is not littered with // abandoned test databases, then say precisely what was holding it. - await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); + await forceDropAbandoned(admin, pool, clients, database); throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); } - await dropWhenFree(admin, database, deadline, pollIntervalMs, onCheck); + await dropWhenFree(admin, pool, clients, database, deadline, teardownTimeoutMs, pollIntervalMs, onCheck); } /** @@ -255,8 +359,20 @@ export async function withTestDatabase( const suffix = `${Date.now().toString(36)}_${Math.floor(Math.random() * 0xffffffff).toString(16)}`; const database = `test_db_${suffix}`; - const admin = createPool({ connectionString, max: 2 }); + // Every teardown step runs on this pool, so the budget is applied here rather than only around + // `pool.end()`. Checking `Date.now()` after an awaited query does not bound that query: a stalled + // but established connection would sit past the deadline with nothing to interrupt it. These + // options make the server itself give up, so the documented budget is the real one. + // A backstop, deliberately looser than the budget it guards. The teardown paths run right up to + // `teardownTimeoutMs` on purpose and then still have cleanup to do — force-dropping the database + // and building the diagnostic — so a backstop set to the same value would preempt the very error + // teardown was trying to report. This exists only for a server that has stopped answering, where + // nothing else would ever return. + const teardownBackstopMs = teardownTimeoutMs * 2 + 1_000; + const admin = createPool({ connectionString, max: 2, connectionTimeoutMillis: teardownTimeoutMs }); let dropped = false; + let bodyFailed = false; + let teardownFailed = false; let bodyError: unknown; let teardownError: unknown; let result!: T; @@ -265,45 +381,64 @@ export async function withTestDatabase( await admin.query(`CREATE DATABASE "${database}"`); const databaseUrl = urlForDatabase(connectionString, database); const pool = createPool({ connectionString: databaseUrl, max: options.max ?? 4 }); + const clients = trackClients(pool); try { result = await body({ pool, database, connectionString: databaseUrl }); } catch (error) { + // A promise may reject with anything, `undefined` included, so the flag is what records that + // the callback failed. Using the captured value as its own sentinel would turn + // `Promise.reject(undefined)` into a success and return an uninitialised result. + bodyFailed = true; bodyError = error; } finally { try { - await tearDown(admin, pool, database, teardownTimeoutMs, pollIntervalMs, options.onQuiescenceCheck); + await withDeadline( + tearDown(admin, pool, clients, database, teardownTimeoutMs, pollIntervalMs, options.onQuiescenceCheck), + teardownBackstopMs, + 'teardown', + ); dropped = true; } catch (error) { + teardownFailed = true; teardownError = error; - // `tearDown` drops the database on the path where it reports lingering backends, so this - // only leaves work for the net below when the drop itself was what failed. + // Both teardown paths that throw a timeout have already force-dropped the database, so only + // those are known-clean. Any other failure leaves the drop to the net below. dropped = error instanceof DatabaseTeardownTimeoutError; } } } catch (error) { - // Reached only when CREATE DATABASE itself failed, so there is no database to drop and the - // callback never ran. - teardownError ??= error; - dropped = true; + // `CREATE DATABASE` failed, or the URL rewrite or pool construction after it did. The last of + // those can happen with the database already created, so the drop below has to stay reachable — + // it is `IF EXISTS`, which makes it harmless when there is nothing there. + if (!teardownFailed) { + teardownFailed = true; + teardownError = error; + } } finally { try { - if (!dropped) await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); + if (!dropped) { + await withDeadline( + admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`), + teardownBackstopMs, + 'last-resort drop', + ); + } } catch { // A last-resort drop that fails leaves the error already in flight, which describes the real // problem better than this one would. } finally { - await admin.end(); + await endPoolWithin(admin, teardownTimeoutMs); } } - if (bodyError !== undefined) { + if (bodyFailed) { // The test's own failure is the one worth reading. A teardown failure rides along as its cause // rather than replacing it: losing the assertion that actually failed would be the worse trade. - if (teardownError !== undefined && bodyError instanceof Error && bodyError.cause === undefined) { + if (teardownFailed && bodyError instanceof Error && bodyError.cause === undefined) { bodyError.cause = teardownError; } throw bodyError; } - if (teardownError !== undefined) throw teardownError; + if (teardownFailed) throw teardownError; return result; } diff --git a/packages/persistence/test/test-database.integration.test.ts b/packages/persistence/test/test-database.integration.test.ts index 06000494..031cb40f 100644 --- a/packages/persistence/test/test-database.integration.test.ts +++ b/packages/persistence/test/test-database.integration.test.ts @@ -52,16 +52,43 @@ async function databaseExists(name: string): Promise { } } +/** How many disposable databases the helper currently has on the server. */ +async function countTestDatabases(): Promise { + const client = await admin(); + try { + const { rows } = await client.query<{ n: string }>( + "SELECT count(*)::text AS n FROM pg_database WHERE datname LIKE 'test\\_db\\_%'", + ); + return Number(rows[0]?.n ?? '0'); + } finally { + await client.end(); + } +} + test('test database: a successful callback leaves no database behind', { skip }, async () => { let name = ''; + let poolRef: Pool | undefined; await withTestDatabase(async ({ pool, database }) => { name = database; + poolRef = pool; await pool.query('SELECT 1'); assert.equal(await databaseExists(database), true, 'the database exists while the callback runs'); }); assert.notEqual(name, ''); assert.equal(await databaseExists(name), false, 'and is gone once the callback returns'); + + // Teardown must end the pool *before* it decides the database is unused, not merely reach the + // same state eventually. Without this, a teardown that never ended the pool still passes: `pg` + // closes idle clients after `idleTimeoutMillis` (10s by default), so the quiescence wait drains + // on its own and the only visible symptom is every test taking fifty times longer. `pool.end()` + // rejecting on a second call is pg's own documented contract, which makes this a fact about the + // pool rather than a measurement of the clock. + await assert.rejects( + poolRef!.end(), + /more than once/, + 'teardown had already ended the pool it was handed', + ); }); test('test database: a throwing callback still loses its database, and its own error', { skip }, async () => { @@ -220,39 +247,131 @@ test('test database: when both the callback and teardown fail, the callback erro assert.equal(await databaseExists(name), false, 'and the database still went away'); }); -test('test database: two isolated databases do not see each other', { skip }, async () => { - // Concurrency: the quiescence predicate filters on `datname`, so one test's backends must be - // invisible to the other's teardown. If it filtered on anything looser, these would deadlock - // against each other or drop the wrong database. +test('test database: a concurrent run is not blocked by another database’s backends', { skip }, async () => { + // The quiescence predicate filters on `datname`, so one run's busy backends must be invisible to + // the other's teardown. Asserting that no check ever saw *anything* would be flaky for the very + // reason this helper exists — a run's own pool can still be closing when its first check runs — + // and would prove nothing about isolation anyway, since the query already filters by database and + // a `LingeringBackend` does not carry the one it came from. + // + // What does prove it: the short run finishes while the long one is still holding a backend open. + // If teardown waited on anything outside its own database, that could not happen. const names: string[] = []; - const observed: Array = []; + const checksLong: Array = []; + const checksShort: Array = []; + let longFinished = false; - const one = withTestDatabase( + const long = withTestDatabase( async ({ pool, database }) => { names.push(database); - // Hold real work open across the other test's teardown. - await pool.query('SELECT pg_sleep(0.35)'); + await pool.query('SELECT pg_sleep(1.5)'); }, - { onQuiescenceCheck: (backends) => observed.push(backends) }, - ); + { onQuiescenceCheck: (backends) => checksLong.push(backends) }, + ).then(() => { + longFinished = true; + }); - const two = withTestDatabase( + const short = withTestDatabase( async ({ pool, database }) => { names.push(database); await pool.query('SELECT 1'); }, - { onQuiescenceCheck: (backends) => observed.push(backends) }, + { onQuiescenceCheck: (backends) => checksShort.push(backends) }, ); - await Promise.all([one, two]); + await short; + assert.equal(longFinished, false, 'the short run completed while the long one still held its database'); + + await long; assert.equal(names.length, 2); assert.notEqual(names[0], names[1], 'each run gets its own database'); for (const name of names) assert.equal(await databaseExists(name), false, `${name} was dropped`); - assert.ok( - observed.every((backends) => backends.length === 0), - 'neither teardown ever saw the other database’s backends', + assert.deepEqual(checksShort.at(-1), [], 'the short run reached quiescence before dropping'); + assert.deepEqual(checksLong.at(-1), [], 'and so did the long one'); +}); + +test('test database: giving up on teardown still leaves no database behind', { skip }, async () => { + // The bounded path force-drops before it reports, and the outer net must not wrongly assume it + // did. A leaked database is invisible to every other assertion here and is the one outcome + // teardown must never produce, so it gets counted directly. + const before = await countTestDatabases(); + let held: Client | undefined; + + try { + await assert.rejects( + withTestDatabase( + async ({ pool, connectionString }) => { + await pool.query('SELECT 1'); + held = new Client({ connectionString, application_name: 'leak-check' }); + await held.connect(); + held.on('error', () => { + // Expected: this is the connection teardown gives up on and then terminates. + }); + }, + { teardownTimeoutMs: 300, pollIntervalMs: 25 }, + ), + (error: unknown) => error instanceof DatabaseTeardownTimeoutError, + ); + } finally { + if (held) await held.end().catch(() => undefined); + } + + assert.equal(await countTestDatabases(), before, 'the disposable database did not survive teardown'); +}); + +test('test database: a leaked pool client does not become an uncaught error', { skip }, async () => { + // The emergency path is the one place FORCE survives, and the connection it terminates can belong + // to the callback's own pool — a client checked out and never released, which is exactly what + // makes `pool.end()` time out and send teardown down that path. That pool has no `error` listener + // during the run, so without one installed before the forced drop, `pg` re-emits the FATAL as an + // uncaught exception: the failure this whole helper exists to remove, reintroduced by its own + // cleanup. Unlike the other leak tests, nothing here attaches a listener of its own — the helper + // has to own the termination it causes. + const before = await countTestDatabases(); + + await assert.rejects( + withTestDatabase( + async ({ pool }) => { + const leased = await pool.connect(); + await leased.query('SELECT 1'); + // Deliberately never released. + }, + { teardownTimeoutMs: 400, pollIntervalMs: 25 }, + ), + (error: unknown) => { + assert.ok(error instanceof DatabaseTeardownTimeoutError, 'the bound is what reports, not a crash'); + return true; + }, + ); + + // If the FATAL had escaped, node:test would have failed this run with an uncaught exception rather + // than reaching here. + assert.equal(await countTestDatabases(), before, 'and the database still went away'); +}); + +test('test database: a callback that rejects with undefined is still a failure', { skip }, async () => { + // `undefined` is a legal rejection value, so it must not double as the helper's own no-error + // sentinel — that would turn this call into a success returning an uninitialised result. + let name = ''; + let resolved = false; + + await assert.rejects( + withTestDatabase(async ({ pool, database }) => { + name = database; + await pool.query('SELECT 1'); + throw undefined; + }).then(() => { + resolved = true; + }), + (error: unknown) => { + assert.equal(error, undefined, 'the rejection value is preserved exactly as thrown'); + return true; + }, ); + + assert.equal(resolved, false, 'a rejection with undefined never becomes a successful return'); + assert.equal(await databaseExists(name), false, 'and its database is still cleaned up'); }); test('test database: a real query failure is not swallowed by teardown', { skip }, async () => { From ffcdbea1b69b722c650849ef777bfe76ed82d6a0 Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Thu, 3 Sep 2026 22:50:57 +0300 Subject: [PATCH 03/11] docs(persistence-test): stop promising a leak-proof teardown MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The last-resort `DROP DATABASE ... WITH (FORCE)` runs inside a `catch`, so that a failed cleanup cannot bury the error already being reported. That is the right trade, but it means a server which refuses that drop can still leave a database behind — and PROJECT_STATE, ROADMAP and the helper's own docstring all claimed teardown "never leaks a database on any path". They now say what is true: the database is dropped on every path teardown can reach, including the one where it gives up, and the final fallback is best effort. Raised by CodeRabbit against the handover doc, and it is the same class of overstatement this branch has been correcting elsewhere. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- docs/PROJECT_STATE.md | 7 +++++-- docs/ROADMAP.md | 2 +- packages/persistence/src/test-support/database.ts | 9 ++++++--- 3 files changed, 12 insertions(+), 6 deletions(-) diff --git a/docs/PROJECT_STATE.md b/docs/PROJECT_STATE.md index 5a907186..993d5031 100644 --- a/docs/PROJECT_STATE.md +++ b/docs/PROJECT_STATE.md @@ -42,8 +42,11 @@ again as loud as it should be. `createPool` and `migrate` are unchanged; no prod Teardown is bounded — `pool.end()` included, because a client checked out and never released leaves it pending indefinitely (measured past a three-second bound) — names the lingering backends when it -gives up, never leaks a database on any path, and never lets a cleanup failure replace the assertion -the test actually failed on. Ten regression tests pin the contract against a real server; none asserts on +gives up, and never lets a cleanup failure replace the assertion +the test actually failed on. It drops the disposable database on every path it can reach, including the +one where it gives up — but that last-resort drop is best effort: it runs inside a `catch` so a +cleanup failure cannot bury the error already being reported, which means a server that refuses the +drop can still leave a database behind. Ten regression tests pin the contract against a real server; none asserts on elapsed wall-clock time, which would measure the machine rather than the guarantee. The emergency path owns the termination it causes: it attaches a listener to the pool *and* to every live client before force-dropping, because a client the callback checked out and never released is not idle, so diff --git a/docs/ROADMAP.md b/docs/ROADMAP.md index 1682f8ee..b0ff9707 100644 --- a/docs/ROADMAP.md +++ b/docs/ROADMAP.md @@ -1350,7 +1350,7 @@ Debt observed during M14. Each states what is known, not what is planned; items - **The search surface was not gated on `capabilities.search`, so an absolute kill switch still showed a search box (RESOLVED in M15 Increment 24 / ADR-0132 §5).** `SEARCH_ENABLED=0` — the chart's `search.enabled: false`, an absolute kill switch per ADR-0055 — leaves `searchRepository` unconstructed and `GET /v1/search` answering 503 on every mode, keyword included. The entry point was the persistent header form in `packages/web/index.html`, present on every page; being a `` rather than an `a[data-route]`, `NAV_CAPABILITY_MAP` could not reach it, which is why the first pass at Increment 24 gated the semantic and hybrid *modes* and left keyword ungated — the same defect class one mode over. Raised by the Qodo review of PR #155. **Fixed in the same increment rather than deferred:** the form now ships `hidden` and is revealed by `applySearchCapability` only on an explicit `search: true`; the route renders an honest unavailable notice and issues no request; and keyword search waits for the capability answer, reversing this increment's own earlier latency decision, because knowing whether a request is pointless requires having asked. A markup-contract test pins the `hidden` attribute, since the gate depends on it and every other test passes without it. - **Clicking a search mode discarded text typed since the page loaded (RESOLVED in a follow-up to M15 Increment 24 / ADR-0132).** `createModeInput` in `packages/web/src/app/search-mount.ts` closed over the query captured when the route mounted, so `navigateToSearchMode` navigated with the old term and the remount reset the input to match it. Type a new term into the header field, click **Semantic** without pressing enter, and the typed text was gone with no indication it had been discarded. Pre-existing — the closure predated Increment 24 and was untouched by it — and found by the adversarial review of PR #155 while reviewing the capability gate wrapped around the same control. **Resolved:** the query is now a `() => string` read when a mode is chosen rather than a string captured when the selector renders, matching what `main.ts`'s submit handler already does, and falling back to the mounted query only where the document has no header input. Two regression tests, one of which fails against the exact pre-fix closure. - **`startHarness` drew ports `fetch` refuses (RESOLVED in ADR-0140); the unexplained whole-file failure is still open.** Two signatures were filed here, deliberately not as one cause, and that judgement held. **Signature A is resolved.** WHATWG Fetch blocks eighty-two ports and undici enforces the list on the port number alone, before opening a socket — so `server.listen(0)` could bind, listen and answer raw TCP while `fetch` still refused, surfacing as `TypeError: fetch failed` / `Error: bad port` at the harness’s first request rather than at the listen that caused it. Whether it can happen at all is a property of the host’s dynamic port range: a typical Linux CI range (32768–60999) contains no blocked port, while the Windows range in use here (1024–15000) contains nineteen, which is the whole of "green on CI, flaky locally". The guard that already existed was incomplete in a way that still failed — its hand-observed set of eighteen ports was the spec list intersected with one machine’s range **minus `6679`** — and it retried unboundedly, had no behaviour on exhaustion, and had been copy-pasted into `auth-signin-schema.integration.test.ts`, so the missing port had to be found twice. `packages/api/test/listen.ts` now owns port acquisition for both sites: the spec-complete eighty-two ports (verified by sweeping all 65535 through the real `fetch` on Node v24.15.0), a bounded twenty attempts, each rejected listener closed before the next is asked for, a guarded `address()` read in place of the `as AddressInfo` cast, and an exhaustion error naming the attempts and rejected ports and nothing else. **Signature B is not resolved and was not folded in.** A file still fails with `'test failed'`, no assertion, no stack and none of its own tests reported. Twenty consecutive full runs gave five failures: on pre-fix code one signature A (`auth.test.js`) and three signature B; on post-fix code one signature B and no signature A. The port fix removes A and leaves B exactly where it was, which is the evidence that they are two defects. Four different files were hit (`move-explanation-route`, `tournament-commentary-route`, `bot-detection-analyze`, `anti-cheat-analysis`), sharing no import beyond `./helpers`; each died in 589–703 ms with no test of its own reporting and no stderr. Refuted with evidence: ephemeral-port exhaustion (113 sockets in TIME_WAIT against a 13977-port range), a `Promise.race` loser becoming an unhandled rejection (`race` subscribes to every promise, confirmed on v24.15.0), a throwing `after`/`afterEach` hook (the affected files use none), and a double `close()` rejecting (awaited in a `finally`, it would be attributed to that test with a stack). A second bounded pass — twelve more full runs under the TAP reporter with a preload recording `uncaughtException`, `unhandledRejection` and any non-zero exit — produced twelve clean runs and captured nothing at the time. **A follow-up increment (`claude/node-test-signature-b`) then captured the defect directly, three more times, on three files never previously implicated** (`rate-limit-atomicity`, `dependency-parity`, `studies-api`) — seven distinct files observed with this symptom to date. Occurrences across seven distinct files make a shared or cross-cutting path more plausible and make a defect confined to one test file less likely, but do not exclude file-specific inputs or lifecycle interactions. An instrumented preload (`packages/api/test/diagnostics/signature-b-preload.cjs`) hooking process-level events — `process.exit`, `process.abort`, `process.kill`, `uncaughtExceptionMonitor` (passively observing uncaught exceptions and fatal unhandled rejections), `warning`, `beforeExit`, and Node’s own unconditional `exit` — showed **none of the hooks active at the time fired** on any of the three historical captures (though `process.abort()` was not wrapped in those initial runs and is now covered for future occurrences). A synthetic `process.exit(1)`-before-registration fixture reproduces the identical silent shape; every other synthetic mechanism tried (a post-test async throw, an emitter `'error'` with its listener removed, a synchronous module-load throw, a delayed `SIGKILL`) prints a visibly different diagnostic line, stack, or partial test output that the real defect never shows. This narrows the investigated possibilities while leaving the root cause unresolved: the per-file child process (`node --test` spawns one per file, confirmed by distinct PIDs) was not terminated by `process.exit`, uncaught exceptions, or fatal unhandled rejections, and future runs with `process.abort` instrumentation will record whether abort was called through JS; an absent record narrows in-runtime JS termination but cannot alone prove external termination without corroborating child exit status/signal data or OS-level crash evidence (e.g. distinguishing an external kill or uncatchable signal from a native C++/V8 crash). The machine had roughly 2.5 GB of 15.7 GB RAM free at capture time with several other agents’ processes concurrently running, which is circumstantially consistent with resource contention, but no crash was recorded in the Windows Application or System event logs in that window, so the exact external trigger is still not established. No fix was invented — the forbidden responses (sleeps, whole-file retries, lowering concurrency) would only hide the unresolved root cause, whose origin is not yet established. **A further increment then crossed the parent/child boundary the earlier work stopped at, and found the evidence had been there all along:** Node's runner attaches the child's `exitCode` and `signal` to the `ERR_TEST_FAILURE` it throws, and the `spec` reporter discards them — `formatError` replaces the error with `error.cause`, the bare string `'test failed'` — while the built-in `tap` reporter serializes them, so running `spec` to stdout and `tap` to a file recovers the exit status with no custom reporter and no patched internals. Exit codes were measured on this platform rather than assumed: `process.abort()` gives `134`, `Stop-Process -Force` gives `4294967295`, NTSTATUS faults surface as raw unsigned values such as `3221225477` (`0xC0000005`) — and `1` is produced alike by an uncaught exception, `process.exit(1)`, `taskkill /F` and `process.kill`, so it identifies nothing on its own and is classified `inconclusive`. `signature-b-correlate.cjs` joins the parent's TAP record to the child's JSONL log on the test file path (which also yields the child PID) and states what the pair does and does not establish; where the exit code is ambiguous, a child that reached `preload-installed` and then logged nothing still excludes `process.exit` and an uncaught exception, because both would have left a record and fired Node's `exit` event. A bounded pass of 20 runs under this instrumentation produced 0 captures — which bounds the rate and proves nothing: treating the historical ~1-in-5 as an independent per-run rate, zero captures in 20 runs has probability `(4/5)^20 ≈ 1.2%`, and independence is an assumption rather than an established fact; it ran at 3084–3834 MB free against roughly 2.5 GB at the historical captures, consistent with the resource-contention hypothesis but not evidence for it. **Signature B stays UNRESOLVED**; what changed is that the next occurrence is readable rather than silent. See ADR-0140 §4. -- **Isolated-database test teardown dropped databases out from under connections that had not finished closing (RESOLVED in M15 Increment 45).** `withDatabase` in `packages/persistence/test/variant-migrations.integration.test.ts` ended its pool and then immediately ran `DROP DATABASE ... WITH (FORCE)`. `pool.end()` does not wait for its clients to close: in pg 8.22.0 `_pulseQueue` reaches the end callback in the same synchronous turn in which `_remove` filters the last client out of `_clients`, while `client.end()` has only queued the Terminate byte — instrumentation recorded **zero of four `remove` events fired at the moment `end()` resolved**. The drop could therefore still find a backend attached; `FORCE` terminated it, and the resulting `FATAL` arrived on a socket whose pool still had `idleListener` attached, which `pg` re-emitted as `pool.emit('error')` — an unhandled EventEmitter error that `node:test` attributed to whichever test was running rather than to the teardown that caused it. It surfaced as intermittent `terminating connection due to administrator command` failures in `postgres integration (persistence)` during M15 Increment 44, on a different test each run, which is the signature of a race rather than a broken assertion. The same shape existed in `packages/api/test/auth-signin-schema.integration.test.ts`, which had absorbed SQLSTATE 57P01 with a `pool.on('error', ...)` listener — a symptom fix for the same cause. **Resolved in Increment 45:** a shared `withTestDatabase` helper (`@chess-platform/persistence/test-support`) ends the pool under a bound, waits for `pg_stat_activity` to report the database unused, and drops it *without* `FORCE`. Measured on PostgreSQL 16.14, a plain drop against a still-attached backend fails with SQLSTATE 55006 and leaves that connection untouched, where `FORCE` succeeds by killing it — so the change trades a quiet, harmful success for a loud, harmless failure. FORCE remains only on the emergency path that guarantees no database is leaked once teardown has already failed. The 57P01 absorber is deleted, because the corrected lifecycle never causes one. `createPool` and `migrate` are unchanged, and no migration was added. +- **Isolated-database test teardown dropped databases out from under connections that had not finished closing (RESOLVED in M15 Increment 45).** `withDatabase` in `packages/persistence/test/variant-migrations.integration.test.ts` ended its pool and then immediately ran `DROP DATABASE ... WITH (FORCE)`. `pool.end()` does not wait for its clients to close: in pg 8.22.0 `_pulseQueue` reaches the end callback in the same synchronous turn in which `_remove` filters the last client out of `_clients`, while `client.end()` has only queued the Terminate byte — instrumentation recorded **zero of four `remove` events fired at the moment `end()` resolved**. The drop could therefore still find a backend attached; `FORCE` terminated it, and the resulting `FATAL` arrived on a socket whose pool still had `idleListener` attached, which `pg` re-emitted as `pool.emit('error')` — an unhandled EventEmitter error that `node:test` attributed to whichever test was running rather than to the teardown that caused it. It surfaced as intermittent `terminating connection due to administrator command` failures in `postgres integration (persistence)` during M15 Increment 44, on a different test each run, which is the signature of a race rather than a broken assertion. The same shape existed in `packages/api/test/auth-signin-schema.integration.test.ts`, which had absorbed SQLSTATE 57P01 with a `pool.on('error', ...)` listener — a symptom fix for the same cause. **Resolved in Increment 45:** a shared `withTestDatabase` helper (`@chess-platform/persistence/test-support`) ends the pool under a bound, waits for `pg_stat_activity` to report the database unused, and drops it *without* `FORCE`. Measured on PostgreSQL 16.14, a plain drop against a still-attached backend fails with SQLSTATE 55006 and leaves that connection untouched, where `FORCE` succeeds by killing it — so the change trades a quiet, harmful success for a loud, harmless failure. FORCE remains only on the emergency path that guarantees the disposable database is still dropped once teardown has already failed — best effort, since that last drop runs inside a `catch` so it cannot bury the error being reported. The 57P01 absorber is deleted, because the corrected lifecycle never causes one. `createPool` and `migrate` are unchanged, and no migration was added. - **`ApiServer.listen` registered no `'error'` handler, so a failed bind hung and raised an uncaught event (RESOLVED in ADR-0140 §5).** `packages/api/src/server.ts` resolved its promise from the `listening` callback only and built it with no reject path. A bind failing asynchronously (`EADDRINUSE`, `EMFILE`) left the promise pending forever and, with no `'error'` listener on the `http.Server`, was re-raised as an uncaught exception. Found while investigating ADR-0140 and independently raised by the Qodo review of PR #21. **Resolved in the same increment** rather than deferred, because ADR-0140 §2's bounded, diagnosable acquisition is not true without it — the retry can only report a bind error if the listener it is handed rejects. A one-shot `'error'` listener now rejects and is removed once listening, so later server errors keep their previous semantics rather than being swallowed by a `reject` on a settled promise. The regression test fails against the exact pre-fix code, through an uncaught `ERR_UNHANDLED_ERROR`. - **`main.ts`'s controller-disposal list is manual, untested, and silently incomplete when a section is added (RESOLVED in Increment 25 / ADR-0092).** `run()` in `packages/web/src/main.ts` disposes the previous route's controllers by name, and its own comment says doing so "is what makes re-bootstrapping safe" — but adding a section to `bootstrap` and forgetting to add it there compiles, passes every gate, and leaks. Increment 23 shipped exactly that omission for `LearningController` and it was caught in PR review, not by a test. `main.ts` has no test coverage of any kind, so no section's disposal is verified. A structural fix (bootstrap returning its disposables as a collection, or a type-level exhaustiveness check keyed off the result type) would make the next omission a compile error; it is a refactor across ~15 return sites and belongs in its own increment. **Resolved in Increment 25 (ADR-0092):** extracted `createLifecycle` run loop in `lifecycle.ts`, defined `BootstrappedDisposables` and `DisposableKey` driving `DISPOSABLE_TEARDOWN_MAP: Record` for compile-time exhaustiveness, normalised `.dispose()` verb across all disposables, and cascaded `GameController.stop()` to `gameSync.stop()`. - **`stepView` sends the answers to the learner (RESOLVED in Increment 29 / ADR-0095).** `packages/api/src/presenters.ts` emits `expectedSan` on a move step and `correctIndex` on a quiz step, and `GET /v1/lessons/:id/steps` is the route the learner's own lesson page calls. Increment 23 omits both from the client-side types (`packages/web/src/api/models.ts`), so the app cannot render or grade against them and a future edit that tries becomes a compile error — but the fields are still on the wire and readable in devtools. The authoring routes legitimately need them returned to the author, so the fix is a learner-scoped step view (or a caller-dependent projection), not a deletion: an API contract decision with its own ADR. Nothing rated or rewarded depends on step progress today, so this is a wart rather than a breach. **Resolved in Increment 29 (ADR-0095):** added `LearnerStepView` / `learnerStepView` in `packages/api/src/presenters.ts` omitting `expectedSan` and `correctIndex`. `GET /v1/lessons/:id/steps` and `GET /v1/steps/:id` now check course authorship via `repo.getLesson` / `repo.getCourse`, returning full `stepView` to the author and `learnerStepView` to learners and anonymous callers. Updated OpenAPI schema and web model comments. The first attempt resolved authorship with a separate `getLesson` + `getCourse` after the step read, which doubled both routes from 3 SQL queries to 6 because `listSteps` / `getStep` had already made those reads internally and discarded the course; caught in the PR #92 review and fixed by adding `getStepWithCourse` / `listStepsWithCourse` to `LearningRepository`, which return what was already loaded. Both routes now make exactly one repository call, pinned by a counting-proxy test. diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts index 46613ede..0784f06d 100644 --- a/packages/persistence/src/test-support/database.ts +++ b/packages/persistence/src/test-support/database.ts @@ -277,7 +277,7 @@ async function dropWhenFree( const lingering = await waitForQuiescence(admin, database, deadline, pollIntervalMs, onCheck); if (lingering.length > 0 && Date.now() >= deadline) { // Giving up here still has to leave the server clean: reporting the timeout without dropping - // would leak the database, which is the one outcome teardown must never produce. + // would leave the database behind, which is the outcome teardown works hardest to avoid. await forceDropAbandoned(admin, pool, clients, database); throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); } @@ -336,8 +336,11 @@ async function tearDown( * succeeds by killing it. So teardown waits for the database to be genuinely unused and then drops * it ordinarily — trading a quiet, harmful success for a loud, harmless failure. * - * Teardown always runs and always removes the database. It never replaces the callback's own error: - * when both fail, the callback's error is thrown with the teardown failure attached as its `cause`. + * Teardown always runs, and drops the disposable database on every path it can reach — including the + * one where it gives up and reports a timeout. The final fallback drop is best effort: it runs inside + * a `catch`, because a cleanup failure must not bury the error already being reported, so a server + * that refuses that drop can still leave a database behind. Teardown never replaces the callback's + * own error: when both fail, the callback's error is thrown with the teardown failure as its `cause`. */ export async function withTestDatabase( body: (db: TestDatabase) => Promise, From 32f9697073df572d2fe1776ab88aadba81cbc880 Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Thu, 3 Sep 2026 23:25:20 +0300 Subject: [PATCH 04/11] fix(persistence-test): bound admin work by owning its connection MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four more review findings, three of them consequences of the previous round. Racing `admin.query()` bounded nothing. The abandoned query kept its client checked out, and `pool.end()` never closes a checked-out client — so the bounded end gave up as well and the helper could return with live sockets and a query still running, which is the opposite of the guarantee it had just added. Admin statements now lease their client explicitly and `release(true)` it on overrun, which destroys the connection the statement is waiting on. Only a deadline overrun destroys: a statement that fails on its own terms, 55006 from a drop say, has finished with a client that is still good. `isForcedTermination` matched any message containing "Connection terminated", which is also what pg reports for an unrelated server restart or dropped network. As a general predicate it is now SQLSTATE 57P01 only. The bare message still has to be absorbed — measured here, that is exactly what a *leased* client sees when its socket goes down under an in-flight lease, and narrowing to SQLSTATE alone made the leaked-pool-client test fail — so that match now lives inside `forceDropAbandoned`, scoped to connections already being abandoned, after this code has itself issued the termination, on a path that always throws. The last-resort drop is a forced drop too, so it owes the same connections the same listener. It routes through `forceDropAbandoned` when a pool exists. The concurrency test assumed the short lifecycle finished inside a fixed 1.5s `pg_sleep`, which a loaded server can lose — failing a correct implementation. The long run is now held open by an explicit release, so the ordering is a fact of the test rather than a bet on the clock. Found while validating, not by a reviewer: deriving each step's budget from the time remaining collapsed it to 1ms exactly when the deadline was reached, so the quiescence check died with `TeardownDeadlineError` instead of reporting what it found — and node:test attributed the escaping error to an unrelated file, which is the very failure this branch removes. The per-step budget is a safety net for a server that has stopped answering; the loop's deadline is what ends the wait. The two are now separate. Persistence 173/173 and the full suite green on a fresh PostgreSQL 16.14, no databases left behind. 10 of 13 mutations killed, unchanged. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- .../persistence/src/test-support/database.ts | 140 ++++++++++++++---- .../test/test-database.integration.test.ts | 12 +- 2 files changed, 121 insertions(+), 31 deletions(-) diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts index 0784f06d..b54a5d71 100644 --- a/packages/persistence/src/test-support/database.ts +++ b/packages/persistence/src/test-support/database.ts @@ -6,7 +6,7 @@ * a separate subpath so the driver-facing surface does not grow a test harness. */ -import type { Pool, PoolClient } from 'pg'; +import type { Pool, PoolClient, QueryResult, QueryResultRow } from 'pg'; import { createPool } from '../pg/pool'; /** A backend still attached to the disposable database when teardown wanted to drop it. */ @@ -91,16 +91,16 @@ function sqlState(error: unknown): string | null { } /** - * Whether an error is a connection dying because something terminated its backend. + * Whether an error is the backend termination this helper itself just asked for. * - * Two shapes, because the client sees whichever arrives first: the `FATAL` message, which carries - * SQLSTATE 57P01, or the socket simply closing underneath it, which `pg` reports with no code at - * all. Both were observed against PostgreSQL 16.14 while measuring a forced drop. + * SQLSTATE only. `pg` also reports a bare "Connection terminated unexpectedly" when the socket + * closes before the `FATAL` is read, and matching that string would absorb every unrelated + * disconnect too — a server restart, a dropped network — precisely while the emergency listeners are + * installed. 57P01 is the server saying it terminated the backend on command, which is the only + * thing this code has grounds to treat as its own doing. */ function isForcedTermination(error: unknown): boolean { - if (sqlState(error) === ADMIN_SHUTDOWN) return true; - const message = error instanceof Error ? error.message : ''; - return message.includes('Connection terminated'); + return sqlState(error) === ADMIN_SHUTDOWN; } /** Replaces the database in a connection URL, leaving credentials and host alone. */ @@ -115,6 +115,14 @@ function delay(ms: number): Promise { return new Promise((resolve) => setTimeout(resolve, ms)); } +/** A teardown step that ran out of budget, as opposed to one that failed on its own terms. */ +class TeardownDeadlineError extends Error { + constructor(what: string, timeoutMs: number) { + super(`withTestDatabase: ${what} exceeded its ${timeoutMs}ms budget`); + this.name = 'TeardownDeadlineError'; + } +} + /** * Run `work`, but stop waiting for it after `timeoutMs`. * @@ -122,9 +130,8 @@ function delay(ms: number): Promise { * connection that stops answering would sit past the deadline with nothing to interrupt it, which * would make the budget advisory rather than real. Every teardown step therefore goes through here. * - * A step that times out is abandoned rather than cancelled — PostgreSQL is still holding whatever it - * was given — so the caller goes on to end the admin pool, which is what actually drops the sockets - * those queries are waiting on. + * Losing the race abandons the wait, not the work — so callers that raced a *query* must also + * destroy the connection it was running on. {@link boundedQuery} is how they do that. */ async function withDeadline(work: Promise, timeoutMs: number, what: string): Promise { let timer: NodeJS.Timeout | undefined; @@ -132,10 +139,7 @@ async function withDeadline(work: Promise, timeoutMs: number, what: string return await Promise.race([ work, new Promise((_resolve, reject) => { - timer = setTimeout( - () => reject(new Error(`withTestDatabase: ${what} exceeded its ${timeoutMs}ms budget`)), - timeoutMs, - ); + timer = setTimeout(() => reject(new TeardownDeadlineError(what, timeoutMs)), timeoutMs); }), ]); } finally { @@ -143,6 +147,37 @@ async function withDeadline(work: Promise, timeoutMs: number, what: string } } +/** + * Run one admin statement under the budget, and take its connection away if it overruns. + * + * Racing `pool.query()` alone is not enough to bound anything. The abandoned query keeps its client + * checked out, and `pool.end()` never closes a checked-out client — so the bounded end gives up too + * and the helper returns with live sockets and a query still running, which is the opposite of the + * guarantee. Leasing the client here makes it reachable: `release(true)` destroys it rather than + * returning it to the pool, which drops the socket the statement is waiting on. + * + * Only a deadline overrun destroys the connection. A statement that fails on its own terms — 55006 + * from a drop, say — has finished with its client, and that client is still perfectly good. + */ +async function boundedQuery( + admin: Pool, + timeoutMs: number, + what: string, + text: string, + values: readonly unknown[] = [], +): Promise> { + const client = await withDeadline(admin.connect(), timeoutMs, `${what} (connect)`); + let overran = false; + try { + return await withDeadline(client.query(text, [...values]), timeoutMs, what); + } catch (error) { + overran = error instanceof TeardownDeadlineError; + throw error; + } finally { + client.release(overran); + } +} + /** * Resolve once no backend is attached to `database`, or return what is still there at the deadline. * @@ -155,15 +190,19 @@ async function waitForQuiescence( admin: Pool, database: string, deadline: number, + stepTimeoutMs: number, pollIntervalMs: number, onCheck: ((backends: readonly LingeringBackend[]) => void) | undefined, ): Promise { for (;;) { - const { rows } = await admin.query<{ + const { rows } = await boundedQuery<{ pid: number; state: string | null; application_name: string | null; }>( + admin, + stepTimeoutMs, + 'quiescence check', `SELECT pid, state, application_name FROM pg_stat_activity WHERE datname = $1 AND pid <> pg_backend_pid()`, @@ -239,15 +278,26 @@ async function forceDropAbandoned( pool: Pool, clients: ReadonlySet, database: string, + timeoutMs: number, ): Promise { + // Two shapes reach these connections, and both are this call's own doing. The server's `FATAL` + // carries SQLSTATE 57P01. When the backend dies before that message can be read, `pg` reports a + // bare "Connection terminated unexpectedly" with no code at all — measured here, that is what a + // *leased* client sees, because its socket goes down under an in-flight lease. + // + // Matching that string is defensible only because of where it sits: on connections belonging to a + // pool already being abandoned, after this function has itself issued the termination, on a path + // whose caller always throws. It is deliberately not part of {@link isForcedTermination}, which + // stays SQLSTATE-only — as a general predicate the string would absorb an unrelated server restart + // or dropped network too, which is the observability loss the deleted 57P01 absorber caused. const absorbOwnTermination = (error: Error): void => { - if (isForcedTermination(error)) return; + if (isForcedTermination(error) || error.message.includes('Connection terminated')) return; throw error; }; pool.on('error', absorbOwnTermination); for (const client of clients) client.on('error', absorbOwnTermination); - await admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); + await boundedQuery(admin, timeoutMs, 'forced drop', `DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`); } /** @@ -270,15 +320,27 @@ async function dropWhenFree( ): Promise { for (;;) { try { - await admin.query(`DROP DATABASE IF EXISTS "${database}"`); + await boundedQuery( + admin, + teardownTimeoutMs, + 'drop', + `DROP DATABASE IF EXISTS "${database}"`, + ); return; } catch (error) { if (sqlState(error) !== OBJECT_IN_USE || Date.now() >= deadline) throw error; - const lingering = await waitForQuiescence(admin, database, deadline, pollIntervalMs, onCheck); + const lingering = await waitForQuiescence( + admin, + database, + deadline, + teardownTimeoutMs, + pollIntervalMs, + onCheck, + ); if (lingering.length > 0 && Date.now() >= deadline) { // Giving up here still has to leave the server clean: reporting the timeout without dropping // would leave the database behind, which is the outcome teardown works hardest to avoid. - await forceDropAbandoned(admin, pool, clients, database); + await forceDropAbandoned(admin, pool, clients, database, teardownTimeoutMs); throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); } } @@ -307,11 +369,18 @@ async function tearDown( const deadline = Date.now() + teardownTimeoutMs; await endPoolWithin(pool, Math.max(0, deadline - Date.now())); - const lingering = await waitForQuiescence(admin, database, deadline, pollIntervalMs, onCheck); + const lingering = await waitForQuiescence( + admin, + database, + deadline, + teardownTimeoutMs, + pollIntervalMs, + onCheck, + ); if (lingering.length > 0) { // Something outlived its owner. Drop the database anyway so the server is not littered with // abandoned test databases, then say precisely what was holding it. - await forceDropAbandoned(admin, pool, clients, database); + await forceDropAbandoned(admin, pool, clients, database, teardownTimeoutMs); throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); } await dropWhenFree(admin, pool, clients, database, deadline, teardownTimeoutMs, pollIntervalMs, onCheck); @@ -373,6 +442,10 @@ export async function withTestDatabase( // nothing else would ever return. const teardownBackstopMs = teardownTimeoutMs * 2 + 1_000; const admin = createPool({ connectionString, max: 2, connectionTimeoutMillis: teardownTimeoutMs }); + // Hoisted so the last-resort drop can route through `forceDropAbandoned`: that drop is a forced + // one too, and it terminates the same connections, so it owes them the same listener. + let pool: Pool | undefined; + let clients: ReadonlySet = new Set(); let dropped = false; let bodyFailed = false; let teardownFailed = false; @@ -383,8 +456,8 @@ export async function withTestDatabase( try { await admin.query(`CREATE DATABASE "${database}"`); const databaseUrl = urlForDatabase(connectionString, database); - const pool = createPool({ connectionString: databaseUrl, max: options.max ?? 4 }); - const clients = trackClients(pool); + pool = createPool({ connectionString: databaseUrl, max: options.max ?? 4 }); + clients = trackClients(pool); try { result = await body({ pool, database, connectionString: databaseUrl }); } catch (error) { @@ -420,11 +493,18 @@ export async function withTestDatabase( } finally { try { if (!dropped) { - await withDeadline( - admin.query(`DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`), - teardownBackstopMs, - 'last-resort drop', - ); + // The same forced drop, so the same duty of care: if a pool exists it may still own + // connections this is about to terminate, and they need a listener before it happens. + if (pool !== undefined) { + await forceDropAbandoned(admin, pool, clients, database, teardownBackstopMs); + } else { + await boundedQuery( + admin, + teardownBackstopMs, + 'last-resort drop', + `DROP DATABASE IF EXISTS "${database}" WITH (FORCE)`, + ); + } } } catch { // A last-resort drop that fails leaves the error already in flight, which describes the real diff --git a/packages/persistence/test/test-database.integration.test.ts b/packages/persistence/test/test-database.integration.test.ts index 031cb40f..57e8c053 100644 --- a/packages/persistence/test/test-database.integration.test.ts +++ b/packages/persistence/test/test-database.integration.test.ts @@ -261,10 +261,19 @@ test('test database: a concurrent run is not blocked by another database’s bac const checksShort: Array = []; let longFinished = false; + // The long run is held open by an explicit release rather than a sleep. A fixed `pg_sleep` would + // make this assertion a bet that the short run finishes first, which a loaded server can lose — + // failing a correct implementation. Held this way, the ordering is a fact of the test. + let releaseLong = (): void => undefined; + const heldOpen = new Promise((resolve) => { + releaseLong = resolve; + }); + const long = withTestDatabase( async ({ pool, database }) => { names.push(database); - await pool.query('SELECT pg_sleep(1.5)'); + await pool.query('SELECT 1'); + await heldOpen; }, { onQuiescenceCheck: (backends) => checksLong.push(backends) }, ).then(() => { @@ -282,6 +291,7 @@ test('test database: a concurrent run is not blocked by another database’s bac await short; assert.equal(longFinished, false, 'the short run completed while the long one still held its database'); + releaseLong(); await long; assert.equal(names.length, 2); From 210fefa25045461a5bb3c9c63e5b8c1dd0da8abc Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Thu, 3 Sep 2026 23:54:07 +0300 Subject: [PATCH 05/11] fix(persistence-test): release the gate on every path, and keep 55006 typed MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four more findings, and two of them were leaks in this file's own tests — the class of defect it exists to prevent. The concurrency test released its latch only on the success path. If the short run rejected or the ordering assertion failed, the long callback stayed suspended on `heldOpen` forever: its teardown never ran, its pool and disposable database stayed alive, and the runner could fail to exit. The gate now opens in a `finally` and the long run is awaited there. That test also held its database with `pool.query`, which returns its client to the pool as soon as it answers. An idle client can be closed before the short run finishes, leaving the long run holding no backend at all — so the isolation it claims to prove would not have been proven. It leases a client across the gate now and releases it in a `finally`. In `dropWhenFree`, a `DROP DATABASE` answering 55006 at or past the deadline was rethrown as a raw PostgreSQL error. That skipped the snapshot naming what still held the database, skipped the typed DatabaseTeardownTimeoutError, and left only the outer best-effort drop. 55006 at the deadline is a teardown timeout like any other: it takes a final snapshot, force-drops, and reports the typed error. Every other SQLSTATE still propagates untouched. Persistence 173/173, full suite green on a fresh PostgreSQL 16.14, no databases left behind, all six guard scripts pass. 10 of 13 mutations killed, unchanged. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- .../persistence/src/test-support/database.ts | 12 +++++--- .../test/test-database.integration.test.ts | 28 ++++++++++++++----- 2 files changed, 29 insertions(+), 11 deletions(-) diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts index b54a5d71..b5efce5d 100644 --- a/packages/persistence/src/test-support/database.ts +++ b/packages/persistence/src/test-support/database.ts @@ -328,7 +328,9 @@ async function dropWhenFree( ); return; } catch (error) { - if (sqlState(error) !== OBJECT_IN_USE || Date.now() >= deadline) throw error; + // Anything but "still in use" is a real database error and belongs to the caller untouched. + if (sqlState(error) !== OBJECT_IN_USE) throw error; + const lingering = await waitForQuiescence( admin, database, @@ -337,9 +339,11 @@ async function dropWhenFree( pollIntervalMs, onCheck, ); - if (lingering.length > 0 && Date.now() >= deadline) { - // Giving up here still has to leave the server clean: reporting the timeout without dropping - // would leave the database behind, which is the outcome teardown works hardest to avoid. + if (Date.now() >= deadline) { + // 55006 arriving at or past the deadline is still a teardown timeout, not a raw SQL fault: + // rethrowing the PostgreSQL error would skip the snapshot that names what was holding the + // database and leave only the outer best-effort drop. Giving up here has to leave the server + // clean too, so the database goes before the report does. await forceDropAbandoned(admin, pool, clients, database, teardownTimeoutMs); throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); } diff --git a/packages/persistence/test/test-database.integration.test.ts b/packages/persistence/test/test-database.integration.test.ts index 57e8c053..0891c4eb 100644 --- a/packages/persistence/test/test-database.integration.test.ts +++ b/packages/persistence/test/test-database.integration.test.ts @@ -272,8 +272,16 @@ test('test database: a concurrent run is not blocked by another database’s bac const long = withTestDatabase( async ({ pool, database }) => { names.push(database); - await pool.query('SELECT 1'); - await heldOpen; + // A leased client, not `pool.query`. `pool.query` returns its client to the pool as soon as it + // answers, and an idle client can be closed before the short run finishes — which would leave + // this run holding no backend at all, and the isolation this test claims to prove unproven. + const leased = await pool.connect(); + try { + await leased.query('SELECT 1'); + await heldOpen; + } finally { + leased.release(); + } }, { onQuiescenceCheck: (backends) => checksLong.push(backends) }, ).then(() => { @@ -288,11 +296,17 @@ test('test database: a concurrent run is not blocked by another database’s bac { onQuiescenceCheck: (backends) => checksShort.push(backends) }, ); - await short; - assert.equal(longFinished, false, 'the short run completed while the long one still held its database'); - - releaseLong(); - await long; + try { + await short; + assert.equal(longFinished, false, 'the short run completed while the long one still held its database'); + } finally { + // The gate has to open on every path. If the short run rejects or the ordering assertion fails, + // an unreleased latch leaves the long callback suspended forever: its teardown never runs, its + // database and pool stay alive, and the runner may not exit. A test that leaks the thing it is + // policing is the failure this whole file exists to prevent. + releaseLong(); + await long; + } assert.equal(names.length, 2); assert.notEqual(names[0], names[1], 'each run gets its own database'); From 8fed6112d7c49d4904cc9b0319ad3fbcc3b50a09 Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Fri, 4 Sep 2026 00:36:34 +0300 Subject: [PATCH 06/11] fix(persistence-test): keep the typed timeout when the forced drop fails too MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two findings, both second-order consequences of the previous round. The emergency drop is a query, so it can fail or overrun like any other — and awaiting it before constructing DatabaseTeardownTimeoutError meant its failure escaped in place of the typed error, taking with it the list of backends that actually held the database. That list is the only part of the report a reader can act on. Both timeout paths now go through one reporter: the forced drop's failure becomes the timeout's `cause`, and whether it succeeded is recorded on the error as `droppedDatabase` rather than inferred. That inference was the second half of the same defect. The caller set `dropped = error instanceof DatabaseTeardownTimeoutError`, treating the error type as proof the database was gone — so a timeout whose forced drop had failed would skip the last-resort drop exactly when the database was still there. It reads `droppedDatabase` now. In the concurrency test, awaiting the long run from a `finally` let its rejection replace a short-run or assertion failure, because a throw from `finally` supersedes whatever was already propagating. The gate is still released and the long fixture still settles on every path, but the first failure is now the one thrown, with the long run's failure attached as its cause — the same rule the helper itself follows for callback-versus-teardown errors. Persistence 173/173, full suite green on a fresh PostgreSQL 16.14, no databases left behind, all six guards pass, counts 3270. Mutations 10 of 14 killed: the new M15 — letting a failed emergency drop replace the typed timeout — survives alongside M7, M13 and M14, all four being defensive branches that need fault injection to reach. They are named in the PR rather than padded out. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- .../persistence/src/test-support/database.ts | 68 ++++++++++++++++--- .../test/test-database.integration.test.ts | 35 ++++++++-- 2 files changed, 85 insertions(+), 18 deletions(-) diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts index b5efce5d..e043d16d 100644 --- a/packages/persistence/src/test-support/database.ts +++ b/packages/persistence/src/test-support/database.ts @@ -59,8 +59,21 @@ export interface TestDatabaseOptions { export class DatabaseTeardownTimeoutError extends Error { readonly database: string; readonly lingering: readonly LingeringBackend[]; + /** + * Whether the emergency drop actually removed the database. + * + * The caller uses this rather than assuming a timeout implies a clean server: the forced drop is + * itself a query, and it can fail or overrun like any other. When it does, the database is still + * there and the last-resort drop still has work to do. + */ + readonly droppedDatabase: boolean; - constructor(database: string, timeoutMs: number, lingering: readonly LingeringBackend[]) { + constructor( + database: string, + timeoutMs: number, + lingering: readonly LingeringBackend[], + droppedDatabase: boolean, + ) { const who = lingering.length > 0 ? lingering @@ -69,12 +82,47 @@ export class DatabaseTeardownTimeoutError extends Error { : 'nothing was visible on the server, so the pool itself never finished closing'; super( `database "${database}" was still in use ${timeoutMs}ms after its pool was closed: ${who}. ` + - 'It has been dropped so nothing leaks, but something held a connection it did not own.', + (droppedDatabase + ? 'It has been dropped, but something held a connection it did not own.' + : 'Dropping it then failed too, so it may still be on the server — see this error’s cause.'), ); this.name = 'DatabaseTeardownTimeoutError'; this.database = database; this.lingering = lingering; + this.droppedDatabase = droppedDatabase; + } +} + +/** + * Force-drop for a teardown that has already failed, and report the timeout either way. + * + * The forced drop is a query like any other: it can fail, or overrun its own budget. Letting that + * escape would replace the typed timeout — and with it the list of backends that actually held the + * database, which is the only part of this a reader can act on. So the drop's failure becomes the + * timeout's `cause`, and whether it succeeded is recorded rather than assumed. + */ +async function reportTimeoutAfterForcedDrop( + admin: Pool, + pool: Pool, + clients: ReadonlySet, + database: string, + timeoutMs: number, + lingering: readonly LingeringBackend[], +): Promise { + let dropFailure: unknown; + try { + await forceDropAbandoned(admin, pool, clients, database, timeoutMs); + } catch (error) { + dropFailure = error; } + const timeout = new DatabaseTeardownTimeoutError( + database, + timeoutMs, + lingering, + dropFailure === undefined, + ); + if (dropFailure !== undefined) timeout.cause = dropFailure; + throw timeout; } /** SQLSTATE 55006 — `DROP DATABASE` refusing because a backend is still attached. */ @@ -342,10 +390,8 @@ async function dropWhenFree( if (Date.now() >= deadline) { // 55006 arriving at or past the deadline is still a teardown timeout, not a raw SQL fault: // rethrowing the PostgreSQL error would skip the snapshot that names what was holding the - // database and leave only the outer best-effort drop. Giving up here has to leave the server - // clean too, so the database goes before the report does. - await forceDropAbandoned(admin, pool, clients, database, teardownTimeoutMs); - throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); + // database and leave only the outer best-effort drop. + await reportTimeoutAfterForcedDrop(admin, pool, clients, database, teardownTimeoutMs, lingering); } } } @@ -384,8 +430,7 @@ async function tearDown( if (lingering.length > 0) { // Something outlived its owner. Drop the database anyway so the server is not littered with // abandoned test databases, then say precisely what was holding it. - await forceDropAbandoned(admin, pool, clients, database, teardownTimeoutMs); - throw new DatabaseTeardownTimeoutError(database, teardownTimeoutMs, lingering); + await reportTimeoutAfterForcedDrop(admin, pool, clients, database, teardownTimeoutMs, lingering); } await dropWhenFree(admin, pool, clients, database, deadline, teardownTimeoutMs, pollIntervalMs, onCheck); } @@ -481,9 +526,10 @@ export async function withTestDatabase( } catch (error) { teardownFailed = true; teardownError = error; - // Both teardown paths that throw a timeout have already force-dropped the database, so only - // those are known-clean. Any other failure leaves the drop to the net below. - dropped = error instanceof DatabaseTeardownTimeoutError; + // A timeout reports whether its own forced drop succeeded, because that drop is a query and + // can fail too. Trusting the error type alone would skip the net below exactly when the + // database is still there. + dropped = error instanceof DatabaseTeardownTimeoutError && error.droppedDatabase; } } } catch (error) { diff --git a/packages/persistence/test/test-database.integration.test.ts b/packages/persistence/test/test-database.integration.test.ts index 0891c4eb..6324a03f 100644 --- a/packages/persistence/test/test-database.integration.test.ts +++ b/packages/persistence/test/test-database.integration.test.ts @@ -296,17 +296,38 @@ test('test database: a concurrent run is not blocked by another database’s bac { onQuiescenceCheck: (backends) => checksShort.push(backends) }, ); + // The gate has to open on every path. If the short run rejects or the ordering assertion fails, + // an unreleased latch leaves the long callback suspended forever: its teardown never runs, its + // database and pool stay alive, and the runner may not exit. A test that leaks the thing it is + // policing is the failure this whole file exists to prevent. + // + // Not a `finally`, though — throwing from one replaces whatever was already propagating, so a + // long run that also failed would bury the short-run failure that started all this. The same rule + // the helper follows for callback-versus-teardown errors: the first failure is the one worth + // reading, and the second rides along. + let primaryFailure: unknown; + let primaryFailed = false; try { await short; assert.equal(longFinished, false, 'the short run completed while the long one still held its database'); - } finally { - // The gate has to open on every path. If the short run rejects or the ordering assertion fails, - // an unreleased latch leaves the long callback suspended forever: its teardown never runs, its - // database and pool stay alive, and the runner may not exit. A test that leaks the thing it is - // policing is the failure this whole file exists to prevent. - releaseLong(); - await long; + } catch (error) { + primaryFailed = true; + primaryFailure = error; + } + + releaseLong(); + const longFailure = await long.then( + () => undefined, + (error: unknown) => error ?? new Error('the long run rejected with a falsy value'), + ); + + if (primaryFailed) { + if (longFailure !== undefined && primaryFailure instanceof Error && primaryFailure.cause === undefined) { + primaryFailure.cause = longFailure; + } + throw primaryFailure; } + if (longFailure !== undefined) throw longFailure; assert.equal(names.length, 2); assert.notEqual(names[0], names[1], 'each run gets its own database'); From 3a65b41111fb2ee76969c24c78822a7a85aa54aa Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Fri, 4 Sep 2026 01:01:30 +0300 Subject: [PATCH 07/11] fix(api-test): make each teardown step independent of the last MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Chained with plain awaits, a server that failed to close skipped `shutdownAnalysis` entirely — leaving the analysis worker holding the pool while `withTestDatabase` tried to end it, so a small close failure became a teardown timeout and a run of pool-after-end errors. Restoring the saved environment was skipped for the same reason, which the next case in the file would inherit. Each step now runs whatever the one before it did, and the case's own failure keeps precedence: a cleanup failure rides along as its `cause` rather than replacing it. That is the rule `withTestDatabase` already follows for callback-versus-teardown errors, and this file should not have differed from it. Raised by CodeRabbit as a trivial nitpick against code this branch restructured. It is the same cascade class this PR exists to remove, so it is fixed rather than deferred. Persistence 173/173, api 975, full suite green on a fresh PostgreSQL 16.14, no databases left behind, all six guards pass, counts 3270. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- .../auth-signin-schema.integration.test.ts | 43 +++++++++++++++---- 1 file changed, 34 insertions(+), 9 deletions(-) diff --git a/packages/api/test/auth-signin-schema.integration.test.ts b/packages/api/test/auth-signin-schema.integration.test.ts index 98427e61..b732ed35 100644 --- a/packages/api/test/auth-signin-schema.integration.test.ts +++ b/packages/api/test/auth-signin-schema.integration.test.ts @@ -107,6 +107,8 @@ async function withSchema(run: (fixture: Fixture) => Promise): Promise Promise) | undefined; + let caseFailed = false; + let caseError: unknown; try { const composed = createPgApiServer({ pool, logger, config: { accessTokenSecret: TEST_SECRET } }); shutdownAnalysis = composed.shutdownAnalysis; @@ -122,17 +124,40 @@ async function withSchema(run: (fixture: Fixture) => Promise): Promise migrate(pool, dir), }); - } finally { - // The server and the analysis worker both hold this pool, so they have to be shut down - // before the callback returns — teardown ends the pool the moment it does, and anything - // still using it would fail with "Cannot use a pool after calling end on the pool". - if (http) await closeServer(http); - if (shutdownAnalysis) await shutdownAnalysis(); - for (const [key, value] of Object.entries(savedEnv)) { - if (value === undefined) delete process.env[key]; - else process.env[key] = value; + } catch (error) { + caseFailed = true; + caseError = error; + } + + // The server and the analysis worker both hold this pool, so they have to be shut down before + // the callback returns — teardown ends the pool the moment it does, and anything still using + // it would fail with "Cannot use a pool after calling end on the pool". + // + // Each step runs whatever the one before it did. Chained with plain awaits, a server that + // failed to close would skip `shutdownAnalysis` entirely, leaving the analysis worker holding + // this pool while teardown tried to end it — turning a small close failure into a teardown + // timeout and a run of pool-after-end errors. Restoring the environment must not be skipped + // either, or the next test in the file inherits it. + const cleanupFailures: unknown[] = []; + const record = (error: unknown): void => { + cleanupFailures.push(error); + }; + if (http) await closeServer(http).catch(record); + if (shutdownAnalysis) await shutdownAnalysis().catch(record); + for (const [key, value] of Object.entries(savedEnv)) { + if (value === undefined) delete process.env[key]; + else process.env[key] = value; + } + + // Same precedence the helper itself uses: the case's own failure is the one worth reading, and + // a cleanup failure rides along rather than replacing it. + if (caseFailed) { + if (cleanupFailures.length > 0 && caseError instanceof Error && caseError.cause === undefined) { + caseError.cause = cleanupFailures[0]; } + throw caseError; } + if (cleanupFailures.length > 0) throw cleanupFailures[0]; }, { connectionString: DATABASE_URL, max: 4 }, ); From 8e961a8dd9e4d7a7421e95cd75015512d02e77b7 Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Fri, 4 Sep 2026 01:57:45 +0300 Subject: [PATCH 08/11] test(persistence): settle the long run where it is created, and assert by name MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two findings from CodeRabbit, both in this file's own tests. The long fixture only gained a rejection handler after `await short`. A rejection arriving while the short run was still pending was unhandled at that moment, so node:test would report an uncaught rejection instead of the captured failure — hiding precisely what the precedence logic below it was written to surface. The outcome is now settled in the same `.then` that sets `longFinished`, where the promise is created. `countTestDatabases()` counted every `test_db_%` database on the server, and this suite shares that server with whatever else runs against DATABASE_URL. A before/after count was therefore answering for the other process as much as for the fixture. Both leak checks name their own database instead, which is exact and immune to a neighbour. CodeRabbit raised one of the two; the same reasoning applied to the other, so both are fixed and the counting helper is gone. Persistence 173/173, api 975, full suite green on a fresh PostgreSQL 16.14, no databases left behind, all six guards pass, counts 3270. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- .../test/test-database.integration.test.ts | 57 +++++++++---------- 1 file changed, 28 insertions(+), 29 deletions(-) diff --git a/packages/persistence/test/test-database.integration.test.ts b/packages/persistence/test/test-database.integration.test.ts index 6324a03f..48ef1c39 100644 --- a/packages/persistence/test/test-database.integration.test.ts +++ b/packages/persistence/test/test-database.integration.test.ts @@ -52,19 +52,6 @@ async function databaseExists(name: string): Promise { } } -/** How many disposable databases the helper currently has on the server. */ -async function countTestDatabases(): Promise { - const client = await admin(); - try { - const { rows } = await client.query<{ n: string }>( - "SELECT count(*)::text AS n FROM pg_database WHERE datname LIKE 'test\\_db\\_%'", - ); - return Number(rows[0]?.n ?? '0'); - } finally { - await client.end(); - } -} - test('test database: a successful callback leaves no database behind', { skip }, async () => { let name = ''; let poolRef: Pool | undefined; @@ -284,9 +271,17 @@ test('test database: a concurrent run is not blocked by another database’s bac } }, { onQuiescenceCheck: (backends) => checksLong.push(backends) }, - ).then(() => { - longFinished = true; - }); + // Settled here, where the promise is created, rather than after `await short`. A rejection + // arriving while `short` is still pending would otherwise be unhandled at that moment, and + // node:test would report an uncaught rejection instead of the failure the precedence logic + // below exists to preserve — hiding exactly what it was written to surface. + ).then( + () => { + longFinished = true; + return undefined; + }, + (error: unknown) => error ?? new Error('the long run rejected with a falsy value'), + ); const short = withTestDatabase( async ({ pool, database }) => { @@ -316,10 +311,7 @@ test('test database: a concurrent run is not blocked by another database’s bac } releaseLong(); - const longFailure = await long.then( - () => undefined, - (error: unknown) => error ?? new Error('the long run rejected with a falsy value'), - ); + const longFailure = await long; if (primaryFailed) { if (longFailure !== undefined && primaryFailure instanceof Error && primaryFailure.cause === undefined) { @@ -338,15 +330,18 @@ test('test database: a concurrent run is not blocked by another database’s bac test('test database: giving up on teardown still leaves no database behind', { skip }, async () => { // The bounded path force-drops before it reports, and the outer net must not wrongly assume it - // did. A leaked database is invisible to every other assertion here and is the one outcome - // teardown must never produce, so it gets counted directly. - const before = await countTestDatabases(); + // did. A leaked database is invisible to every other assertion here, so it is checked directly — + // by name rather than by counting `test_db_%` on the server. This suite shares a server with + // whatever else is running against `DATABASE_URL`, and a count taken before and after would be + // answering for that other process as much as for this fixture. + let name = ''; let held: Client | undefined; try { await assert.rejects( withTestDatabase( - async ({ pool, connectionString }) => { + async ({ pool, connectionString, database }) => { + name = database; await pool.query('SELECT 1'); held = new Client({ connectionString, application_name: 'leak-check' }); await held.connect(); @@ -362,7 +357,8 @@ test('test database: giving up on teardown still leaves no database behind', { s if (held) await held.end().catch(() => undefined); } - assert.equal(await countTestDatabases(), before, 'the disposable database did not survive teardown'); + assert.notEqual(name, '', 'the fixture reported the database it created'); + assert.equal(await databaseExists(name), false, 'the disposable database did not survive teardown'); }); test('test database: a leaked pool client does not become an uncaught error', { skip }, async () => { @@ -373,11 +369,12 @@ test('test database: a leaked pool client does not become an uncaught error', { // uncaught exception: the failure this whole helper exists to remove, reintroduced by its own // cleanup. Unlike the other leak tests, nothing here attaches a listener of its own — the helper // has to own the termination it causes. - const before = await countTestDatabases(); + let name = ''; await assert.rejects( withTestDatabase( - async ({ pool }) => { + async ({ pool, database }) => { + name = database; const leased = await pool.connect(); await leased.query('SELECT 1'); // Deliberately never released. @@ -391,8 +388,10 @@ test('test database: a leaked pool client does not become an uncaught error', { ); // If the FATAL had escaped, node:test would have failed this run with an uncaught exception rather - // than reaching here. - assert.equal(await countTestDatabases(), before, 'and the database still went away'); + // than reaching here. Checked by name, not by counting `test_db_%`: this suite shares a server, so + // a count would be answering for whatever else is running against it too. + assert.notEqual(name, '', 'the fixture reported the database it created'); + assert.equal(await databaseExists(name), false, 'and the database still went away'); }); test('test database: a callback that rejects with undefined is still a failure', { skip }, async () => { From d80beed45c81f093467224b54915b3c80df3c612 Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Fri, 4 Sep 2026 02:15:40 +0300 Subject: [PATCH 09/11] docs: say that emergency cleanup is best effort in both directions MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The normal teardown path terminates nothing — that is the whole point of dropping without FORCE — but PROJECT_STATE still described the emergency path as "removing the database so nothing leaks", which claims more than the code does in both directions. That path does terminate whatever is still attached, and its final fallback drop runs inside a `catch` so a cleanup failure cannot bury the error being reported, which means a server that refuses the drop can leave a database behind. Which of the two happened is recorded rather than assumed: DatabaseTeardownTimeoutError carries `droppedDatabase`, with any failed drop attached as its `cause`. AI_HANDOVER.md points engineers and agents at this file as the detailed handover, so wording that overstates the guarantee would misdirect exactly the person diagnosing a teardown. Raised by CodeRabbit. Docs only. No code change. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- docs/PROJECT_STATE.md | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/docs/PROJECT_STATE.md b/docs/PROJECT_STATE.md index 993d5031..db8e2c78 100644 --- a/docs/PROJECT_STATE.md +++ b/docs/PROJECT_STATE.md @@ -28,8 +28,17 @@ it — so `pg` re-emitted it as `pool.emit('error')`, an unhandled EventEmitter backend deliberately held open: plain `DROP DATABASE` fails with SQLSTATE 55006 and leaves that connection untouched, where `WITH (FORCE)` succeeds by killing it. The fix trades a quiet, harmful success for a loud, harmless failure — teardown waits for the database to be genuinely unused, then -drops it ordinarily. FORCE survives only on the emergency path, where teardown has already given up -and is removing the database so nothing leaks. +drops it ordinarily, so the normal path terminates nothing. + +FORCE survives only on the emergency path, reached once teardown has already failed, and there it is +**best effort in both directions**. It does terminate whatever is still attached — the helper +installs an error listener on the pool and on every live client first, so the FATAL it causes cannot +escape as an uncaught error — and the final fallback drop runs inside a `catch`, so a cleanup failure +cannot bury the error being reported. A server that refuses that drop can therefore still leave a +database behind. Which of the two happened is recorded rather than assumed: +`DatabaseTeardownTimeoutError` carries `droppedDatabase`, with any failed drop attached as its +`cause`. Anyone diagnosing a teardown should read that flag instead of taking a reported timeout to +mean the server came out clean. **Shared helper.** `packages/persistence/src/test-support/database.ts` exposes `withTestDatabase` through the new `@chess-platform/persistence/test-support` subpath, kept off the driver-facing `./pg` From a76a4e78b763376b8a6cb98f690964fc79136ba0 Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Fri, 4 Sep 2026 02:49:02 +0300 Subject: [PATCH 10/11] fix(persistence-test): destroy a late lease, and bound CREATE DATABASE MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two more findings, both about work this code starts and then stops waiting for. `withDeadline(admin.connect(), ...)` stops the wait but does not cancel the connect. A lease landing after the deadline was checked out with nobody left to release it, and `pool.end()` waits for checked-out clients — so the pool the bound existed to protect would never close. The late arrival is now destroyed with `release(true)`, and the lease rejecting on its own is tolerated. `CREATE DATABASE` ran through a raw `admin.query`. `connectionTimeoutMillis` bounds acquiring a connection, not a query on one already established, so a stalled server could hold that await open forever — before the callback runs and before there is any cleanup to start. It goes through `boundedQuery` now, under its own generous CREATE_TIMEOUT_MS rather than `teardownTimeoutMs`: two tests set that as low as 300ms to exercise the timeout path, and starving creation with a teardown budget is a hazard this branch already had to back out of once. The static-analysis SQL-injection warnings on that line are noise, not a finding. PostgreSQL has no bound-parameter form for an identifier, the name is generated in this function and cannot be supplied by a caller, and it matches `[a-z0-9_]+` with nothing to escape — which is written down beside the generation. Persistence 173/173, api 975/975, full suite green on a fresh PostgreSQL 16.14 across two consecutive runs, no databases left behind, six guards pass, counts 3270, mutations 10 of 14. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- .../persistence/src/test-support/database.ts | 32 +++++++++++++++++-- 1 file changed, 30 insertions(+), 2 deletions(-) diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts index e043d16d..f34f9082 100644 --- a/packages/persistence/src/test-support/database.ts +++ b/packages/persistence/src/test-support/database.ts @@ -125,6 +125,17 @@ async function reportTimeoutAfterForcedDrop( throw timeout; } +/** + * Bound on creating the disposable database. + * + * Deliberately generous, and deliberately *not* `teardownTimeoutMs`. `connectionTimeoutMillis` + * bounds acquiring a connection, not a query on one already established, so a stalled server could + * otherwise hold this await open forever — before the callback runs and before there is any cleanup + * to start. It is separate from the teardown budget because tests set that as low as 300ms to + * exercise the timeout path, and creation has nothing to do with how long teardown may wait. + */ +const CREATE_TIMEOUT_MS = 30_000; + /** SQLSTATE 55006 — `DROP DATABASE` refusing because a backend is still attached. */ const OBJECT_IN_USE = '55006'; @@ -214,7 +225,24 @@ async function boundedQuery( text: string, values: readonly unknown[] = [], ): Promise> { - const client = await withDeadline(admin.connect(), timeoutMs, `${what} (connect)`); + const lease = admin.connect(); + let client: PoolClient; + try { + client = await withDeadline(lease, timeoutMs, `${what} (connect)`); + } catch (error) { + // The deadline stops this waiting; it does not cancel the connect. A lease that lands afterwards + // would be checked out with nobody left to release it — and `pool.end()` waits for checked-out + // clients, so the pool this was meant to bound would never close. Destroy the late arrival + // instead, and tolerate the lease rejecting on its own. + void lease.then( + (late) => { + late.release(true); + }, + () => undefined, + ); + throw error; + } + let overran = false; try { return await withDeadline(client.query(text, [...values]), timeoutMs, what); @@ -503,7 +531,7 @@ export async function withTestDatabase( let result!: T; try { - await admin.query(`CREATE DATABASE "${database}"`); + await boundedQuery(admin, CREATE_TIMEOUT_MS, 'create', `CREATE DATABASE "${database}"`); const databaseUrl = urlForDatabase(connectionString, database); pool = createPool({ connectionString: databaseUrl, max: options.max ?? 4 }); clients = trackClients(pool); From b8b4232fe21baeb5446e51e42e9d9d658d55f7ec Mon Sep 17 00:00:00 2001 From: Hussein Mohamed Date: Fri, 4 Sep 2026 03:21:33 +0300 Subject: [PATCH 11/11] fix(persistence-test): stop binding admin acquisition to the teardown budget MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both reviewers found this independently, and it is the same hazard this branch already backed out of once in another form. An earlier revision applied `teardownTimeoutMs` as a `statement_timeout` on the admin pool and had to drop that because the same pool runs `CREATE DATABASE`. The `connectionTimeoutMillis` left behind did exactly the same thing to acquisition: tests here pass `teardownTimeoutMs: 300` to exercise the timeout path, so setup connections were capped at 300ms and creation could fail on a loaded server before the callback ever ran — with `CREATE_TIMEOUT_MS` of 30s never getting a say. Removed rather than raised to a floor. It was redundant as well as harmful: every `admin.connect()` in this file goes through `boundedQuery`, which already bounds acquisition with the budget belonging to that operation — 30s for creation, the teardown budget for teardown. A second pool-level bound could only ever disagree with the right one. Persistence 173/173, api 975, full suite green on a fresh PostgreSQL 16.14, no databases left behind, six guards pass, counts 3270, mutations 10 of 14. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01CUPqvu66J5ZVyiv4nJ797r --- .../persistence/src/test-support/database.ts | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/packages/persistence/src/test-support/database.ts b/packages/persistence/src/test-support/database.ts index f34f9082..5ce2e84d 100644 --- a/packages/persistence/src/test-support/database.ts +++ b/packages/persistence/src/test-support/database.ts @@ -126,13 +126,12 @@ async function reportTimeoutAfterForcedDrop( } /** - * Bound on creating the disposable database. + * Bound on creating the disposable database, covering both its connection and its statement. * - * Deliberately generous, and deliberately *not* `teardownTimeoutMs`. `connectionTimeoutMillis` - * bounds acquiring a connection, not a query on one already established, so a stalled server could - * otherwise hold this await open forever — before the callback runs and before there is any cleanup - * to start. It is separate from the teardown budget because tests set that as low as 300ms to - * exercise the timeout path, and creation has nothing to do with how long teardown may wait. + * Deliberately generous, and deliberately *not* `teardownTimeoutMs`: creation happens before the + * callback runs and before there is any cleanup to start, so it has nothing to do with how long + * teardown may wait. Tests here set the teardown budget as low as 300ms to exercise the timeout + * path, and creation held to that would fail on a loaded server rather than on a real fault. */ const CREATE_TIMEOUT_MS = 30_000; @@ -518,7 +517,13 @@ export async function withTestDatabase( // teardown was trying to report. This exists only for a server that has stopped answering, where // nothing else would ever return. const teardownBackstopMs = teardownTimeoutMs * 2 + 1_000; - const admin = createPool({ connectionString, max: 2, connectionTimeoutMillis: teardownTimeoutMs }); + // No pool-level `connectionTimeoutMillis`. It would apply to *every* acquisition on this pool, + // including the one `boundedQuery` makes for `CREATE DATABASE` — which runs before the callback + // and has nothing to do with how long teardown may wait. Tests here pass `teardownTimeoutMs: 300` + // to exercise the timeout path, so binding acquisition to it would cap setup at 300ms and fail + // creation on a loaded server. It is also redundant: every `admin.connect()` in this file goes + // through `boundedQuery`, which bounds acquisition with the budget belonging to that operation. + const admin = createPool({ connectionString, max: 2 }); // Hoisted so the last-resort drop can route through `forceDropAbandoned`: that drop is a forced // one too, and it terminates the same connections, so it owes them the same listener. let pool: Pool | undefined;