PostgreSQL · advanced

How to test PostgreSQL statement timeout without hiding locks

This guide explains how to verify PostgreSQL statement_timeout behavior in isolation from lock-wait latency, so engineers can prove that a deadline fired against an intended statement rather than being masked by a concurrent lock. It frames verification as a controlled experiment with three observable boundaries: timer enforcement, error surface, and preserved evidence in pg_stat_activity and pg_stat_statements.

The symptoms

  • statement_timeout appears not to fire because the client observes a "canceling statement due to statement timeout" error after a delay dominated by lock acquisition rather than query execution
  • Tests of statement_timeout intermittently pass or fail depending on whether another transaction holds a conflicting lock at the moment the test query runs
  • Evidence in pg_stat_activity shows the timed-out backend waiting on a lock for most of the elapsed wall-clock time, with query_start far in the past and wait_event_type set to Lock
  • PostgreSQL log_min_duration_statement or auto_explain output attributes the abort to lock_timeout rather than to statement_timeout, even though the application intended only a statement-level deadline
  • Repeated runs of the same query produce inconsistent row counts in pg_stat_statements because the timeout fired on different statements, masking the test's true variance

Likely causes

  • Test environment conflates lock_timeout (which caps lock-wait) with statement_timeout (which caps total elapsed time), so the observed cancel reflects whichever deadline expired first
  • The verification query is blocked by a long-held row or relation lock from a separate session, inflating wall-clock time and obscuring whether statement_timeout would have fired on an unblocked run
  • Lock acquisition itself is being measured as part of statement timing, so the deadline appears to "succeed" by stopping a wait that had no useful work to interrupt
  • Evidence collection scripts read pg_stat_activity after the cancel, conflating the post-cancel idle state with the actual wait state the deadline interrupted
  • Lock_timeout is left unset at the session level, so a blocking transaction silently extends the effective deadline beyond the intended statement_timeout budget

First ten minutes

  1. 01Capture the current value of statement_timeout and lock_timeout for the target session and database, recording whether each was set at the role, database, or session level via pg_settings
  2. 02List active backends in pg_stat_activity and record their state, wait_event_type, wait_event, and query_start so any blocking lock is identified before the test query runs
  3. 03Resolve or isolate any session that holds a lock on the relations the verification query will touch, so the test runs against an unblocked path
  4. 04Set both statement_timeout and lock_timeout to the intended test values for the verification session only, using SET LOCAL inside a transaction so other workloads are unaffected
  5. 05Run a baseline short query on the same relation to confirm execution returns promptly and to capture the unblocked timing envelope the deadline must beat

Evidence to collect

  • pg_settings rows for statement_timeout, lock_timeout, and idle_in_transaction_session_timeout, including their source (session, user, database) and reset_val
  • pg_stat_activity snapshot showing wait_event_type, wait_event, state, query_start, and xact_start for both the verification backend and any potential blockers
  • PostgreSQL log line containing the SQLSTATE and message text for the canceled statement, plus the duration reported by log_min_duration_statement or auto_explain if enabled
  • pg_locks rows for the verification session's pid, including locktype, mode, granted, and the relation or tuple identifiers held or awaited
  • pg_stat_statements row for the timed-out query, capturing calls, total_exec_time, and rows so the post-test variance can be compared to the unblocked baseline

Where to look

  • Server-level timeout boundary: pg_settings for statement_timeout and lock_timeout, where the GUC hierarchy (postgresql.conf, ALTER ROLE/DATABASE, SET) determines which value the backend actually enforces
  • Per-backend behavior boundary: pg_stat_activity joined to pg_locks on pid, where wait_event_type=Lock and granted=false indicate the deadline is being consumed by a wait rather than by execution
  • Catalog and statistics boundary: pg_stat_database and pg_stat_statements, where total_exec_time and blk_read_time reveal whether I/O or planning, not the deadline, dominated the canceled run
  • Logging boundary: PostgreSQL log directory and log_line_prefix output, where the SQLSTATE 57014 family and the duration field document the precise moment and cause of the cancel
  • Plan boundary: EXPLAIN (without ANALYZE) output for the verification query, used to confirm the unblocked plan is bounded before any timeout is applied

Diagnostic steps

  1. 01Compare the elapsed wall-clock time between query_start and the cancel log line against the configured statement_timeout value; a large gap with wait_event_type=Lock points to a lock-wait, not an execution-budget overrun
  2. 02Reproduce the query against a relation guaranteed not to be locked, and confirm the deadline fires within a tight envelope of the configured value plus planning overhead; failure here indicates the timeout is not actually enforced for this session
  3. 03Run the same query with statement_timeout unset and lock_timeout set to a value well above statement_timeout; if the cancel still appears with SQLSTATE 57014, the verification is exercising lock_timeout, not statement_timeout
  4. 04Inspect pg_locks for the timed-out pid after the cancel; a granted=false entry on a relation or tuple lock at cancel time proves the deadline interrupted a wait, which is the exact failure mode this guide isolates
  5. 05Cross-check pg_stat_statements.total_exec_time across runs; if variance collapses only after locks are removed, the original test was masking the deadline's true target
  6. 06Validate that the cancel log line names "statement timeout" rather than "lock timeout" or "idle-in-transaction timeout" so the evidence matches the intended deadline

