Skip to content

feat(db): configurable writer session timeouts (lock, idle-txn, statement) - #6229

Open
TheSentinel454 wants to merge 2 commits into
mainfrom
fizz/db-session-timeouts
Open

feat(db): configurable writer session timeouts (lock, idle-txn, statement)#6229
TheSentinel454 wants to merge 2 commits into
mainfrom
fizz/db-session-timeouts

Conversation

@TheSentinel454

@TheSentinel454 TheSentinel454 commented Aug 18, 2026

Copy link
Copy Markdown
Contributor

Why

A wedged relay boot pod holding a relation lock can park every other writer in the fleet behind it: DB load pins at pool capacity in Lock:relation waits while CPU stays flat, and nothing server-side releases the lock until the holder dies. We hit exactly this in production — ~1,400 sessions queued behind one crash-looping pod's boot transaction for ~20 minutes until kubelet killed the container.

What

Applies session-level Postgres timeouts to every writer connection inside the existing single after_connect hook in buzz-db, all env-tunable through the same Config::from_env → DbConfig path as the existing pool-size knobs:

Env var GUC Default Effect
BUZZ_DB_LOCK_TIMEOUT_MS lock_timeout 5000 statements waiting on any lock fail fast instead of parking behind a wedged holder
BUZZ_DB_IDLE_TXN_TIMEOUT_MS idle_in_transaction_session_timeout 60000 reaps wedged clients idling inside an open transaction while holding locks
BUZZ_DB_STATEMENT_TIMEOUT_MS statement_timeout 0 (off) opt-in runaway-statement cap; off by default because startup migrations/backfills legitimately run long statements

0 disables a timeout (Postgres semantics) and deliberately passes through the env parsing — unlike the pool-size knobs where 0 falls back to the default. The reader pool is untouched: replica sessions never take contended locks and already fail acquire in 150 ms.

Deployers tune these via plain env vars (.env, or relay.extraEnv in the Helm chart) — no code changes needed.

Behavior change to note

With the 5 s default lock_timeout, a boot-time migration or backfill that waits >5 s on a lock now errors (surfacing in logs / crash-looping the pod) instead of stalling silently. That is the intended visible-failure-over-fleet-stall tradeoff; deployers with slow contended migrations can set BUZZ_DB_LOCK_TIMEOUT_MS=0.

Testing

  • cargo test -p buzz-db -p buzz-relay — buzz-db green; buzz-relay has 9 failures that also fail on clean main in this environment (api::admin/api::media/mesh_demo — unrelated, pre-existing).
  • New config test covers override / 0-passthrough / invalid-fallback for all three env vars.
  • Extended the existing writer_pool_safety_hook_is_single_and_composed source-shape test so the timeouts can't drift out of the single after_connect hook (SQLx replaces hooks — a second hook would silently disarm the floor guard).
  • cargo fmt --check and cargo clippy --all-targets clean for the touched crates.

Closest existing PR/issue: none found.


Update Aug 28, 17:06 EDT: Rebased onto main at a3730784fc and addressed the latest correctness review.

  • Ported the timeout policy onto the refactored buzz-db::runtime pool constructor and kept the shared env overlay for relay, admin, deletion, and audit writers.
  • Migration/schema-destruction connections now disable lock_timeout and statement_timeout for their intentional long wait/DDL path. This supersedes the earlier “Behavior change to note”: contended boot migrations wait for the current migration owner rather than crash-looping after five seconds.
  • The audit worker now preserves and retries the same entry on PostgreSQL 55P03 lock timeouts, using exponential backoff capped at one second. Other database errors retain the existing terminal error behavior, and retries emit buzz_audit_log_lock_retries_total.
  • Added CI-backed PostgreSQL regressions for writer GUC installation/migration exemption, audit-pool lock timeouts, and worker recovery. The worker regression holds the real audit advisory lock past lock_timeout, observes a retry, releases the lock, and proves the original entry is appended exactly once.

Current verification supersedes the earlier testing notes: workspace Rust clippy passed with warnings denied; all nine infrastructure-free backend unit-test lanes passed; all three focused PostgreSQL regressions passed against PostgreSQL 17; formatting, diff checks, file-size guards, and desktop frontend checks passed. The Linux Blox workstation could not run the unrelated Tauri native lane because glib-2.0 is absent, so that platform check is left to PR CI.

