Skip to main content
RunBook Academy

← All break/fix scenarios in PostgreSQL

advancedpg-connection-storm~45 min

A four-second storage stall turned into a two-hour outage, and the database never recovered on its own after the storage came back

Reported symptoms

  • Storage reports a four-second write stall at 14:02:11 during a controller failover, and confirms normal service from 14:02:15 onwards
  • Database latency rises from 4 ms to 190 ms within thirty seconds of the stall and does not come back down
  • Two hours later, with storage healthy throughout, latency is still above 150 ms and the application is timing out
  • Connection count climbed from 90 to 465 during the same thirty seconds and has stayed there
  • CPU on the database host is pinned at 100 percent with almost all of it in user time, not iowait
  • No single query is slow in isolation - the same statements run in a few milliseconds when tested from a separate session
  • Restarting the application tier restores service within a minute, which nobody can explain

Evidence

  • · The storage incident record shows a 4.1 second write stall ending at 14:02:15
  • · pg_stat_activity backend count rose from 90 to 465 between 14:02:11 and 14:02:44 and stayed above 450 for two hours
  • · The connection pool is configured with a minimum of 5, a maximum of 20 per pod, and grows when a checkout waits longer than 50 ms
  • · There are 40 pods, so the pool ceiling is 800 connections and the observed 465 is well inside it
  • · Average query duration measured at the database is 190 ms; the same query executed from a separate psql session takes 1.4 ms
  • · iowait on the host is under 2 percent for the whole two hours after 14:02:15
  • · A benchmark on this hardware peaks at 64 concurrent connections and loses 28 percent of its throughput by 400
  • · The application restart dropped connection count to 200 and latency to 6 ms within 40 seconds
Diagnosis and resolutionclick to reveal

Root cause

A connection storm is a positive feedback loop between a pool that adds connections when it sees latency, and a database whose latency rises when it is given more connections. The four-second stall was the trigger and nothing more. It caused a burst of checkout waits above the pool's 50 ms growth threshold, so every pod opened additional connections. Those connections outlived the stall — pools shrink slowly or not at all — and by 14:02:44 the database was carrying 465 backends instead of 90. A database does not get faster with more connections past a point. On this hardware the throughput curve peaks at 64 concurrent connections and declines from there: throughput falls 28 percent and average latency rises 8.6-fold by 400 clients, with the disks idle. The work is the same; the contention is not. So the loop closes. Latency at 465 connections is far above the pool's growth threshold. Every checkout wait looks, to the pool, exactly like the original stall. The pool keeps the connections it has and stands ready to add more. The database stays at the bad end of its own throughput curve. Storage recovering at 14:02:15 changed nothing, because storage was no longer the constraint after 14:02:11. This is why "no single query is slow" and why the same statement runs in 1.4 ms from a fresh session: there is no slow query. There are 465 processes contending for four cores, and each one is waiting behind the others. The application restart worked because it is the only thing in the system that reduces connection count. It broke the loop by force. Nothing else was capable of breaking it, which is the actual defect.

Remediation

Break the loop by reducing connections. Nothing else will work while the loop is running, and the database cannot break it alone. If you can restart or scale down the application tier, that is the fastest path and it is legitimate. It is what worked here. Do it deliberately rather than as a mystery: ```bash kubectl rollout restart deployment/orders-api ``` If you cannot, shed connections from the database side. Terminate idle sessions first, and keep terminating as pools reopen them, until the count is near the knee of the curve: ```sql SELECT pg_terminate_backend(pid) FROM pg_stat_activity WHERE backend_type = 'client backend' AND state = 'idle' AND state_change < now() - interval '30 seconds'; ``` Do not terminate `active` sessions indiscriminately. Their work will be retried by the application, and a retry storm on top of a connection storm makes the loop faster. Confirm you are treating the right thing before you touch storage or queries: ```sql SELECT count(*) FILTER (WHERE state = 'active') AS active, count(*) FILTER (WHERE state = 'idle') AS idle, count(*) AS total FROM pg_stat_activity WHERE backend_type = 'client backend'; SELECT wait_event_type, wait_event, count(*) FROM pg_stat_activity WHERE backend_type = 'client backend' AND state = 'active' GROUP BY 1,2 ORDER BY 3 DESC LIMIT 10; ``` A storm shows a large `active` count with waits concentrated in `LWLock` and `Lock` — CPU and internal contention. An actual storage problem shows waits in `IO` and iowait on the host. These are different pictures and they need different responses. Once the count is back near the knee, latency collapses on its own within seconds. There is nothing else to fix in the database.

