Crash recovery: what "consistent state" means · PostgreSQL

Crash recovery is not an exceptional path. It is the same code that runs on every standby continuously, and it runs on the primary any time the cluster was not shut down cleanly.

What it does

Read pg_control to find the last checkpoint’s redo location.
Replay every WAL record from there forward.
Stop when a record is not valid — that is the end of the log.
Take a checkpoint.
Accept connections.

Committed transactions are replayed and become visible. Uncommitted ones were never visible and remain so. Nothing is rolled back, because nothing needs to be: from lesson VII-01, an aborted transaction’s versions are simply never visible to anyone.

The log, line by line

Service impact possiblea real crash recovery— Captured on 18.6. 300,000 rows had been inserted after a CHECKPOINT; the container was then killed with SIGKILL.

$ docker kill --signal=KILL rbpg-stor && docker start rbpg-stor

LOG:  database system was interrupted; last known up at 2026-08-27 21:01:01 UTC
LOG:  database system was not properly shut down; automatic recovery in progress
LOG:  redo starts at 7/CB35CEA8
LOG:  invalid record length at 7/CF4461A0: expected at least 24, got 0
LOG:  redo done at 7/CF446178 system usage: CPU: user: 0.09 s, system: 0.03 s, elapsed: 0.12 s
LOG:  checkpoint starting: end-of-recovery immediate wait
LOG:  checkpoint complete: wrote 6003 buffers (36.6%), wrote 2 SLRU buffers; 0 WAL file(s) added, 4 removed, 0 recycled; write=0.026 s, sync=0.018 s, total=0.066 s; sync files=9, longest=0.013 s, average=0.002 s; distance=66468 kB, estimate=66468 kB; lsn=7/CF4461A0, redo lsn=7/CF4461A0
LOG:  database system is ready to accept connections

Read-only / Safethe data, afterwards— Captured on 18.6 immediately after recovery completed.

$ psql -U postgres -At -c "SELECT count(*) FROM crashtest"

Line	Meaning
`was interrupted; last known up at`	The control file was not marked shut down
`was not properly shut down; automatic recovery in progress`	Recovery is starting
`redo starts at 7/CB35CEA8`	The last checkpoint’s redo location
`invalid record length … got 0`	The end of the WAL. Normal.
`redo done at 7/CF446178 … elapsed: 0.12 s`	Replay finished, with timing
`checkpoint starting: end-of-recovery immediate wait`	Establishing a new recovery point
`database system is ready to accept connections`	Done

The line that reads like corruption

LOG:  invalid record length at 7/CF4461A0: expected at least 24, got 0

This appears in every crash recovery. It is how recovery discovers where the log ends: it reads forward until it finds something that is not a valid record header, and reports what it found.

The variants are equally normal:

invalid magic number 0000 in log segment ...
invalid resource manager ID ...
record with incorrect prev-link ...

All of these, at LOG level and immediately before redo done, are the end-of-WAL marker.

What would indicate a genuine problem:

The message at PANIC or FATAL rather than LOG.
redo done never appearing.
could not open file "pg_wal/…" — a missing segment, which is a different failure entirely and means recovery cannot proceed.
The message appearing at a position far behind where the cluster was known to be.

During an incident, people see this line, conclude the WAL is corrupt, and restore from backup — discarding a working cluster and hours of committed data. Recognising it is worth more than most of this lesson.

Estimating recovery time

Measured here: 65 MB replayed in 0.12 seconds of elapsed time. That is this hardware, warm cache, a simple insert workload — but the method generalises:

recovery time ≈ WAL to replay ÷ replay rate
WAL to replay ≈ up to max_wal_size, or checkpoint_timeout × generation rate

Measure your own replay rate, before you need it

The honest way to get the number is to cause a crash on a copy:

# On a restored copy, never production. Substitute your own container
# name or, on a package install, the postmaster's pid.
pgbench -c 8 -T 300 restored_db
docker kill --signal=KILL pg-restore-copy
docker start pg-restore-copy
# then read the recovery log for "redo starts", "redo done" and "elapsed"

redo starts at and redo done at give the LSN range; subtracting them gives the bytes; the elapsed: figure gives the time.

Doing this once tells you what a crash costs on your hardware with your workload, and that number is what the max_wal_size decision in lesson XII-04 should be made against.

Three things that make replay slower than you expect:

Replay is largely single-threaded. The startup process applies records in order. A primary generating WAL from sixty-four concurrent clients is replayed by one process.

Random reads. Replay reads the pages it modifies, in whatever order the WAL dictates. A cold cache makes this substantially slower than the original write path, which had the pages in shared buffers already.

recovery_prefetch exists to mitigate the second problem, and defaults to try on this cluster. It reads ahead of the replay position so the pages are being fetched while earlier records are applied.