Common mistakes

  • Setting statement_timeout on the session but leaving lock_timeout at zero or unlimited, so a blocking transaction silently stretches the effective deadline and the cancel arrives from the wrong source
  • Asserting success because the client saw SQLSTATE 57014 without checking which timeout the server reported, conflating statement_timeout, lock_timeout, and idle_in_transaction_session_timeout cancels
  • Reading pg_stat_activity after the cancel and reporting the idle state as evidence the timeout "worked," when the relevant wait_event and query_start were overwritten on transaction end
  • Re-running the verification query against a shared test database without isolating the relation, so other engineers' sessions become invisible blockers that skew every run
  • Trusting total_time in pg_stat_statements as proof of deadline enforcement, since it aggregates execution across calls and does not distinguish a canceled run from a completed one

Safe fixes

  • Run the verification inside a transaction with SET LOCAL statement_timeout and SET LOCAL lock_timeout pinned to the intended test values, so the change reverts on COMMIT or ROLLBACK and cannot leak into other sessions
  • Acquire a session-scoped advisory lock on a stable key for the duration of the verification, so concurrent test runners cannot become silent blockers on the same relations
  • Pair the timed query with a short, unblocked baseline and require the deadline to fire within the configured value plus a small planning overhead; otherwise treat the run as inconclusive and re-check pg_settings
  • Capture pg_stat_activity and pg_locks snapshots immediately before and after the cancel, and archive the cancel log line, so the evidence trail records wait_event and SQLSTATE rather than relying on client-side timing
  • Use EXPLAIN (without ANALYZE) to bound the plan of the verification query so a deadline that fires inside planning is recognized as a planning-bound timeout rather than an execution-bound one

Prove the fix

  1. 01The cancel log line reports SQLSTATE 57014 with the message text naming statement timeout, and the elapsed duration is within a tight envelope of the configured statement_timeout value
  2. 02pg_stat_activity at the moment of cancel shows wait_event_type distinct from Lock, and pg_locks shows no granted=false entries for the verification pid, proving the deadline interrupted execution rather than a wait
  3. 03The same verification query run against an unblocked relation produces identical cancel timing across at least three runs, with the variance attributable only to planning and not to lock acquisition
  4. 04pg_stat_statements rows for the verification query show consistent total_exec_time across runs, indicating the deadline fired deterministically on the intended statement rather than on whichever work happened to be in flight
  5. 05Re-running the verification with lock_timeout set well below statement_timeout produces a log line naming lock timeout, confirming the two deadlines are independently observable and not aliased in the test

Prevention and next steps

  • Adopt a verification harness that pins both statement_timeout and lock_timeout per session, records pg_stat_activity and pg_locks snapshots, and asserts the SQLSTATE message text rather than relying on wall-clock timing alone
  • Maintain a dedicated relation or schema for timeout tests so unrelated workloads cannot introduce locks that silently extend the effective deadline during a verification run
  • Document the expected SQLSTATE 57014 message text and duration envelope for each statement_timeout value used in tests, so regressions in enforcement surface as observable diffs in CI logs
  • Periodically audit pg_settings across roles and databases to confirm that ALTER ROLE/DATABASE overrides do not silently mask the session-level values used by the verification harness

Safe commands and checks

SELECT name, setting, unit, source, reset_val FROM pg_settings WHERE name IN ('statement_timeout','lock_timeout','idle_in_transaction_session_timeout');
SELECT pid, state, wait_event_type, wait_event, query_start, xact_start FROM pg_stat_activity WHERE datname = current_database() ORDER BY query_start;
SELECT pid, locktype, mode, granted, relation::regclass FROM pg_locks WHERE pid = <pid> ORDER BY granted DESC, locktype;
BEGIN; SET LOCAL statement_timeout = '<ms>'; SET LOCAL lock_timeout = '<ms>'; <verification query>; ROLLBACK;
SELECT query, calls, total_exec_time, rows FROM pg_stat_statements WHERE query ILIKE '<verification query pattern>' ORDER BY calls DESC LIMIT 5;
EXPLAIN (FORMAT TEXT, ANALYZE FALSE, BUFFERS FALSE) <verification query>;
SELECT pg_backend_pid(); -- obtain <pid> for use in pg_locks and pg_stat_activity joins