Comment thread crates/buzz-db/src/lib.rs Outdated
/// lock wait on the relay's hot paths, yet turns a wedged relation-lock
/// holder from a fleet-wide stall into per-statement errors that surface in
/// logs and retry naturally.
pub const DEFAULT_LOCK_TIMEOUT_MS: u64 = 5_000;

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Open to bumping this until we have a better understanding of how long we tend to spend running migrations.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Leaving this thread open: the 5s default is unchanged pending real migration-duration data. There are no boot-time migration duration metrics today; the proposal on the table is a buzz_boot_migration_duration_seconds gauge around db.migrate() (each pod boot is a sample), either in this PR or a small follow-up — awaiting the maintainer's call. Note that as of 605244c the migration advisory-lock path is exempt from lock_timeout/statement_timeout, so the default now only governs runtime traffic, which lowers the stakes of the choice.

This reply was generated by an AI agent (Fizz).

@TheSentinel454
TheSentinel454 marked this pull request as ready for review August 18, 2026 15:50
@TheSentinel454
TheSentinel454 requested a review from a team as a code owner August 18, 2026 15:50

@wpfleger96 wpfleger96 left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Combined review — two independent agent passes (Paul and Thufir) that converged on the migration finding, deduped into the inline comments below. The mechanism itself looks right to me: one composed after_connect hook, 0-passthrough env semantics, reader pool left alone, bare-integer ms values verified live against Postgres. Nobody's asking for a different design — two blocking items and two nits.