`pg_controldata`

The authoritative state of a cluster that is not running.

Read-only / Safepg_controldata on a healthy running cluster— Captured on 18.6. Read the cluster state line first.

$ pg_controldata "$PGDATA"

pg_control version number:            1800
Catalog version number:               202506291
Database system identifier:           7678780827444375601
Database cluster state:               in production
pg_control last modified:             Thu 27 Aug 2026 09:01:28 PM UTC
Latest checkpoint location:           7/D327F4D8
Latest checkpoint's REDO location:    7/D327F4D8
Latest checkpoint's REDO WAL file:    0000000100000007000000D3
Latest checkpoint's TimeLineID:       1
Latest checkpoint's PrevTimeLineID:   1
Latest checkpoint's full_page_writes: on
Latest checkpoint's NextXID:          0:848603
Latest checkpoint's NextOID:          27921
Latest checkpoint's NextMultiXactId:  4

Field	Use
`Database cluster state`	`shut down` is clean; `in production` on a stopped cluster means it crashed
`Latest checkpoint's REDO location`	Where recovery will start
`Latest checkpoint's REDO WAL file`	The earliest segment that must exist
`Database system identifier`	Identifies the cluster lineage. Must match between a primary and its standbys
`Latest checkpoint's TimeLineID`	Which timeline. Relevant after any promotion

Latest checkpoint's REDO WAL file is the precise answer to “which WAL files do I still need” for crash recovery — that file and everything after it. It is not the answer for archiving or replication, which retain from their own positions.

Clean shutdown, for contrast

Read-only / Safethe same cluster after docker stop, which sends SIGTERM— Captured on 18.6. No redo, no recovery, no end-of-WAL message.

$ docker stop rbpg-stor && docker start rbpg-stor

LOG:  starting PostgreSQL 18.6 (Debian 18.6-1.pgdg13+2) on x86_64-pc-linux-gnu
LOG:  listening on IPv4 address "0.0.0.0", port 5432
LOG:  database system was shut down at 2026-08-27 21:01:27 UTC
LOG:  database system is ready to accept connections

database system was shut down at versus database system was interrupted; last known up at is how you determine, after the fact, whether the last stop was clean. It is the first line to look for in a post-incident log review.

Why recovery cannot be parallelised, and what that means for failover

The startup process replays WAL records strictly in order, in one process. The obvious question is why, given that the primary generated them from many concurrent backends.

The answer is that WAL is a serialised record of a total order. Record N+1 may depend on the state record N produced — a page split, a HOT chain link, a freeze — and there is no general way to determine from the records alone which pairs are independent. Applying them out of order risks producing a state the primary never had.

Some parallelism exists around the edges. recovery_prefetch reads pages ahead of the apply position so that I/O overlaps with CPU, which addresses the dominant cost on a cold cache. But the application of records is serial and is expected to remain so.

The operational consequences are the ones that matter for planning.

A primary can generate WAL faster than a standby can replay it. Sixty-four concurrent writers against one replaying process. This is the mechanism behind replication lag that grows without bound under load, and no amount of standby hardware fixes it beyond a point.

Recovery time is not improved by more CPUs. A sixty-four-core server recovers at the same rate as an eight-core one, given the same storage. The lever is storage latency and recovery_prefetch, not cores.

Failover time is dominated by replay backlog, not by the promotion itself. A standby that is 40 GB behind must apply 40 GB before it can be promoted, and that is measurable in advance:

SELECT pg_size_pretty(pg_last_wal_receive_lsn() - pg_last_wal_replay_lsn())
         AS unapplied_backlog;

Monitoring that number is monitoring your recovery time objective. Part XIV and Part XV develop this; the point here is that it follows from recovery being serial, which follows from WAL being a total order.

What to take from this

Recovery replays from the last checkpoint’s redo location to the end of the WAL, then checkpoints.
invalid record length … got 0 at LOG level before redo done is the normal end marker, not corruption.
Measured: 300,000 rows survived a SIGKILL; 65 MB replayed in 0.12 s.
Measure your own replay rate on a copy, and make the max_wal_size decision against it.
pg_controldata’s cluster state and REDO WAL file are the first two fields to read on a stopped cluster.
Replay is serial. More cores do not help; storage latency and recovery_prefetch do.

Cross-course references

Linux for Production Sysadmins — Part VIII (Logging and journald) covers capturing the redo log lines before they rotate, and Part LXXXII (Root cause analysis) covers establishing what caused the crash rather than being satisfied that recovery worked.
Docker & Containers — Part VI (Container lifecycle) covers the stop-then-kill sequence that makes a crash the normal case for a containerised cluster.