Verification

Connection count sits near the measured knee of the throughput curve for this hardware, and latency is back to its normal value: ```sql SELECT count(*) FILTER (WHERE backend_type = 'client backend') AS backends FROM pg_stat_activity; ``` Host CPU is no longer saturated, and iowait is where it was before. **The loop is proven broken by testing it.** Inject a stall deliberately, in a maintenance window, and watch the connection count: it should rise, then return, without an operator doing anything. A system that recovers only when a human restarts it has not been fixed; it has been reset. The pool's maximum is a number that keeps `pods x pool_max` under the knee, and that arithmetic is written down where the next person to change the pod count will see it. If a pooler was introduced, the database backend count stays flat while client connections vary. That is the property being bought, and it is directly observable: in a measured run, 400 clients produced 465 server backends directly and 65 through a pool of 64.

Prevention

**Cap the pool below the knee, and make the pool queue rather than grow.** A pool that adds connections in response to latency is a feedback amplifier pointed at your database. A pool that queues converts overload into fair waiting, which is survivable and visible. **Measure the knee for your hardware and workload, once.** It is a short benchmark and it turns pool sizing from an argument into arithmetic. On the four-core cluster measured here the curve was: | Clients | tps | Avg latency | | --- | --- | --- | | 64 | 173,535 | 0.369 ms | | 128 | 161,277 | 0.794 ms | | 256 | 141,666 | 1.807 ms | | 400 | 125,352 | 3.191 ms | Past 64 every added connection cost throughput and bought latency. **Put a pooler in transaction mode in front, sized at the knee.** Its product is not speed — it is that the server's connection count stops depending on how many clients arrive. Measured at 400 clients on a 1.4 ms query: 465 backends direct versus 65 pooled, with the pooled run marginally *faster*. On sub-millisecond queries the same pooler was three times slower, because a single-threaded proxy becomes the bottleneck. Size and site it knowing both results. **Alert on connection count, not only on latency.** Count is the leading indicator and it moved thirty seconds before anybody noticed the latency. **Alert on the shape of the wait events.** `LWLock` and `Lock` dominating means contention; `IO` dominating means storage. Two hours were spent looking at storage that had been healthy since minute one. **Set `idle_session_timeout` for application roles**, so connections opened during a burst do not persist for two hours: ```sql ALTER ROLE app SET idle_session_timeout = '5min'; ``` **Rehearse the trigger.** A four-second storage stall is a routine event. If the system cannot absorb one without human intervention, that is worth knowing before the controller fails over on its own schedule.

Reported symptoms

Storage reports a four-second write stall at 14:02:11 during a controller failover, and confirms normal service from 14:02:15.

Database latency rises from 4 ms to 190 ms within thirty seconds — and does not come back down. Two hours later, with storage healthy the whole time, latency is still above 150 ms and the application is timing out.

Connection count climbed from 90 to 465 in those same thirty seconds and has stayed there.

Host CPU is pinned at 100 percent, almost all of it user time. iowait is under 2 percent.

No single query is slow. The same statements run in a few milliseconds when tested from a separate session.

Restarting the application tier restores service within a minute, and nobody can explain why.

Evidence provided

The pool is configured with a minimum of 5 and a maximum of 20 per pod, and it grows when a checkout waits longer than 50 ms. There are 40 pods, so its ceiling is 800 — the observed 465 is well inside it.

Average query duration measured at the database is 190 ms. The same query from a separate psql session takes 1.4 ms.

And this is the curve for this hardware:

