diff --git a/.env.example b/.env.example index 33f385e..399b03e 100644 --- a/.env.example +++ b/.env.example @@ -7,6 +7,29 @@ DATABASE_URL= # Separate test database (platform_test_ — SPEC.md §6) DATABASE_URL_TEST= +# The web process's database deadlines (#172). All optional: leaving one blank +# keeps the number in src/db/client.ts, sized for dev's one-core instance +# shared by dev and every open preview. Production's managed database (#24) is +# another machine with another connection cap and sets its own. Whole numbers +# only, at most 2147483647. The scripts (seed, import, backfill) ignore these +# and run without deadlines — a migration or an import cut off halfway is +# worse than a slow one. +# Connections this container may hold at once. At least 1. +DB_POOL_MAX= +# How long a request waits for a free connection before it is answered with +# an error. At least 1: without a bound it waits for ever, which is the bug +# this set of variables exists to keep fixed. +DB_CONNECT_TIMEOUT_MS= +# How long one statement may run before the server cuts it off. 0 does not +# mean "no bound" — it means the server's own setting stands, which is 0 on +# our PostgreSQL but need not be on a managed one. +DB_STATEMENT_TIMEOUT_MS= +# How long one statement may wait for a lock another transaction holds. +DB_LOCK_TIMEOUT_MS= +# How long a transaction may sit between statements before the server ends the +# session. It still holds every lock it has taken while it sits there. +DB_IDLE_TX_TIMEOUT_MS= + # SSH target of the dev instance for the tunnel, e.g. ubuntu@ DEV_SSH_HOST= # Hostname the dev deployment answers on (SPEC §8). Leave empty and diff --git a/SPEC.md b/SPEC.md index 680a749..5569a23 100644 --- a/SPEC.md +++ b/SPEC.md @@ -337,6 +337,19 @@ export function ownerKey( plain Docker image). The one line worth paying from day one is the managed database, and not for performance: prod holds real accounts and photos, so someone else's backups and patching is the product being bought. To settle with #24. +- **Every wait on the database has a deadline, and each environment sets its own** (#172): + the pool answers a caller it cannot give a connection to within five seconds instead of + queueing them for ever, and the server cuts off a statement that runs past ten seconds or + waits past three for a lock. The numbers live in `src/db/client.ts`, sized for dev's one + core shared by dev and every preview, and each is an environment variable (`DB_POOL_MAX`, + `DB_CONNECT_TIMEOUT_MS`, `DB_STATEMENT_TIMEOUT_MS`, `DB_LOCK_TIMEOUT_MS`, + `DB_IDLE_TX_TIMEOUT_MS`) because prod's managed database is another machine with another + cap. They travel in the connection, not in `DATABASE_URL`, so a migration or a script is + never cut off by a bound meant for a page — the scripts ignore those variables entirely. + The migration runner keeps one bound of its own, and it guards the site rather than the + migration: five seconds of waiting for a lock, because the old container is still serving + and a migration queueing for `ACCESS EXCLUSIVE` queues every reader of that table behind + itself. - Outside prod (`APP_ENV` other than `production`): `X-Robots-Tag: noindex` (A7) — set on every response by `src/proxy.ts`; the deployment provides `APP_ENV`. - One time zone for the whole interface: `Europe/Warsaw` (next-intl `timeZone`; decision of diff --git a/deploy/migrate.mjs b/deploy/migrate.mjs index 84616b4..1bba48e 100644 --- a/deploy/migrate.mjs +++ b/deploy/migrate.mjs @@ -38,7 +38,23 @@ const folder = path.join( const pending = readdirSync(folder).filter((name) => name.endsWith(".sql")); console.log(`${pending.length} migration file(s) in the image`); -const pool = new Pool({ connectionString: url }); +// #172 deliberately does not reach this file: the web deadlines +// (statement_timeout, lock_timeout) live in the pool src/db/client.ts opens, +// not in DATABASE_URL, precisely so a migration is never cut off half-applied +// by a bound meant for a page. The one bound worth having here is the +// opposite one — a database that cannot be reached should fail the deploy +// rather than hold it open for ever. +// The lock bound is the exception, and it guards the SITE rather than the +// migration: the old container is still serving while this runs, and a +// migration waiting for ACCESS EXCLUSIVE queues every reader of that table +// behind itself. Better to fail the deploy in five seconds — old container +// serving, old schema untouched — than to stall the site for as long as +// whatever holds the table. +const pool = new Pool({ + connectionString: url, + connectionTimeoutMillis: 30_000, + lock_timeout: 5_000, +}); try { // Drizzle records what it has applied in its own table and skips those, so // this is safe to run on every deploy — including one that changes nothing. diff --git a/scripts/backfill-file-keys.ts b/scripts/backfill-file-keys.ts index 9e7704c..04e49fa 100644 --- a/scripts/backfill-file-keys.ts +++ b/scripts/backfill-file-keys.ts @@ -1,6 +1,6 @@ import { eq, isNull } from "drizzle-orm"; import { alias } from "drizzle-orm/pg-core"; -import { getDb } from "@/db/client"; +import { getDb, runAsBatchJob } from "@/db/client"; import { files } from "@/db/schema"; import { requireEnv } from "@/lib/env"; import { contentKey, keyPrefix } from "@/lib/storage"; @@ -46,6 +46,8 @@ function assertLocalTarget(url: string, allowRemote: boolean): void { } async function main(): Promise { + // #172: one pass over every file row, allowed to take as long as it takes. + runAsBatchJob(); loadDotEnv(); const url = requireEnv("DATABASE_URL"); assertLocalTarget(url, process.argv.includes("--allow-remote")); diff --git a/scripts/import-teryt.ts b/scripts/import-teryt.ts index 7f213cd..07e1a60 100644 --- a/scripts/import-teryt.ts +++ b/scripts/import-teryt.ts @@ -1,6 +1,6 @@ import { readFileSync } from "node:fs"; import { sql } from "drizzle-orm"; -import { getDb, type Database } from "@/db/client"; +import { getDb, runAsBatchJob, type Database } from "@/db/client"; import { places } from "@/db/schema"; import { requireEnv } from "@/lib/env"; import { @@ -106,6 +106,9 @@ export async function importPlaces( } async function main(argv: readonly string[]): Promise { + // #172: a hundred thousand places upserted in one statement is a batch job, + // not a web request. + runAsBatchJob(); loadDotEnv(); const target = new URL(requireEnv("DATABASE_URL")); const database = `${target.host}${target.pathname}`; diff --git a/scripts/seed.ts b/scripts/seed.ts index d1b11c6..79aaedb 100644 --- a/scripts/seed.ts +++ b/scripts/seed.ts @@ -1,4 +1,4 @@ -import { getDb } from "@/db/client"; +import { getDb, runAsBatchJob } from "@/db/client"; import { requireEnv } from "@/lib/env"; import { getStorage, isStorageConfigured, keyPrefix } from "@/lib/storage"; import { @@ -68,6 +68,9 @@ function printSummary(summary: SeedSummary, password: string): void { } async function main(argv: readonly string[]): Promise { + // #172: a seed writes fourteen accounts and their photos — long by the web + // deadlines' standards, and nobody is waiting on a page for it. + runAsBatchJob(); loadDotEnv(); // Sample accounts with one published password belong in dev and test // databases only. The loopback check below is the guard; this is the belt. diff --git a/src/db/client.test.ts b/src/db/client.test.ts new file mode 100644 index 0000000..ae2f1a4 --- /dev/null +++ b/src/db/client.test.ts @@ -0,0 +1,276 @@ +import { Pool } from "pg"; +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { + databaseStall, + deadlinesFor, + poolConfig, + runAsBatchJob, + watchPool, +} from "./client"; + +// #172. Two halves: what the pool is configured with (pure, runs everywhere) +// and what those settings actually do to a waiting statement — which only a +// real server can answer, so that half runs when DATABASE_URL_TEST is set +// (always in CI, through the tunnel locally). PGlite cannot stand in: it is +// one in-process connection, and every bound here is about the second one. + +const VARIABLES = [ + "DB_POOL_MAX", + "DB_CONNECT_TIMEOUT_MS", + "DB_STATEMENT_TIMEOUT_MS", + "DB_LOCK_TIMEOUT_MS", + "DB_IDLE_TX_TIMEOUT_MS", +]; + +beforeEach(() => { + // Vitest loads .env, and these variables are meant to be set — so a + // developer who has set one would otherwise fail the tests that assert the + // built-in numbers, for a reason that has nothing to do with the change. + for (const name of VARIABLES) vi.stubEnv(name, ""); +}); + +afterEach(() => { + vi.unstubAllEnvs(); +}); + +describe("the deadlines a web process runs under", () => { + it("bounds the wait for a connection, the statement and the lock", () => { + const config = poolConfig("web", "postgres://example/db"); + expect(config.max).toBe(10); + expect(config.connectionTimeoutMillis).toBe(5_000); + expect(config.statement_timeout).toBe(10_000); + expect(config.lock_timeout).toBe(3_000); + // A transaction that has gone quiet still holds its locks. + expect(config.idle_in_transaction_session_timeout).toBe(10_000); + }); + + it("takes its numbers from the environment, so production can differ", () => { + vi.stubEnv("DB_POOL_MAX", "40"); + vi.stubEnv("DB_STATEMENT_TIMEOUT_MS", "2500"); + expect(deadlinesFor("web")).toMatchObject({ + poolMax: 40, + statementMs: 2500, + // Untouched variables keep the built-in number. + connectMs: 5_000, + }); + }); + + it("keeps the idle-transaction bound when the statement bound is lifted", () => { + // One variable must not turn off two bounds: raising the statement bound + // to let a slow report through must not also let a transaction sit on its + // locks for ever. + vi.stubEnv("DB_STATEMENT_TIMEOUT_MS", "0"); + expect(deadlinesFor("web")).toMatchObject({ + statementMs: 0, + idleTxMs: 10_000, + }); + }); + + it("refuses a deadline that is not a whole number of milliseconds", () => { + vi.stubEnv("DB_CONNECT_TIMEOUT_MS", "5s"); + // Loud, like every other environment mistake here: a deadline that + // silently fell back to the default would be found the night it mattered. + expect(() => deadlinesFor("web")).toThrow(/DB_CONNECT_TIMEOUT_MS/); + }); + + it("refuses the values that look permissive and are not", () => { + // 0 connections becomes pg's default of 10, silently. + vi.stubEnv("DB_POOL_MAX", "0"); + expect(() => deadlinesFor("web")).toThrow(/DB_POOL_MAX/); + vi.unstubAllEnvs(); + // 0 here is the unbounded wait this whole issue is about. + vi.stubEnv("DB_CONNECT_TIMEOUT_MS", "0"); + expect(() => deadlinesFor("web")).toThrow(/DB_CONNECT_TIMEOUT_MS/); + vi.unstubAllEnvs(); + // Past setTimeout's ceiling Node fires after ONE millisecond, so "a big + // number meaning never" would refuse every queued caller instantly. + vi.stubEnv("DB_CONNECT_TIMEOUT_MS", "3000000000"); + expect(() => deadlinesFor("web")).toThrow(/DB_CONNECT_TIMEOUT_MS/); + vi.unstubAllEnvs(); + // Number("0x10") is 16 — a typo that quietly means something else. + vi.stubEnv("DB_POOL_MAX", "0x10"); + expect(() => deadlinesFor("web")).toThrow(/DB_POOL_MAX/); + }); + + it("names the connection after the environment holding it", () => { + vi.stubEnv("S3_PREFIX", "pr-170/"); + // dev and every preview share one database (#113); pg_stat_activity has + // to say which of them is queueing. + expect(poolConfig("web", "postgres://example/db").application_name).toBe( + "platform-lite/pr-170/web", + ); + }); +}); + +describe("the deadlines a batch job runs under", () => { + it("lets the work take as long as it takes", () => { + const { statementMs, lockMs, connectMs } = deadlinesFor("batch"); + // 0 leaves the server's own setting standing — 0 on ours. A seed, an + // import or a backfill must never be cut off halfway by a number chosen + // for a page. + expect(statementMs).toBe(0); + expect(lockMs).toBe(0); + // It still gives up on a database that cannot be reached at all. + expect(connectMs).toBeGreaterThan(0); + }); + + it("ignores the variables an environment sets for its web process", () => { + vi.stubEnv("DB_STATEMENT_TIMEOUT_MS", "10000"); + vi.stubEnv("DB_LOCK_TIMEOUT_MS", "3000"); + // Otherwise the opt-out would be defeated by the very variables this + // change introduces: `pnpm db:import-teryt` upserts a hundred thousand + // places in one statement, and ten seconds would roll it back. + expect(deadlinesFor("batch")).toMatchObject({ + statementMs: 0, + lockMs: 0, + }); + }); + + it("refuses to put a server's own pool on those deadlines", () => { + vi.stubEnv("NEXT_RUNTIME", "nodejs"); + expect(() => runAsBatchJob()).toThrow(/scripts/); + }); +}); + +describe("reading a failure", () => { + it("recognises each bound by the code PostgreSQL raises", () => { + expect( + databaseStall(Object.assign(new Error("x"), { code: "57014" })), + ).toBe("statement-timeout"); + expect( + databaseStall(Object.assign(new Error("x"), { code: "55P03" })), + ).toBe("lock-timeout"); + expect( + databaseStall(Object.assign(new Error("x"), { code: "25P03" })), + ).toBe("idle-transaction"); + }); + + it("recognises the pool's own refusal to wait any longer", () => { + expect( + databaseStall(new Error("timeout exceeded when trying to connect")), + ).toBe("no-connection"); + }); + + it("looks through the wrapper drizzle puts around driver errors", () => { + const wrapped = new Error("Failed query: select 1", { + cause: Object.assign(new Error("canceling statement"), { code: "57014" }), + }); + expect(databaseStall(wrapped)).toBe("statement-timeout"); + }); + + it("gives up on a cause chain that points back at itself", () => { + // This runs on the failure path of every request, on one core: a chain + // with a loop in it must end the walk, not the process. + const first = new Error("first"); + const second = new Error("second", { cause: first }); + (first as { cause?: unknown }).cause = second; + expect(databaseStall(first)).toBeNull(); + }); + + it("says nothing about failures that are not a deadline", () => { + expect(databaseStall(new Error("duplicate key value"))).toBeNull(); + expect(databaseStall("not an error")).toBeNull(); + }); +}); + +const url = process.env.DATABASE_URL_TEST?.trim(); + +describe.skipIf(!url)("against a real PostgreSQL", () => { + const open: Pool[] = []; + + function pool(overrides: Record): Pool { + for (const [name, value] of Object.entries(overrides)) { + vi.stubEnv(name, value); + } + const created = watchPool(new Pool(poolConfig("web", url!))); + open.push(created); + return created; + } + + afterEach(async () => { + await Promise.all(open.splice(0).map((created) => created.end())); + }); + + it("cuts off a statement waiting on a lock somebody else holds", async () => { + const holder = pool({ DB_LOCK_TIMEOUT_MS: "0" }); + const held = await holder.connect(); + try { + await held.query("begin"); + await held.query("select pg_advisory_xact_lock(20260912)"); + + const waiter = pool({ DB_LOCK_TIMEOUT_MS: "300" }); + // Taken inside a transaction, as lib/works.ts takes it: this is the + // per-user advisory lock every write in the app goes through, and that + // lock_timeout covers an ADVISORY lock at all is the one thing here + // worth measuring rather than assuming. + const failure = await waiter + .query("begin; select pg_advisory_xact_lock(20260912)") + .then(() => null) + .catch((error: unknown) => error); + expect(databaseStall(failure)).toBe("lock-timeout"); + + await held.query("rollback"); + } finally { + // Released whatever the assertions did: an outstanding client would + // make pool.end() in afterEach wait for a client that never comes back, + // and the suite would time out instead of reporting the failure. + held.release(); + } + }); + + it("cuts off a statement that simply runs too long", async () => { + const slow = pool({ DB_STATEMENT_TIMEOUT_MS: "300" }); + const failure = await slow + .query("select pg_sleep(5)") + .then(() => null) + .catch((error: unknown) => error); + expect(databaseStall(failure)).toBe("statement-timeout"); + }); + + it("answers the caller that cannot get a connection instead of queueing it", async () => { + const crowded = pool({ DB_POOL_MAX: "1", DB_CONNECT_TIMEOUT_MS: "300" }); + const taken = await crowded.connect(); + try { + const started = Date.now(); + // Before #172 this call waited for as long as the holder kept the + // connection — for ever, if that was a statement nothing cut off. + const failure = await crowded + .query("select 1") + .then(() => null) + .catch((error: unknown) => error); + expect(databaseStall(failure)).toBe("no-connection"); + expect(Date.now() - started).toBeLessThan(5_000); + } finally { + taken.release(); + } + }); + + it("survives the server killing a transaction that went quiet", async () => { + const said: string[] = []; + const logged = vi + .spyOn(console, "error") + .mockImplementation((...parts: unknown[]) => { + said.push(parts.join(" ")); + }); + const napping = pool({ DB_IDLE_TX_TIMEOUT_MS: "300" }); + const client = await napping.connect(); + try { + await client.query("begin"); + await new Promise((wake) => setTimeout(wake, 1_000)); + // The point of the test is not this rejection. It is that the process + // is still here to make it: the kill arrives on a client the pool has + // checked out, whose own error listener pg-pool removed, and an 'error' + // event with no listener ends the process. Measured 12.09.2026 — the + // guard in watchPool is what this reaches. + const failure = await client + .query("select 1") + .then(() => null) + .catch((error: unknown) => error); + expect(failure).toBeInstanceOf(Error); + expect(said.join("\n")).toContain("idle-transaction"); + } finally { + client.release(); + logged.mockRestore(); + } + }); +}); diff --git a/src/db/client.ts b/src/db/client.ts index fff280d..87c08f5 100644 --- a/src/db/client.ts +++ b/src/db/client.ts @@ -1,6 +1,6 @@ import { drizzle } from "drizzle-orm/node-postgres"; import type { PgDatabase, PgQueryResultHKT } from "drizzle-orm/pg-core"; -import { Pool } from "pg"; +import { Pool, type PoolConfig } from "pg"; import { requireEnv } from "@/lib/env"; import * as schema from "./schema"; @@ -9,15 +9,284 @@ import * as schema from "./schema"; // the same drizzle surface either way. export type Database = PgDatabase; +/** + * What the process holding the pool is doing (#172). + * + * `web` answers a visitor: every bound is short, because a page that has not + * answered in a few seconds has already failed as far as they are concerned, + * and the connection it is holding is one of ten. + * + * `batch` is a script (scripts/*.ts): a seed, a TERYT import, a backfill. + * It is allowed to take its time — a statement timeout sized for a web + * request would cut an import off halfway through, which is the one failure + * worse than a slow one. + */ +export type DatabaseUse = "web" | "batch"; + +interface Deadlines { + /** Connections this process may hold at once. */ + poolMax: number; + /** How long a caller waits for a free connection before it is told no. */ + connectMs: number; + /** How long one statement may run. */ + statementMs: number; + /** How long one statement may wait for a lock. */ + lockMs: number; + /** How long a transaction may sit between statements, holding its locks. */ + idleTxMs: number; +} + +// 0 on the three server-side bounds does NOT mean "off": pg only puts a +// setting in the startup packet when it is truthy (pg/lib/client.js), so 0 +// means "send nothing, the server's own setting stands". On ours that setting +// is 0, which is off — but a managed database (#24) may well ship a role-level +// statement_timeout, and a batch job there would inherit it. Read 0 as +// "inherit", and check what is inherited when production exists. + +// Dev's numbers, chosen for the shape of dev: one core, one containerised +// PostgreSQL with max_connections 100, and dev plus every open preview +// sharing it with a pool each (#31, #113). Production's managed database +// (#24) is another machine with another cap and sets its own through the +// environment — which is why each of these is a variable and not a constant. +// +// The web numbers, and why: the app's statements are all small (a profile, a +// page of works, one reorder), so ten seconds is not a slow query, it is a +// stuck one. Three seconds of waiting for a lock is a queue forming behind +// another writer — answering then beats joining it. +const DEADLINES: Record = { + web: { + poolMax: 10, + connectMs: 5_000, + statementMs: 10_000, + lockMs: 3_000, + idleTxMs: 10_000, + }, + batch: { + poolMax: 4, + connectMs: 30_000, + statementMs: 0, + lockMs: 0, + idleTxMs: 0, + }, +}; + +// setTimeout's ceiling. Past it Node warns and fires after ONE millisecond — +// so an operator reaching for a large finite number as "effectively never" +// would make every queued checkout fail instantly, and the log would blame +// the database. Refused instead. +const MAX_MS = 2_147_483_647; + +// Fail loud, like requireEnv: a mistyped deadline that silently fell back to +// the default would be discovered the night it was needed. Decimal digits +// only — Number("0x10") is 16, and a typo that quietly means something else +// is worse than one that stops the process. +function readOverride(name: string, fallback: number, least = 0): number { + const raw = process.env[name]?.trim(); + if (!raw) return fallback; + const value = Number(raw); + if (!/^\d+$/.test(raw) || value < least || value > MAX_MS) { + throw new Error( + `${name} must be a whole number between ${least} and ${MAX_MS}, not "${raw}"`, + ); + } + return value; +} + +export function deadlinesFor(use: DatabaseUse): Deadlines { + const defaults = DEADLINES[use]; + // A batch job takes the built-in numbers and nothing else. These variables + // belong to the WEB process of an environment; a seed or an import that + // inherited a web statement timeout would be cut off halfway through, which + // is the whole reason the opt-out exists. + if (use === "batch") return defaults; + return { + // Never 0: a pool of 0 silently becomes pg's default of 10, and a connect + // deadline of 0 is the unbounded wait this issue is about. + poolMax: readOverride("DB_POOL_MAX", defaults.poolMax, 1), + connectMs: readOverride("DB_CONNECT_TIMEOUT_MS", defaults.connectMs, 1), + statementMs: readOverride("DB_STATEMENT_TIMEOUT_MS", defaults.statementMs), + lockMs: readOverride("DB_LOCK_TIMEOUT_MS", defaults.lockMs), + // Its own variable, not the statement bound reused: raising the statement + // bound to let one slow report through must not also let a transaction + // sit on its locks for ever. + idleTxMs: readOverride("DB_IDLE_TX_TIMEOUT_MS", defaults.idleTxMs), + }; +} + +/** + * The pool's configuration, spelled out (#172). + * + * The two server-side bounds travel in the connection's startup packet, NOT + * in DATABASE_URL — deliberately. The same address is used by the migration + * runner (deploy/migrate.mjs), by psql and by the scripts, and a migration + * that hit a web statement timeout would leave a half-applied schema behind. + * Putting them here means only what opens a pool through this module is + * bound, and each kind of process gets its own numbers. + */ +export function poolConfig( + use: DatabaseUse, + connectionString: string, +): PoolConfig { + const { poolMax, connectMs, statementMs, lockMs, idleTxMs } = + deadlinesFor(use); + return { + connectionString, + max: poolMax, + // Without this the eleventh caller waits for ever: pg's default is 0, + // and 0 means no deadline at all. This is the whole of #172 in one line. + connectionTimeoutMillis: connectMs, + // A connection nobody has used for half a minute is given back. Previews + // come and go all day and each holds its own pool against dev's single + // PostgreSQL; idle connections there are pure occupancy. + idleTimeoutMillis: 30_000, + statement_timeout: statementMs, + lock_timeout: lockMs, + // A transaction left open with nothing happening in it still holds every + // lock it has taken. Nothing here does I/O inside a transaction, so a gap + // that long means the caller is gone. + idle_in_transaction_session_timeout: idleTxMs, + // Who is holding the connection, as pg_stat_activity will show it: dev + // and every preview share one database (#113), so "one of them is + // queueing" is only actionable if the row says which. + application_name: connectionLabel(use), + }; +} + +// The environment's own name, taken from the prefix it already scopes its +// objects with (SPEC §4): "devski/" → devski, "pr-170/" → pr-170, blank in +// production. +function connectionLabel(use: DatabaseUse): string { + const environment = + process.env.S3_PREFIX?.trim().replace(/\/+$/, "") || + process.env.APP_ENV?.trim() || + "local"; + return `platform-lite/${environment}/${use}`; +} + let db: Database | undefined; +let poolUse: DatabaseUse = "web"; + +/** + * Declares this process a batch job (#172) — a script that may take as long + * as its work takes. Call it before the first getDb(); afterwards the pool is + * already open with the web deadlines and the call would be a lie, so it + * throws rather than pretend. + */ +export function runAsBatchJob(): void { + if (process.env.NEXT_RUNTIME) { + throw new Error( + "runAsBatchJob() is for scripts/*: a server must not put the pool its pages use on the batch deadlines (#172)", + ); + } + if (db) { + throw new Error( + "the database pool is already open — runAsBatchJob() belongs before the first getDb()", + ); + } + poolUse = "batch"; +} // Lazy on purpose: importing this module must stay side-effect free so route // modules can be evaluated at build time (and by the DB-less e2e job) without // DATABASE_URL; the first query is where a missing variable fails loudly. export function getDb(): Database { - if (!db) { - const pool = new Pool({ connectionString: requireEnv("DATABASE_URL") }); - db = drizzle({ client: pool, schema }) as Database; - } + db ??= openPool(poolUse); return db; } + +let backgroundDb: Database | undefined; + +/** + * A second pool, for work that runs inside the server but is answering + * nobody: today the R360 collector's sweep (#127, #156), which reads every + * file row to find objects no record names. + * + * It has to be a pool of its own, because the deadlines are a property of the + * connection and the collector shares this process with the pages. Under the + * web bound its sweep would not fail loudly, it would return "nothing found" + * as the table grows — and nothing tells that apart from a clean bucket. + */ +export function getBackgroundDb(): Database { + backgroundDb ??= openPool("batch"); + return backgroundDb; +} + +function openPool(use: DatabaseUse): Database { + const pool = watchPool(new Pool(poolConfig(use, requireEnv("DATABASE_URL")))); + return drizzle({ client: pool, schema }) as Database; +} + +/** + * Both listeners a pool of ours must carry, and the second is not the first + * one written twice. + * + * pg-pool's own listener watches a connection sitting IDLE IN THE POOL, and + * it takes that listener off the client the moment the client is checked out. + * So a connection the server kills while somebody holds it — an + * idle-in-transaction kill, a restart, the tunnel dropping — arrives at a + * client with no listener at all, and Node turns an 'error' event with no + * listener into a crashed process. + * + * Measured on 12.09.2026 against dev's PostgreSQL: with only the pool + * listener the process exits on the idle-in-transaction kill; with the client + * listener the query rejects and the request fails on its own. + */ +export function watchPool(pool: Pool): Pool { + pool.on("error", (error) => { + console.error( + `[db] an idle connection failed (${databaseStall(error) ?? "no bound"}):`, + error.message, + ); + }); + pool.on("connect", (client) => { + client.on("error", (error) => { + console.error( + `[db] a connection in use failed (${databaseStall(error) ?? "no bound"}):`, + error.message, + ); + }); + }); + return pool; +} + +/** + * The bound a failure ran into, or null for everything else (#172). + * + * These four are the ones nobody could see before: each one used to be an + * unbounded wait, and in the log they all looked like a request that never + * came back. Drizzle wraps driver errors and keeps the original in `cause`, + * so the chain is walked rather than the top. + */ +export type DatabaseStall = + "no-connection" | "statement-timeout" | "lock-timeout" | "idle-transaction"; + +// SQLSTATEs, from PostgreSQL's errcodes table. +const STALL_BY_CODE: Record = { + // query_canceled — what statement_timeout raises (also a hand cancel). + "57014": "statement-timeout", + // lock_not_available — what lock_timeout raises. + "55P03": "lock-timeout", + // idle_in_transaction_session_timeout — the session was terminated. + "25P03": "idle-transaction", +}; + +// pg-pool's own wording when connectionTimeoutMillis runs out; there is no +// code on that one, it is an Error the pool makes itself. +const NO_CONNECTION = "timeout exceeded when trying to connect"; + +export function databaseStall(error: unknown): DatabaseStall | null { + // Bounded: a cause chain that points back at itself would otherwise spin + // for ever, and this runs on the failure path of every request. + for ( + let current: unknown = error, links = 0; + current instanceof Error && links < 16; + current = current.cause, links++ + ) { + const code = (current as { code?: unknown }).code; + if (typeof code === "string" && code in STALL_BY_CODE) { + return STALL_BY_CODE[code]; + } + if (current.message.includes(NO_CONNECTION)) return "no-connection"; + } + return null; +} diff --git a/src/instrumentation.ts b/src/instrumentation.ts index 2f3abd3..8f75cc3 100644 --- a/src/instrumentation.ts +++ b/src/instrumentation.ts @@ -20,7 +20,7 @@ export async function register() { appEnv: process.env.APP_ENV, collect: async () => { const [ - { getDb }, + { getBackgroundDb }, { getStorage, keyPrefix }, { collectAllUnfinishedFrameSets, unrecordedFrameSets }, ] = await Promise.all([ @@ -29,7 +29,11 @@ export async function register() { import("@/lib/r360/frame-set"), ]); const deps = { - db: getDb(), + // #172: its own pool, without the web deadlines. This sweep reads + // every file row, and under a statement bound it would stop + // reporting rather than fail — "nothing found" and "nothing looked" + // read the same in a log. + db: getBackgroundDb(), storage: getStorage(), prefix: keyPrefix(), }; @@ -50,3 +54,33 @@ export async function register() { console.error("[r360] collector: the schedule did not start", error); } } + +// #172: the one place every server-side failure passes through (the +// `onRequestError` half of the instrumentation file convention). It exists +// for one line of log — the database deadlines answer with an error now +// instead of waiting for ever, and an operator reading the log has to be able +// to tell that from a request that was merely slow. Everything else Next +// already prints; this adds a name to the four bounds #172 introduced. +export async function onRequestError( + error: unknown, + request: { path: string; method: string }, +) { + // Nothing in here may throw: this hook runs while a request is already + // failing, and a failure of its own would replace the error somebody needs + // to read with the error of the thing meant to explain it. + try { + const { databaseStall } = await import("@/db/client"); + const stall = databaseStall(error); + if (!stall) return; + // The path, not the request target Next hands over: that one carries the + // query string, and a verification or reset token lives there. Those are + // hashed at rest (lib/auth.ts) precisely so a leaked store cannot redeem + // a live link — writing one into the log would undo that in another store. + const path = request.path.split("?")[0]; + console.error( + `[db] ${request.method} ${path} hit the ${stall} bound — the numbers are DB_* in .env.example (#172)`, + ); + } catch { + // Deliberately silent: Next has already reported the original error. + } +} diff --git a/src/lib/api-route.ts b/src/lib/api-route.ts index c6bd072..7bcbcf6 100644 --- a/src/lib/api-route.ts +++ b/src/lib/api-route.ts @@ -1,6 +1,7 @@ import { headers } from "next/headers"; import { NextResponse } from "next/server"; import type { z } from "zod"; +import { databaseStall } from "@/db/client"; import { getAuth } from "@/lib/auth"; import { appOrigin } from "@/lib/env"; @@ -15,7 +16,18 @@ export async function sessionUserId(): Promise { headers: await headers(), }); return session?.user.id ?? null; - } catch { + } catch (error) { + // Closed, but no longer silent (#172). Since the pool answers instead of + // queueing, a database in trouble arrives HERE — and signing everybody + // out is what that looks like from the outside. Nothing else would say so: + // this catch returns a value, so the request succeeds and Next's error + // path never runs. + const stall = databaseStall(error); + if (stall) { + console.error( + `[db] a session could not be read: the ${stall} bound — everyone reads as signed out while this lasts (#172)`, + ); + } return null; } } diff --git a/src/lib/auth.ts b/src/lib/auth.ts index ca3d37e..c1b5f9e 100644 --- a/src/lib/auth.ts +++ b/src/lib/auth.ts @@ -59,7 +59,10 @@ function withCallbackStatus(verifyUrl: string, status: string): string { const link = new URL(verifyUrl); const callbackURL = link.searchParams.get("callbackURL") ?? "/email-changed"; const separator = callbackURL.includes("?") ? "&" : "?"; - link.searchParams.set("callbackURL", `${callbackURL}${separator}status=${status}`); + link.searchParams.set( + "callbackURL", + `${callbackURL}${separator}status=${status}`, + ); return link.href; } @@ -131,6 +134,12 @@ export function createAuth(options: { telemetry: { enabled: false }, // #4 contract: no `fields` mappings — the adapter resolves by the TS // property names in schema.ts, which are the Better Auth defaults. + // + // No `transaction: true`, and that is load-bearing since #172: the + // library wraps sign-up in a transaction when the adapter says it can, + // and that wrapper would hold a connection across scrypt AND the e-mail + // provider's HTTP call — straight into the idle-transaction bound. With + // it off the wrapper is a pass-through and nothing pins a connection. database: drizzleAdapter(db, { provider: "pg", usePlural: true, schema }), advanced: { // §9: ids come from the database (gen_random_uuid()), never the app. @@ -311,7 +320,9 @@ export function createAuth(options: { const callbackURL = requestUrl.searchParams.get("callbackURL"); if ( callbackURL && - ctx.context.isTrustedOrigin(callbackURL, { allowRelativePaths: true }) + ctx.context.isTrustedOrigin(callbackURL, { + allowRelativePaths: true, + }) ) { const target = new URL(callbackURL, ctx.context.baseURL); target.searchParams.set("error", "INVALID_TOKEN"); diff --git a/tasks/plan.md b/tasks/plan.md index f53ecb2..a7e2afb 100644 --- a/tasks/plan.md +++ b/tasks/plan.md @@ -90,13 +90,22 @@ in under 5 minutes (manual walkthrough); e2e green. and someone is there to reason about it. - [#111](https://github.com/Devski/platform-lite/issues/111) Preview cleanup loses the race with a CI run still in flight, and the orphan blocks the two-preview cap (`bug`). -- [#172](https://github.com/Devski/platform-lite/issues/172) The database has no deadlines - (`infra`, `deployment`). Found 12.09.2026 in the security review of #66: the pool is built - with pg's defaults, so `connectionTimeoutMillis` is 0 — a request waiting for a free - connection waits for ever — and neither `statement_timeout` nor `lock_timeout` is set - anywhere, on either side. Every limit in this system is a rate limit on the way IN; past - it, nothing bounds how long a request holds a connection or a lock, so contention queues - silently instead of failing with something to read. +- ~~[#172](https://github.com/Devski/platform-lite/issues/172) The database has no deadlines~~ + — **done 12.09.2026**. Found in the security review of #66: the pool was built with pg's + defaults, so `connectionTimeoutMillis` was 0 — a request waiting for a free connection + waited for ever — and neither `statement_timeout` nor `lock_timeout` was set anywhere, on + either side. Now the pool says how many connections it may hold, waits five seconds for a + free one and then answers, and the server cuts off a statement that runs past ten seconds + or waits past three for a lock. Each number is an environment variable, because prod's + managed database (#24) is another machine with another cap, and they travel in the + connection rather than in `DATABASE_URL`: a migration or a seed must never be cut off by a + bound meant for a page, so the scripts declare themselves batch jobs and run without them. + Proven against a real PostgreSQL — including that `lock_timeout` does cover the advisory + lock every write in this app takes, which was worth measuring rather than assuming. The + review found the sting in the tail: the new idle-transaction bound kills a connection + somebody is holding, and pg-pool takes its own error listener off a connection while it is + checked out — so without a listener of ours the kill ended the PROCESS. Measured, fixed, + and the test fails without the fix. - [#119](https://github.com/Devski/platform-lite/issues/119) The dev instance keeps every image it ever pulled (`infra`). Filed 09.09.2026 when its root filesystem reached 100%: 129 images, 21.8 GB, three of them in use. Previews stopped starting at all, and dev's