PostgreSQL Crash Recovery: Why Startup Took 38 Minutes After the OOM Kill

The sequence looked fast from the outside. The OOM killer picked the postgres postmaster at 14:22 on a Tuesday — the memory accounting story behind that is its own write-up in the OOM killer notes — systemd restarted the unit within a minute, and by 14:23 the process was up and eating RAM again. Then nothing. Every connection attempt got the same refusal, the health checks stayed red, and the failover tooling correctly sat on its hands because the old primary was alive and recovering. At 15:01 the log finally printed "database system is ready to accept connections," thirty-eight minutes after the restart. In between, PostgreSQL replayed 61 GB of WAL, and there was no knob I could turn in the moment to make it go faster. This is what I learned while watching it, and what we changed so the next one took six minutes.

What actually happens between the restart and "ready to accept connections"?

Crash recovery is redo, and redo starts at a fixed point: the REDO pointer of the last completed checkpoint, recorded in pg_control. PostgreSQL reads the control file, sees the cluster was not shut down cleanly, switches into crash recovery, and walks forward from that REDO location applying every WAL record to the data pages it references — pages read from storage, modified in memory, flushed later. Only when replay reaches the end of available WAL and a fresh checkpoint establishes a new clean starting point does the postmaster open the socket. Two properties of this matter operationally. First, replay is essentially single-threaded: one process, WAL records applied in order, no parallelism to buy your way out with. Second, it is I/O-bound in the worst way — the pages being modified were, in our case, exactly the pages evicted from the OS cache when the box started swapping before the OOM, so replay was random reads against cold storage, not the nice sequential WAL read the phrase suggests.

The distance replay has to cover is not "how much data changed since the crash." It is how much WAL was generated since the last checkpoint’s REDO pointer — a number you choose, indirectly, with your checkpoint configuration, which is why this write-up overlaps heavily with the WAL checkpoint tuning notes and the broader WAL monitoring guide.

Why did we have 61 GB of WAL to replay?

Because we had tuned checkpoints for exactly the opposite goal. To smooth write amplification on a write-heavy OLTP cluster — roughly 800 GB of data, peak WAL generation around 40 MB per second during the afternoon batch window — we had pushed max_wal_size to 64 GB and leaned on checkpoint_completion_target to spread each checkpoint thin. In steady state that is the right trade: checkpoints every twenty-plus minutes, no I/O storms, happy disks. The bill arrives at crash time, when the REDO pointer is twenty-plus minutes of WAL behind the crash point and every gigabyte of that gap is recovery latency. Our 61 GB was not an accident; it was the designed behavior of our own settings, discovered at the worst possible time. The first honest measurement came after boot, from the log lines recovery prints and from the checkpointer statistics:

-- PG 17 moved checkpoint stats into their own view
SELECT checkpoints_timed, checkpoints_req,
       checkpoint_write_time, checkpoint_sync_time,
       buffers_checkpoint
FROM pg_stat_checkpointer;

-- How far behind was the last checkpoint at boot time?
-- From shell: pg_controldata $PGDATA | grep -i "REDO"
--   Latest checkpoint's REDO location:    4E2/7A000028

The arithmetic is simple and brutal: WAL-to-replay divided by observed replay throughput equals recovery time. Our replay throughput against cold pages was about 27 MB per second, and 61 GB at 27 MB per second is thirty-eight minutes. Everything that shortens recovery attacks one of those two terms.

What does replay look like from the outside while it runs?

Quiet, mostly, which is its own operational hazard. The log shows "redo starts at …" and then, with default logging, periodic progress lines with the replay position — but nothing on the socket, no pg_stat_activity, none of the wait-event tooling you would normally reach for, because there is no session to observe. Our first failure was one of communication: the load balancer health check flapped the instance as down for thirty-eight minutes, the on-call phone interpreted "primary down for thirty-eight minutes" as a failover trigger, and we came uncomfortably close to promoting a replica that was itself catching up — which would have turned a long restart into a split-brain discussion. The fix was boring: a recovery-aware health check that reads the log’s replay progress, an on-call runbook line that says "redo in progress is not a down database," and a dashboard panel that graphs the replay position advancing so humans can see forward motion instead of a red wall.

What did we change to get from 38 minutes to six?

Three things, in order of impact. First, we capped the exposure: max_wal_size came down to 16 GB and we added a cron-driven CHECKPOINT at the end of each batch window, so the worst-case REDO gap shrank from roughly 25 minutes of WAL to about 7 — the cost was measurably higher checkpoint write I/O, accepted knowingly. Second, we attacked replay throughput: the recovery box’s storage had been the same IOPS class as steady state needed, and doubling the provisioned read IOPS moved replay from 27 MB per second to about 70. Third, we started measuring it on purpose: a quarterly drill that hard-kills a staging clone under load and times recovery, because the number that matters — recovery time under realistic dirty-WAL conditions — is not one you want to learn in production. The second crash, eight weeks later, replayed 11 GB in six minutes and the on-call notes read like a non-event, which is the entire point.

-- Manual checkpoint after the batch window, keeps the
-- crash-time REDO gap short even when traffic was heavy
CHECKPOINT;

-- Watch the gap in steady state: WAL generated since
-- the last checkpoint's redo pointer
SELECT pg_wal_lsn_diff(
         pg_current_wal_lsn(),
         redo_lsn
       ) AS wal_since_redo_bytes
FROM pg_control_checkpoint();

One thing we did not change: restart_after_crash stays on, and the automatic restart stays faster than any human paging chain. The goal was never to avoid crash recovery — it is correct, conservative, and trustworthy — but to bound it, and to make sure nobody mistakes a working recovery for a dead database.

Watching crash recovery with MonPG

The dangerous thirty-eight minutes were not invisible — WAL generation, checkpoint timing, and disk latency were all on graphs; they were just never assembled into "expected recovery time if we crash right now." MonPG monitors PostgreSQL in production today, and its PostgreSQL monitoring tracks checkpoint frequency, WAL generation rate, and the redo-gap arithmetic on one timeline, so the exposure is a number you watch shrink after tuning rather than a surprise you meet at 14:23 on a Tuesday. Crash recovery will always cost something; the job is to make it a budgeted something.

Related documentation

• PostgreSQL: continuous archiving and point-in-time recovery