fix(control-pg): bound Postgres waits so a hung Postgres cannot freeze the engine

Merged
BN
6d ago
+821-70

Stacks on #685; retarget to main after it merges. The class branch moved three times while this was
open (its latest head merges main, which reorganized docs/); this branch is rebased onto its
current head, keeping both sides of the two conflicts: the CHANGELOG.md ### Fixed list (main's
new entries kept, this entry appended to them) and docs/setup.md, which main replaced — the
operator note now lives in docs/control-plane/operate/storage.mdx, next to the Postgres pool
paragraph it belongs with.

What was unbounded (at 44d51b523)

Audit rows #5 and #9 of the blocking-call sweep. Nothing in the Postgres path had a
deadline; the pool's 30 s bound covered only waiting for a free connection, never the database
itself.

#CallSite
5tokio_postgres::connect + batch_execute with no deadline — engine startup, both pools, and every dead-socket reconnect in checkoutcrates/preloop-runner-server/src/control/pg/mod.rs:358-377 (connect_one), Pool::open :72-76, checkout :99-106
5No statement_timeout, lock_timeout or idle_in_transaction_session_timeout anywhere: a statement stuck behind a lock, or a session left idle inside a transaction, could hold a runtime worker, a pooled connection and a run's row locks foreverstore_pg.rs:46-77
9connect + LISTEN with no deadline inside the reconnect loop: a database that accepts TCP and then stalls left the wake listener silently dead — no subscription, no error, no retry — until the process restartedcrates/preloop-runner-server/src/control/wake.rs:103-121, loop :79-95

tokio-postgres' own connect_timeout was not enough: it bounds only the TCP connect
(connect_socket), not the startup packet, TLS handshake or authentication after it.

Deadlines, and why those values

All in crates/preloop-runner-server/src/store_pg.rs, each with a doc comment carrying the
reasoning:

  • CONNECT_TIMEOUT = 10 s — one Postgres session becoming usable: resolution, TCP, TLS,
    authentication and the session SETs (open_session). A healthy connect is milliseconds
    (tens with TLS), so 10 s is ~1000× headroom; it matches the deadline the OS credential store
    already uses, so one stalled dependency is not bounded differently from another.
  • STATEMENT_TIMEOUT = 30 s — server-side. Control commands are one short transaction of
    targeted statements (conditional UPDATE, FOR UPDATE SKIP LOCKED claim, bounded reaper
    verdicts, statistics counts); real durations are milliseconds, and 30 s is also the pool's
    CHECKOUT_TIMEOUT, so a statement that reaches it means "stuck", not "busy".
  • LOCK_TIMEOUT = 15 s — server-side, half of the statement timeout so a lock wait is
    reported as a lock wait (canceling statement due to lock timeout) instead of being masked
    by the statement timeout. This is the incident's shape: a stuck transaction keeps its row
    locks and every command that needs the same run row queues behind it. Row-lock waits in
    production are millisecond-scale (control::txn_stats exists to record them).
  • IDLE_IN_TRANSACTION_TIMEOUT = 60 s — server-side. The incident itself began with
    Postgres killing idle-in-transaction sessions, so the value is now explicit and deterministic
    instead of whatever the server is configured with: far beyond the gap between two statements
    of a control command (no transaction in control/pg is held across an await of anything but
    its next statement), but a leaked transaction can no longer hold a run's row locks forever.
  • TCP keepalives (30 s idle, 10 s interval, 3 retries) in config() bound the peer that
    vanished without a FIN.

Migrations and admin work are not affected. store_admin's preloop store migrate
connection is built in store_admin.rs, never through control/pg::connect_one, so it carries
no serving guard. The one migration a serving process can run — test-support schema creation,
control/pg/mod.rs::create_control_schema — lifts the guards to migration-scoped values
(MIGRATION_STATEMENT_TIMEOUT 10 min, MIGRATION_LOCK_TIMEOUT 5 min) before it runs, which
also bounds the setup pg_advisory_lock wait that migrate_runner::initialize_empty_postgres
takes while another node migrates (Postgres applies lock_timeout to advisory locks; verified
on 18.3).

