WAL and Crash Recovery

When COMMIT returns, your rows are not in the table. SIGKILL a running Postgres and watch it rebuild itself from the log — then turn one setting off and lose transactions that had already reported success.

Concept

When COMMIT returns, your rows are not in the table file. They're in the write-ahead log — a sequential append-only journal — and the actual table page is still a dirty buffer in RAM that nobody has written down. The promise Postgres makes is narrower than "your data is saved": it is "the intent to save your data has been fsynced to a log, and I can reconstruct the table from that log after a crash."

This exercise kills a running Postgres with SIGKILL — no clean shutdown, no chance to flush anything — and then watches it rebuild itself from that log. You'll see committed-but-never-checkpointed rows come back, watch uncommitted rows get replayed onto disk and then be ignored anyway, and finish by turning one GUC off and losing a few dozen transactions that had already told the client they succeeded.

Provenance

PostgreSQL 16 documentation, Chapter 30 Reliability and the Write-Ahead Log, §30.3 "Write-Ahead Logging (WAL)". The claim Parts 1–3 and 5 test:

If we follow this procedure, we do not need to flush data pages to disk on every transaction commit, because we know that in the event of a crash we will be able to recover the database using the log: any changes that have not been applied to the data pages can be redone from the WAL records. (This is roll-forward recovery, also known as REDO.)

Part 4 tests §30.4 "Asynchronous Commit", which is unusually blunt about what it is selling you:

Asynchronous commit introduces the risk of data loss. There is a short time window between the report of transaction completion to the client and the time that the transaction is truly committed (that is, it is guaranteed not to be lost if the server crashes).

and, in the same section, the two bounds that keep it from being reckless:

The duration of the risk window is limited because a background process (the "WAL writer") flushes unwritten WAL records to disk every wal_writer_delay milliseconds. The actual maximum duration of the risk window is three times wal_writer_delay…

The risk that is taken by using asynchronous commit is of data loss, not data corruption.

If a prediction here fails, those two pages are where to go.

Prerequisites

The exercise reads raw heap pages and raw WAL records, so a few things it does not stop to explain carry most of the result. One line each, and where they show up.

1. LSNs are byte offsets. A log sequence number like 0/15AB6B0 is a position in the WAL, so subtracting two of them yields bytes. Used throughout: pg_current_wal_lsn() - redo_lsn in Parts 1 and 5 is literally "how many bytes would recovery have to replay". — PostgreSQL: WAL Internals
2. The heap page and its line pointers. A table is a file of 8 KB pages; each row version (tuple) sits at a slot lp inside a page, with a header carrying t_xmin (the transaction that created it). Used in Part 3, where heap_page_items() shows six tuples on page 0. — PostgreSQL: Database Page Layout
3. MVCC visibility and hint bits. (carries Part 3) A tuple is visible if its t_xmin committed. Postgres caches that verdict in t_infomask — bit 256 XMIN_COMMITTED, bit 512 XMIN_INVALID — the first time anyone reads the tuple. This is the whole reason Part 3 works: the uncommitted rows are physically present and simply never visible, so "rollback" after a crash costs nothing. — PostgreSQL: Transaction Isolation / MVCC, and The Internals of PostgreSQL, ch. 5 for the hint bits specifically.
4. Full-page writes. (carries the Part 1 byte count) The first time a page is touched after a checkpoint, the whole 8 KB image goes into the WAL, so a torn write can be repaired rather than merely replayed. Without this, Part 1's "15,816 bytes for three tiny rows" looks like a bug. — PostgreSQL: full_page_writes

If only one is new, make it #3.

Mental model 1: where your row actually is

A single INSERT ... COMMIT moves data through four places. Only two of them are on disk, and they're not the two you'd guess:

Two more terms close the loop:

Recovery is then a two-line algorithm: read the redo LSN out of pg_control, and replay every WAL record from there to the end of the log. Everything before the redo LSN is already on disk by definition; everything after it is in the WAL by definition. That's the whole mechanism.

Mental model 2: synchronous_commit, and what each level costs you

Part 4 turns the knob that decides how hard COMMIT works before it answers. These are the levels, weakest last:

Setup

Two terminals, side by side. Everything below assumes you have Docker.

docker run --name pg-wal -e POSTGRES_PASSWORD=postgres -d postgres:16

Terminal A:

docker exec -it pg-wal psql -U postgres

Terminal B (a second, independent connection — needed from Part 2):

docker exec -it pg-wal psql -U postgres

In A, create the schema:

CREATE EXTENSION pageinspect;
CREATE EXTENSION pg_buffercache;
CREATE TABLE orders (id int PRIMARY KEY, item text);

Both extensions ship with the official image. pg_buffercache lets you see which pages are dirty in shared memory; pageinspect lets you read raw heap pages, which is how Part 3 catches Postgres red-handed.

Part 1 — a commit that is not on disk

What this part tests: mental model 1's claim that after COMMIT, the table page is still only in RAM. If that's true, there must be a moment where the rows are unquestionably committed and the heap buffer is unquestionably dirty.

CHECKPOINT;
SELECT checkpoint_lsn, redo_lsn, pg_current_wal_lsn()
FROM pg_control_checkpoint();

INSERT INTO orders VALUES (1,'committed-a'),(2,'committed-b'),(3,'committed-c');

SELECT redo_lsn, pg_current_wal_lsn(),
       pg_current_wal_lsn() - redo_lsn AS wal_bytes_to_replay
FROM pg_control_checkpoint();

SELECT relblocknumber, isdirty FROM pg_buffercache
WHERE relfilenode = (SELECT relfilenode FROM pg_class WHERE relname = 'orders');

docker exec -i pg-wal /usr/lib/postgresql/16/bin/pg_waldump \
  -p /var/lib/postgresql/data/pg_wal -s 0/15AB6B0 -e 0/15AF478

Two of the thirteen records it prints account for 14,992 of the 15,816 bytes — 95%:

len (rec/tot): 60/7616 is a 60-byte record carrying a 7.5 KB page image, and FPW says so outright — these are full-page writes of two pg_proc pages (relation 1255) that CREATE EXTENSION had left with dead tuples. The first time a page is modified after a checkpoint, Postgres copies the entire 8 KB page into the WAL, so that a torn write (an 8 KB page half-written when the power died) can be repaired rather than merely re-applied. Your three actual rows are three 71/71 records. This is why WAL volume spikes right after every checkpoint, and why checkpointing more often makes a write-heavy server slower, not faster.

Part 2 — kill it

What this part tests: the recovery algorithm from the mental model — start at redo_lsn, replay to the end. You wrote redo_lsn down in Part 1; the log should print that exact number back at you.

BEGIN;
INSERT INTO orders VALUES (10,'uncommitted-x'),(11,'uncommitted-y'),(12,'uncommitted-z');
SELECT txid_current();

SELECT pg_current_wal_lsn();

docker kill --signal=KILL pg-wal
docker start pg-wal
docker logs pg-wal | tail -8

docker exec -i pg-wal /usr/lib/postgresql/16/bin/pg_waldump \
  -p /var/lib/postgresql/data/pg_wal -s 0/15D3000 -e 0/15D3148

SELECT * FROM orders ORDER BY id;

Part 3 — the uncommitted rows are on disk anyway

What this part tests: how the uncommitted rows are gone. The obvious theory is that recovery skipped them. It didn't. This is the part worth slowing down for.

SELECT lp, t_xmin, t_xmax,
       t_infomask & 256 > 0 AS xmin_committed,
       t_infomask & 512 > 0 AS xmin_aborted
FROM heap_page_items(get_raw_page('orders', 0));

SELECT lp, t_xmin, t_data FROM heap_page_items(get_raw_page('orders',0)) WHERE lp > 3;

docker exec -i pg-wal /usr/lib/postgresql/16/bin/pg_waldump \
  -p /var/lib/postgresql/data/pg_wal -s 0/15AB6B0 -e 0/15D3148 \
  | grep -E '16437|Transaction'

That is why the WAL can be written before the outcome is known, and why an aborted transaction is as cheap as a committed one. It's also the difference from an undo-log database like InnoDB, which must actively roll back uncommitted work during recovery.

Part 4 — the commit that lies

What this part tests: mental model 2's bottom row. synchronous_commit = off moves exactly one thing — the fsync — off the commit path. The claim is that the client is then told "success" about transactions that are still only in RAM.

SET synchronous_commit = on;
INSERT INTO orders VALUES (30,'sync-on');
SELECT pg_current_wal_insert_lsn() AS inserted,
       pg_current_wal_flush_lsn()  AS flushed_to_disk,
       pg_current_wal_insert_lsn() - pg_current_wal_flush_lsn() AS unflushed_bytes;

SET synchronous_commit = off;
INSERT INTO orders VALUES (31,'sync-off');
-- ...same SELECT again

CREATE TABLE async_log (id serial PRIMARY KEY, note text);
CHECKPOINT;