Read-only / Safethroughput against client count, four cores, working set in shared_buffers
$ for C in 4 8 16 32 64 128 256 400; do pgbench -n -S -c $C -j 4 -T 15; done
 clients          tps   avg_latency_ms
     4  38876.335703            0.103
     8  52719.473989            0.152
    16  67119.364271            0.238
    32 124820.373482            0.256
    64 173535.067834            0.369
   128 161277.529189            0.794
   256 141665.950566            1.807
   400 125352.085856            3.191

The application restart dropped connection count to 200 and latency to 6 ms within 40 seconds.

Work the evidence before reading on

  1. Storage was healthy from 14:02:15. Why was the database still slow at 16:00?
  2. CPU is saturated in user time and iowait is under 2 percent. What does that rule out?
  3. The curve peaks at 64 clients. Where on it was the cluster sitting?
  4. Why did restarting the application work, and what does that tell you about what is missing?

Root cause

The loop

The restart worked because it is the only thing that reduces connections

Nothing in the database, the pool, or the platform could bring the count down. The application restart broke the loop by force.

That the system had exactly one recovery mechanism, that it required a human, and that the human could not explain why it worked — that is the actual defect. The stall is routine; controllers fail over.

Resolution

Break the loop by reducing connections. Nothing else works while it is running, and the database cannot break it alone.

If you can restart or scale down the application tier, that is the fastest path and it is legitimate. Do it deliberately rather than as a mystery:

kubectl rollout restart deployment/orders-api

If you cannot, shed connections from the database side, and keep shedding as pools reopen them, until the count is near the knee:

SELECT pg_terminate_backend(pid)
FROM pg_stat_activity
WHERE backend_type = 'client backend'
  AND state = 'idle'
  AND state_change < now() - interval '30 seconds';

Confirm you are treating the right thing before touching storage or queries:

SELECT count(*) FILTER (WHERE state = 'active') AS active,
       count(*) FILTER (WHERE state = 'idle')   AS idle,
       count(*)                                 AS total
FROM pg_stat_activity WHERE backend_type = 'client backend';

SELECT wait_event_type, wait_event, count(*)
FROM pg_stat_activity
WHERE backend_type = 'client backend' AND state = 'active'
GROUP BY 1,2 ORDER BY 3 DESC LIMIT 10;

A storm shows waits concentrated in LWLock and Lock. A real storage problem shows waits in IO and iowait on the host. Different pictures, different responses — and two hours went into the wrong one here.

Once the count is near the knee, latency collapses within seconds. There is nothing else to fix in the database.

Verification

Connection count sits near the measured knee and latency is normal.

Host CPU is no longer saturated.

Test that the loop is broken. Inject a stall deliberately in a maintenance window and watch the connection count rise and then return, with no operator involved. A system that recovers only when a human restarts it has not been fixed — it has been reset.

pods x pool_max is under the knee, and that arithmetic is written where the next person to change the pod count will see it.

If a pooler was introduced, backend count stays flat while client count varies. That property is directly observable:

Read-only / Safe400 clients, direct against pooled, on a 1.4 ms query
$ pgbench -f real.sql -c 400 -j 4 -T 25   # against the server, then against the pooler
  direct 400 clients : 2042 tps, 195.9 ms, 465 server backends
pooled 400 clients : 2243 tps, 178.4 ms,  65 server backends

Prevention

Cap the pool below the knee, and make it queue rather than grow. A pool that adds connections in response to latency is a feedback amplifier pointed at your database. A pool that queues converts overload into fair waiting — survivable, and visible.

Measure the knee once, for your hardware and workload. It is a short benchmark and it turns pool sizing from an argument into arithmetic.

Put a pooler in transaction mode in front, sized at the knee.

Alert on connection count, not only on latency. Count moved thirty seconds before anybody noticed the latency, and count is what you act on.

Alert on the shape of the wait events. LWLock/Lock dominating means contention; IO dominating means storage.

Set idle_session_timeout for application roles, so connections opened during a burst do not persist for two hours:

ALTER ROLE app SET idle_session_timeout = '5min';

Rehearse the trigger. A four-second storage stall is routine. If the system cannot absorb one without a human, that is worth learning before the controller fails over on its own schedule.