Comment thread crates/buzz-db/src/lib.rs Outdated
Comment thread crates/buzz-db/src/lib.rs Outdated
Comment thread crates/buzz-db/src/lib.rs Outdated
Comment thread .env.example
Comment thread crates/buzz-db/src/migration.rs Outdated
Fut: Future<Output = (PgConnection, Result<T>)>,
{
let mut lock_conn = pool.acquire().await?.detach();
// Exempt this connection from the lock/statement writer-session timeouts.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To be honest, we shouldn't be doing this, and we need to move away from applying migrations on boot, but that's a bigger change that I'll be pushing for separately.

@wpfleger96 wpfleger96 left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Re-reviewed the exact current head. The previous two IMPORTANT findings plus two MINOR notes are addressed for pools constructed through Db::new(): the Postgres-backed CI test covers effective GUCs, ordinary 55P03 contention, and migration-lock exemption; independent PG 17 verification reproduced 55P03 at 502 ms and migration success after waiting 1,521 ms past both configured lock/statement budgets. Admin and deletion now share the centralized env overlay, and the comments/docs are accurate.

IMPORTANT / Correctness — crates/buzz-relay/src/main.rs:356-364: the timeout policy is only installed by Db::new(), but the audit service is a separate production relay writer pool built with raw PgPoolOptions. AuditService::log() writes audit_log in a transaction and waits on a session-scoped pg_advisory_lock; live verification at this exact head showed all three GUCs remained 0 on a production-shaped direct pool and the waiter was still blocked at the 1,201 ms harness deadline. Because the relay has one audit worker and a bounded queue whose producers use .send().await, a blocked audit lock can stall the worker, fill the queue, and backpressure event/media handlers.

Please arm the audit writer with the same session settings—preferably through a reusable buzz-db pool configuration helper rather than duplicated SQL—and add a Postgres-backed regression asserting its effective GUCs and bounded advisory-lock wait. The separately deployed push gateway also constructs a raw writer pool; explicitly decide/document whether it belongs in this PR’s stated “every writer” scope.

@wpfleger96 wpfleger96 left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Combined review of exact head 9bbcade722b7a680e764feabcdb5acf738347ed3 — three independent agent passes (two source reviews plus a clean-relay live E2E run), deduped here. Both live probes converged on the same new defect independently, which is strong confirmation it's real.

Previous round's findings — all addressed:

  • The audit pool now goes through the renamed public Db::connect_writer_pool via connect_audit_pool() (crates/buzz-relay/src/main.rs:38), inheriting the timeouts, the created_at floor guard, and the READ COMMITTED assertion; the source-shape guard test tracks the new name so the single-after_connect-hook invariant can't drift.
  • Migration/schema-destruction connections exempt their legitimate long waits. Proven live twice: a relay with BUZZ_DB_LOCK_TIMEOUT_MS=300 waited ~3 s behind the schema-migration advisory lock and completed startup.
  • Admin, deletion, relay, and audit pool configuration share the centralized env overlay; comments and operator docs match PostgreSQL semantics.
  • The requested Postgres-backed regressions exist and actually run: the Backend Integration job at this head executed both focused tests from the archive (session_timeouts_install_through_db_new_and_bound_lock_waits PASS 4.96 s, audit_writer_pool_installs_timeouts_and_bounds_advisory_lock_waits PASS 0.52 s). The final commit's CI split is a genuine hardening: separate nextest invocations mean a relay-binary test missing from the archive fails loudly instead of the combined OR-filter silently passing on the buzz-db half.
  • Push-gateway scope decision is documented consistently in .env.example, the with_session_timeouts_from_env doc, and docs/push-gateway-deployment.md.

Core mechanism verified live (clean relay, isolated Postgres/Redis/MinIO, head-built binaries): a real message write behind an ACCESS EXCLUSIVE lock on events failed in 0.486 s instead of parking, the relay stayed ready throughout, and accepted/read messages normally after release — the exact incident shape this PR exists to fix.

IMPORTANT / Correctness — audit lock timeouts now permanently discard accepted events' audit entries. connect_audit_pool() correctly installs the 5 s default lock_timeout, but AuditService::log() propagates SQLSTATE 55P03 and log_audit_entry() (crates/buzz-relay/src/state.rs:1342-1349) only logs the error and increments a metric before consuming the queue item — no retry, no durable outbox. Both live probes reproduced this independently at this exact head: holding one community's audit advisory lock past the timeout, the relay accepted and persisted the message (event_rows=1), the worker logged canceling statement due to lock timeout, and audit_rows remained 0 (one probe additionally drove a real end-to-end channel message through the head-built CLI: event accepted, permanently unaudited). Releasing the lock let the next event audit normally — transient contention became permanent audit loss, not database unavailability. Before this PR the audit pool had no lock_timeout, so the failure mode was indefinite worker blockage; the fix converts it into silent audit-chain gaps, which regresses the durable-audit contract (SECURITY.md:67-74, VISION_MODERATION.md) and the queue's stated no-drop intent.

Required fix: preserve the current queued entry across retryable lock-timeout failures — retry with bounded backoff until appended, or use a transactional durable outbox if request-path decoupling must survive prolonged contention. Add a Postgres-backed worker-level regression that holds the advisory lock past lock_timeout, releases it, then proves the original accepted event is eventually audited (the current audit test proves the pool fails fast, not that the consuming workflow preserves the entry). A fix also needs a live contention re-run proving the accepted event ends up with exactly one audit row.

New-regression sweep — nothing else found: all remaining raw PgPoolOptions writers at this head are accounted for (search pool is SELECT-only FTS, mesh-boot/channel-snapshot pools are test-only, push gateway documented out of scope), and the merge from main introduced no semantic interaction with the PR's files.

Quality: Minimalism 9/10; Elegance 9/10; Correctness 7/10 pending durable recovery from the newly expected lock-timeout error.

TheSentinel454 added a commit that referenced this pull request Aug 25, 2026
## Why

Database pressure currently collapses several distinct delays into one
symptom. This adds the evidence layer needed to distinguish pool
acquisition wait, logical database operation time, advisory-lock wait,
and selected transaction duration before changing timeout or retry
policy.

This is the phase 2 Lane A observability bundle for
[#26](TheSentinel454#26),
[#28](TheSentinel454#28), and
[#33](TheSentinel454#33). It is stacked
on #6668.

## What

- Record explicit reader/writer checkout wait and acquisition outcomes
with `buzz_db_pool_acquire_wait_seconds` and
`buzz_db_pool_acquisitions_total`.
- Extend the compile-time `#[datastore_span(name = "...")]` seam with
`buzz_db_operation_duration_seconds`, so operation labels remain static
source literals instead of request data.
- Route correctness-critical replacement, membership, push-gate,
deletion, and migration/schema-safety advisory locks through one
observer without changing their SQL, order, scope, or blocking behavior.
- Measure six internally owned transaction lifetimes with
`buzz_db_transaction_duration_seconds`, starting after `BEGIN` succeeds
and ending after explicit commit/rollback or scope exit.
- Emit root slow-operation warnings at 500 ms, logging the first slow
completion and then 1/100 per call site with only `operation`,
`outcome`, and `elapsed_ms`.
- Document names, units, fixed label vocabularies, measurement
boundaries, and blind spots in this PR description.

Fixed labels are deliberately small:

- `pool_role`: `writer`, `reader`
- `lock_type`: `replacement`, `membership`, `push_gate`, `deletion`,
`migration_schema_safety`
- `outcome`: `success`, `error`, `timeout` where SQLx/PostgreSQL can
distinguish it accurately
- `operation`: compile-time datastore names plus the six closed
transaction operation names documented in the runbook

No metric or slow warning contains community IDs, event IDs, event
kinds, coordinates, d-tags, SQL/query text, query IDs, returned errors,
or event content.

## Coverage boundaries

- Operation duration is the complete annotated logical function body,
not pure SQL execution; it may include implicit checkout, lock wait,
nested operations, and application work. Cancelled futures do not reach
its completion hook.
- Pool timing covers explicit helper checkouts, including proved-reader
routing and selected writer-owned transactions. Implicit SQLx checkout
through `&PgPool` remains folded into operation duration.
- Lock timing covers application-side blocking locks in the five named
families. Trigger/stored-procedure locks, channel-TTL locking, the usage
try-lock, and the audit service session lock remain outside this slice.
- Transaction timing covers only the six wholly owned boundaries
documented in the runbook. It excludes pool wait, `BEGIN`, asynchronous
rollback cleanup after an early return, and caller-owned
`Db::begin_transaction` lifetime.

## Relationship to #6229

#6229 is the incident-driven timeout precursor. This PR does not add or
change `statement_timeout`, `lock_timeout`,
`idle_in_transaction_session_timeout`, retries, audit durability, or
client-visible conflicts. It provides the missing distributions needed
to evaluate those policies later and intentionally leaves #6229's open
audit retry/durability finding untouched.

The branches overlap in `crates/buzz-db/src/lib.rs` and
`crates/buzz-db/src/migration.rs`, so a later rebase may need textual
conflict resolution, but the behavior is complementary rather than
duplicated.

## Risk assessment

Moderate-low. The primary risk is instrumentation overhead and added
static series. Cardinality is source-bounded, slow logs are
sampled/redacted root events, and the lock/transaction changes wrap
existing awaits without changing policy or ordering.

## Verification

Author workstation: `buzz-tornquist-db-pressure-observability`
(`2010927`), exact head `d7cf833e26c528adfcde3917ded80daf6f4ddac9`,
parent `6f50e6b2b2a996349149af61d35bdd6a355f77fd`.

- `cargo fmt --all --check` — passed
- `cargo clippy -p buzz-datastore-tracing -p buzz-db -p buzz-audit -p
buzz-search -p buzz-relay --all-targets -- -D warnings` — passed
- `cargo test -p buzz-datastore-tracing --quiet` — 4 passed
- `cargo test -p buzz-db --quiet` — 109 passed, 200 ignored
- `cargo test -p buzz-audit -p buzz-search --quiet` — 16 passed, 25
ignored
- `cargo test -p buzz-relay --lib --quiet -- --test-threads=1` — 906
passed, 48 ignored
- Native PostgreSQL focused tests for pool success/timeout/error, lock
success/contention/timeout/error, replacement, membership serialization,
push ordering, deletion fencing, migration/schema exclusion, and reader
fallback — 8 passed

The default-parallel relay run passed once; subsequent runs exposed the
existing load-sensitive
`api::mesh_demo::tests::demo_join_forwarded_arm_round_trips_echo` 504 at
the end of the suite. That test passes in isolation and the full relay
suite passes serially.

Independent exact-head review workstation:
`buzz-tornquist-db-pressure-observability-review` (`2013067`).
Formatting, the same all-target clippy command, datastore
instrumentation tests, DB unit tests, source privacy guards, and
diff/non-goal audits passed; no review findings.

Generated with Codex

---------

Signed-off-by: tornquist <tornquist@squareup.com>
Signed-off-by: Luke Tornquist <tornquist@squareup.com>
Signed-off-by: Luke Tornquist <tornquist@squareup.com>
@TheSentinel454
TheSentinel454 force-pushed the fizz/db-session-timeouts branch from 9bbcade to 2305bb4 Compare August 28, 2026 21:06
@github-actions

Copy link
Copy Markdown

🔐 Codex Security Review

Status: review required for the current range.

The current range is a3730784fc851bb1125b40cca9b0a30788a293c1...2305bb489f0f6c348fc8a72cdcef72c93c433f9d.
A new review must complete for this exact range. When manual authorization
is required, a Block organization member must comment exactly
@buzz-security-review 2305bb489f0f6c348fc8a72cdcef72c93c433f9d to authorize a new review.
Any previous review applies only to its recorded range.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants