Deadlines on every wait for the database (#172) - #178
Merged
Conversation
The pool was built with pg's defaults, which meant the one that matters was absent: connectionTimeoutMillis 0, a caller waiting for a free connection waiting for ever. Nothing set statement_timeout or lock_timeout either, on the client or on the server, so contention queued where nobody could see it. Now the pool states what it holds and how long anything may wait, 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: dev is one core shared by dev and every preview, and prod's managed database (#24) is another machine with another cap. They travel in the connection's startup packet, not in DATABASE_URL, because the same address belongs to the migration runner, psql and the scripts — a migration cut off half-applied by a bound meant for a page is worse than a slow one. The scripts say so out loud (runAsBatchJob) and run without them. Proven against a real PostgreSQL rather than asserted, including that lock_timeout does cover the advisory lock every write in this app takes. A failure now carries the name of the bound it hit, and onRequestError puts that name in the log — a stall used to look exactly like a slow request. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The idle-transaction bound could kill the process. pg-pool takes its own error listener off a connection while somebody holds it, so a connection the server ends mid-transaction reaches a client with no listener at all — and Node turns that into an exit, not a log line. Measured against dev's PostgreSQL: without the listener added here the process exits, with it the query rejects and the request fails on its own. The test fails without the fix. The batch escape hatch was defeated by the very variables this change adds: a seed or an import would have inherited the web statement timeout from the environment's .env. A batch job now takes the built-in numbers and nothing else, and a server is refused the batch deadlines outright. The collector kept the web bound it cannot live under. It runs inside the server, so it could not opt out — and its sweep over every file row would not have failed loudly, it would have started reporting "nothing found" as the table grew. It gets a pool of its own. Also: the idle bound has its own variable, so lifting the statement bound no longer lifts it too; the reader refuses 0, hexadecimal, and numbers past setTimeout's ceiling, where a value meant as "never" fires after one millisecond; the cause walk is capped, so a chain pointing at itself ends the walk and not the core; the logged path drops its query string, where a verification token lives; a session read that fails on a bound says so, because signing everyone out silently is what a stalled database looks like from the outside; and the migration runner gets a five-second lock bound — that one guards the site, not the migration, because a migration queueing for ACCESS EXCLUSIVE queues every reader behind it while the old container serves. Two tails filed rather than smuggled in: #179 (anonymous renders have no cache and no per-address limit) and #180 (three queries that scan a whole table). Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closes #172.
Every wait on the database had no end to it.
src/db/client.tsbuilt the poolwith a connection string and nothing else, so pg's defaults stood — and the
default for
connectionTimeoutMillisis 0, which means a caller waiting for afree connection waits for ever. Neither
statement_timeoutnorlock_timeoutwas set on either side. Contention therefore queued where nothing could be
read: no error, no log line, a page that simply never came back.
What this changes
max,connectionTimeoutMillis(5 s),idleTimeoutMillis, with the reasoning next to each number.statement_timeout10 s,lock_timeout3 s, andidle_in_transaction_session_timeoutat the samebound as a statement, because a transaction gone quiet still holds its locks.
DB_POOL_MAX,DB_CONNECT_TIMEOUT_MS,DB_STATEMENT_TIMEOUT_MS,DB_LOCK_TIMEOUT_MS,documented in
.env.example. The built-in values are sized for dev's onecore, shared by dev and every open preview (PR preview deployments on the dev instance #31, PR previews: a database cloned from dev per preview, not the shared one #113); prod's managed
database (Production environment: instance, managed Postgres, prod bucket, CDN, G10 drill #24) is another machine with another cap and will set its own.
runAsBatchJob()in the threescripts (seed, TERYT import, file-key backfill). The migration runner needs
no opt-out at all, which is the point of the next item.
DATABASE_URL. The addressis shared by
deploy/migrate.mjs, psql and the scripts; a migration cut offhalf-applied by a bound meant for a page is worse than a slow migration. The
migration runner does gain the opposite bound — 30 s to reach the database at
all, so an unreachable one fails the deploy instead of holding it open.
databaseStall()reads the bound out of theerror (57014, 55P03, 25P03, and pg-pool's own connect-timeout message),
looking through the wrapper drizzle puts around driver errors, and
onRequestErrorwrites it to the log. A stall used to look exactly like aslow request.
application_namesays who is holding the connection —platform-lite/pr-170/web. Dev and every preview share one database, so"something is queueing" is only actionable if
pg_stat_activitysays which.errorlistener. Without one, an idle connection theserver drops arrives as an unhandled
'error'event — a crash, not a log.Decisions taken
Retry-After.The issue left it open. Nothing on the client retries, and inviting a retry
into a database that is already saturated is the wrong advice; what was
missing was an answer and a name in the log, and both are here.
idle_in_transaction_session_timeoutequals the statement bound. Notransaction in this codebase does I/O — the S3 calls are all outside — so a
gap inside one longer than a whole statement may run means the caller is gone.
Verification
pnpm checkgreen,pnpm buildgreen. The issue's verification list isautomated in
src/db/client.test.tsagainst a real PostgreSQL (the CI servicecontainer; the tunnel locally — PGlite cannot stand in, every bound here is
about the second connection):
advisory lock
lockUsertakes on every write, measured rather thanassumed, because the PostgreSQL documentation's "table, index, row, or other
database object" does not say it in so many words. It is
55P03after thelock bound, not the statement one.
pg_sleep) is cut off;🤖 Generated with Claude Code
What the two review lanes changed
One crash, and it was mine to introduce. The new
idle_in_transaction_session_timeoutends a connection while a caller holdsit, and pg-pool removes its own
errorlistener from a client for exactly aslong as that client is checked out. An
'error'event with no listener is aprocess exit in Node. Probed against dev's PostgreSQL: without a listener of
ours the process dies (exit 9,
terminating connection due to idle-in-transaction timeout), with it the query rejects and the request fails on its own. The newtest fails when the listener is removed — checked, not assumed.
Also fixed, all from the reviews:
environment's web process, and
.envis loaded by the scripts before thepool opens — so
DB_STATEMENT_TIMEOUT_MS=10000on the instance would haverolled back a TERYT import at ten seconds. Batch takes the built-in numbers
and nothing else, and a server is refused
runAsBatchJob()outright.could not opt out; under the web bound its sweep over every
filesrowwould not fail loudly, it would return "nothing found" as the table grew —
which reads exactly like a clean bucket.
DB_IDLE_TX_TIMEOUT_MSis its own variable, so lifting the statementbound for one slow report no longer also lets a transaction sit on its locks.
0for the pool(pg silently substitutes 10) or for the connect wait (that is the bug this
closes), hexadecimal (
0x10parses as 16), and anything past setTimeout'sceiling, where a number meant as "effectively never" fires after 1 ms.
every request, and a self-referential
causewould have spun the core.sessionUserId()catches and returns null, so a stalled database used to hang and now
silently signs everyone out — with nothing in the log, because the request
succeeds and Next's error path never runs.
deploy/migrate.mjsgains a five-secondlock_timeout. That one guardsthe site rather than the migration: the old container is still serving, and
a migration queueing for
ACCESS EXCLUSIVEqueues every reader of thattable behind itself.
0on a server-side bound means "the server's setting stands", not "off"— corrected in
.env.exampleand in the code, because a managed database(Production environment: instance, managed Postgres, prod bucket, CDN, G10 drill #24) may well ship a role-level
statement_timeout.Two findings were filed rather than folded in: #179 (anonymous renders
have no cache and no per-address limit, and the proxy's 1.5 s lookup keeps a
5 s place in the pool queue) and #180 (three queries that scan a whole
table, now under a deadline).