Duplication: the connect-with-deadline shape exists once, as store_pg::open_session (bounded
connect + driver wiring + bounded session SETs, one call site each in control/pg and
control/wake). It has no subprocess/blocking-thread work, so nothing in this slice belongs in
preloop_observability::deadline.

Tests

No test waits a production deadline (30 s of pg_sleep is not a test), so the deadline values
are covered two ways: the installed values are asserted on live sessions, and the mechanism
runs with short deadlines through the same builders.

  • control::pg::tests::a_stalled_database_ends_the_session_open_at_the_deadline — a TCP listener
    that accepts and never answers (no Postgres needed): the session open ends at the deadline,
    after the TCP connect was accepted, with an error naming Postgres and the deadline.
    Fail-before: the same listener against the pre-fix call shape (tokio_postgres::connect,
    no deadline) never returned; only an external 3 s timeout ended it. Removed after the check.
  • control::wake::tests::a_stalled_database_ends_the_listen_attempt_at_the_deadline — same
    listener, listen_once: the attempt ends at the deadline instead of hanging.
  • control::wake::tests::a_stalled_database_is_retried_not_silently_dead — with a short attempt
    deadline the loop accepts a second connection inside 2 s, i.e. it retries on backoff instead
    of staying silently dead (the pre-fix behaviour: exactly one accept, ever).
  • control::pg::tests::pooled_sessions_carry_the_control_timeouts — on a real database, writer
    and reader sessions report statement_timeout 30 s, lock_timeout 15 s,
    idle_in_transaction_session_timeout 60 s (fails before the change: Postgres reports 0).
  • control::pg::tests::the_statement_guard_kills_a_stuck_statement — SELECT pg_sleep(10) under
    the guard SQL dies in ~250 ms with SQLSTATE 57014 and "statement timeout" in the server's
    message.
  • control::pg::tests::the_lock_guard_kills_a_stuck_lock_wait — a row lock held by another
    session makes the waiter die in ~250 ms with SQLSTATE 55P03 and "lock timeout" in the
    message.
  • store_pg::tests — the driver config cannot be talked out of the TCP connect deadline by a
    connect_timeout in the URL (and still rewrites sslmode=verify-full), the deadline error
    names Postgres and the deadline, and the guard SQL carries the documented milliseconds.

Gates

After rebasing onto the current class head (which merges main a0409afdf):

cargo fmt --all --check                                                       clean
cargo clippy --locked -p preloop-runner-server --all-targets -- -D warnings    clean
cargo clippy --locked -p preloop-runner-server --lib -- -D dead_code           clean
cargo test --locked -p preloop-runner-server --lib                             1293 passed, 0 failed, 3 ignored
cargo test --locked -p preloop-runner-server --lib -- "::pg::" wake::tests store_pg::tests
                                                                              174 passed, 0 failed

The Postgres tests ran for real against a local server (PRELOOP_TEST_POSTGRES_URL set,
max_connections = 400, 4 test threads), not just the skipping path. One earlier run of the same
filter had control::pg::tests::late_skipped_completion_preserves_cancellation fail once; it is a
pre-existing test that takes no lock and waits for nothing, it passes in isolation and the filter
then passed 174/174, so that was a flake, recorded here rather than hidden. Earlier attempts at the
full suite failed for environmental reasons only: at 8 test threads the throwaway cluster's default
max_connections = 100 produced FATAL: sorry, too many clients already (each PgBackend opens
33 connections), and one run had the cluster killed mid-suite.

Deliberately left

  • A server that keeps TCP alive but never answers a statement (postmaster wedged with open
    sockets) is still only bounded by TCP keepalives, not by a client-side per-statement deadline:
    statement_timeout is enforced by the server, which is not processing. Bounding that needs a
    deadline on every statement, i.e. an adapter over GenericClient/Transaction across all ~40
    command modules (and the router has no TimeoutLayer). The realistic stuck-query, stuck-lock
    and stuck-idle-in-transaction cases — the ones the incident showed — are now bounded.
  • control/migrate_runner.rs still takes the setup advisory lock with a bare pg_advisory_lock;
    it is bounded from this side by the migration-scoped lock_timeout for the only serving-path
    caller, and is otherwise operator-initiated admin work.