python3 -c "
print('SET synchronous_commit = off;')
for i in range(1,400001): print(\"INSERT INTO async_log(note) VALUES ('r%d');\" % i)
" > bulk.sql
docker exec -i pg-wal psql -U postgres -t < bulk.sql > acked.log 2>&1

docker kill --signal=KILL pg-wal
grep -c "INSERT 0 1" acked.log
docker start pg-wal
docker exec -i pg-wal psql -U postgres -c "SELECT count(*), max(id) FROM async_log;"

SELECT wal_records, wal_write, wal_sync FROM pg_stat_wal;

Part 5 — what a checkpoint actually buys

What this part tests: the other half of the checkpoint's job. It doesn't make anything more durable — Parts 2 and 4 were durable via WAL alone — so what is it for?

CHECKPOINT;
SELECT redo_lsn, pg_current_wal_lsn(),
       pg_current_wal_lsn() - redo_lsn AS to_replay
FROM pg_control_checkpoint();

docker kill --signal=KILL pg-wal && docker start pg-wal

What you should see

A COMMIT that returns while pg_buffercache still reports the table page as isdirty = t — committed and not on disk. A SIGKILLed server that comes back printing redo starts at 0/15AB6B0, the exact redo LSN you read before the crash, and invalid record length at 0/15D3148, the exact WAL position you read before the crash — and hands you back three rows that never touched the table file. Six tuples on page 0 of that table, half of them belonging to a transaction that never committed, replayed onto disk and rendered invisible not by recovery but by the absence of a single 34-byte COMMIT record in the WAL. And, with synchronous_commit = off, some number of transactions — 31 in this run — that returned success to the client and no longer exist.

Why

Because the only cheap durable write is a sequential append. A commit that had to place rows into their final positions in the table file would mean a random write per page touched, plus an fsync, on the latency path of every transaction. The WAL replaces all of that with one append to one file and one fsync, and buys back the correctness by promising that the table can always be reconstructed from the log. Checkpointing is then just amortization: it does the expensive scattered writes in the background, on its own schedule, and moves the redo LSN forward so the log doesn't have to be replayed from the beginning of time.

Given that, everything else in this exercise is a corollary. Recovery starts at the redo LSN because that's where disk stopped being trustworthy (Part 2). It stops when it reads a record header that isn't one, because a log killed mid-append has no end marker — only garbage after the last good byte. It replays uncommitted changes because it is a physical byte-level redo that doesn't know or care about transaction outcomes, and because MVCC will filter them out afterward at no cost (Part 3) — a Postgres transaction is committed precisely when its commit record is in the log, and rollback is therefore free. Full-page writes exist because fsync guarantees ordering, not atomicity, and an 8 KB page can still be torn by a power failure mid-write (Part 1).

And synchronous_commit = off is the one setting that breaks the promise on purpose. It doesn't skip the log or reorder it — recovery still stops at a perfectly consistent point, which is why it cannot corrupt anything. It just moves the fsync off the commit path, so the point where recovery stops can be earlier than what the client was told. That is a coherent trade for clickstream data and an incoherent one for money, and the ~5× throughput is exactly the size of the bribe.

Go deeper

• Set fsync = off (in postgresql.conf, requires a restart) and repeat Part 4. This is the genuinely dangerous one, and the contrast is the point: synchronous_commit = off loses recent transactions, fsync = off lets the OS reorder writes and can leave you with a corrupt cluster that won't start. Postgres will warn you at startup.
• Repeat Part 2 but SIGKILL only the checkpointer (pkill -9 -f checkpointer inside the container) instead of the postmaster. The postmaster notices a child died uncleanly and takes the whole cluster down into recovery on purpose — one crashed backend can have corrupted shared memory, so nothing in it can be trusted.
• Run pg_waldump across an UPDATE and a DELETE instead of an INSERT. There is no "delete the row" record type — you'll see Heap/DELETE setting xmax on the existing tuple, and Heap/UPDATE writing a new tuple plus a forward pointer. The WAL is a log of page edits, not of SQL statements, which is what makes physical replication possible.
• Watch the distance= and estimate= figures in the checkpoint-complete log lines while running Part 4's bulk load. That's the feedback loop Postgres uses to pace checkpoint I/O against checkpoint_completion_target.
• The same mechanism from the other side: point-in-time recovery. Archive WAL segments, take a pg_basebackup, then restore with a recovery_target_time partway through the log and watch recovery stop early on purpose.

Sources: PostgreSQL 16 Docs §30.3: Write-Ahead Logging (WAL) · §30.4: Asynchronous Commit · §30.1: Reliability, on what fsync does and does not guarantee about disk caches · synchronous_commit · pg_waldump

Cleanup

docker rm -v matters: the official image declares an anonymous volume for /var/lib/postgresql/data, and a plain docker rm leaves it behind.

docker stop pg-wal && docker rm -v pg-wal
rm -f bulk.sql acked.log