# Postgres: WAL and crash recovery ## 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 35 transactions that had already told the client they succeeded. ## 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: | Place | What's there | Survives `kill -9`? | | --- | --- | --- | | **The heap page in `shared_buffers`** | The real, final row, in the real table page. Marked *dirty*: memory disagrees with disk. | No. RAM. | | **The WAL buffer** | A compact description of the change ("insert this tuple at offset 3 of block 0 of relation 16437"). | No. RAM. | | **The WAL file on disk** (`pg_wal/…`) | The same description, appended sequentially and `fsync`ed. **This is what `COMMIT` waits for.** | **Yes.** | | **The heap file on disk** (`base/…`) | The table as the OS sees it — as of the last time somebody wrote those pages out. | Yes, but it's *stale*, and that's fine. | The gap between the last two is the entire design. Writing the WAL is one sequential append + one `fsync`; writing the heap would be a scattered random write per dirty page. So Postgres makes the commit path pay only for the cheap one, and defers the expensive one indefinitely. Two more terms close the loop: | Term | What it is | | --- | --- | | **LSN** (log sequence number) | A byte offset into the WAL, printed as `0/15AEA20`. Every WAL record has one. Subtracting two LSNs gives you bytes, which is why you can do arithmetic on them in SQL. | | **Checkpoint** | Postgres flushes every dirty buffer to the heap files and records "as of LSN *X*, disk is caught up". *X* is the **redo LSN**. | 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: | Level | `COMMIT` returns after… | What a `kill -9` loses | Reach for it when… | | --- | --- | --- | --- | | `remote_apply` | the standby has replayed the commit and it's *visible* to readers there | nothing | You load-balance reads onto replicas and a user must never write, redirect, and read their own write as missing. The most expensive setting: every commit waits a full round trip plus replay. | | `on` (default) | the local WAL is `fsync`ed **and** the standby has flushed it, if you have synchronous standbys | nothing | The default, and correct for anything that represents money, identity, or a legal record. Non-negotiable for the system of record. | | `remote_write` | local `fsync` + standby has `write()`n the WAL, but not `fsync`ed it | nothing on a Postgres crash; data if the *standby's OS* crashes at the same moment as the primary | Cross-region replicas where you'll accept a double-fault window to avoid paying the remote disk latency on every commit. | | `local` | the local WAL is `fsync`ed. Ignores standbys entirely. | nothing on this node | Per-transaction escape hatch: a bulk import into a table you'd rather not stall on a slow replica, while everything else keeps waiting for it. | | `off` | …nothing. The commit record is in a memory buffer; the WAL writer will get to it, typically within 200 ms. | **every transaction committed in the last ~600 ms — after the client was told they succeeded** | Data you can regenerate: clickstream, metrics, session heartbeats, a cache warm-up. Crucially, it is *not* like `fsync = off` — it never corrupts anything, it only ever loses whole recent transactions. | Two properties are worth pinning down before you touch it. `off` is **per-transaction** — `SET LOCAL synchronous_commit = off` inside one transaction, and it's the only one at risk. And `off` **cannot corrupt your database**: the WAL is still written in order, so recovery still ends at a consistent point. It just ends earlier than the client believed. ## Setup Two terminals, side by side. Everything below assumes you have Docker. ```bash docker run --name pg-wal -e POSTGRES_PASSWORD=postgres -p 5432:5432 -d postgres:16 ``` Note the missing `--rm`: this container has to survive being killed and be started again, which is the entire exercise. Clean it up at the end. Terminal A: ```bash docker exec -it pg-wal psql -U postgres ``` Terminal B (a second, independent connection — needed from Part 2): ```bash docker exec -it pg-wal psql -U postgres ``` In **A**, create the schema: ```sql 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. ## Steps ### 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. 1. **A**: force a checkpoint so disk is caught up, then look at where the WAL stands: ```sql CHECKPOINT; SELECT checkpoint_lsn, redo_lsn, pg_current_wal_lsn() FROM pg_control_checkpoint(); ``` ``` checkpoint_lsn | redo_lsn | pg_current_wal_lsn ----------------+-----------+-------------------- 0/15AEA58 | 0/15AEA20 | 0/15AEAD0 ``` `redo_lsn` is the number that matters — the point recovery would start from if the server died right now. (Your LSNs will differ; only the *differences* between them are meaningful.) 2. **A**: commit three rows. ```sql INSERT INTO orders VALUES (1,'committed-a'),(2,'committed-b'),(3,'committed-c'); ``` 3. **Predict**: that's a committed transaction. Has `redo_lsn` moved? Is the table page on disk? 4. **A**: ```sql 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'); ``` 5. **Observe**: ``` redo_lsn | pg_current_wal_lsn | wal_bytes_to_replay -----------+--------------------+--------------------- 0/15AEA20 | 0/15B27B0 | 15760 relblocknumber | isdirty ----------------+--------- 0 | t ``` `redo_lsn` is unchanged — a `COMMIT` does not trigger a checkpoint. The WAL has grown by 15,760 bytes and the only copy of your three rows that a reader could use is `isdirty = t`: block 0, in memory, disagreeing with the file on disk. **Committed, and not on disk.** That is the normal steady state of a running Postgres, not an edge case. > **15,760 bytes for three tiny rows?** Almost all of it is > *full-page writes*. 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. `pg_waldump` shows > two of them here as `len (rec/tot): 60/7616` — a 60-byte record > carrying a 7.5 KB page image. 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 down `redo_lsn` in Part 1; the log should print that exact number back at you. 6. **B**: open a transaction, write three more rows, and *do not commit*: ```sql BEGIN; INSERT INTO orders VALUES (10,'uncommitted-x'),(11,'uncommitted-y'),(12,'uncommitted-z'); SELECT txid_current(); ``` ``` txid_current -------------- 745 ``` Leave B sitting exactly there. (Session A's transaction was 744.) 7. **A**: note where the WAL ends, then walk away from psql: ```sql SELECT pg_current_wal_lsn(); ``` ``` pg_current_wal_lsn -------------------- 0/15B5D98 ``` 8. **Predict**: you are about to `SIGKILL` the postmaster. No shutdown checkpoint, no buffer flush, no chance to run any code at all. Which of the six rows come back? 9. **Host shell** — kill and restart: ```bash docker kill --signal=KILL pg-wal docker start pg-wal docker logs pg-wal | tail -8 ``` 10. **Observe**: ``` LOG: database system was interrupted; last known up at 2026-07-22 15:13:13 UTC LOG: database system was not properly shut down; automatic recovery in progress LOG: redo starts at 0/15AEA20 LOG: invalid record length at 0/15B7A30: expected at least 24, got 0 LOG: redo done at 0/15B5D98 system usage: CPU: user: 0.00 s, system: 0.00 s LOG: checkpoint starting: end-of-recovery immediate wait LOG: database system is ready to accept connections ``` Read those three middle lines against your notes: - `redo starts at 0/15AEA20` — character-for-character the `redo_lsn` you read in Part 1, step 5. Postgres found it in `pg_control` and began there. - `redo done at 0/15B5D98` — character-for-character the `pg_current_wal_lsn()` you read in step 7. It replayed right up to the last byte that existed when the process died. - `invalid record length at 0/15B7A30: expected at least 24, got 0` is not an error, despite reading like one. It is *how recovery knows where to stop*: it walks forward until the next record header is garbage or zeroes, which is exactly what the tail of a WAL segment killed mid-stream looks like. Every crash recovery prints one. 11. **A** (reconnect): `SELECT * FROM orders ORDER BY id;` 12. **Observe**: ``` id | item ----+------------- 1 | committed-a 2 | committed-b 3 | committed-c ``` The three committed rows are back — reconstructed purely from the WAL, since Part 1 proved they were never written to the table file. The three uncommitted rows are gone. Session B is gone too; its connection died with the server, which for an open transaction is an implicit rollback. ### 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. 13. **Predict**: rows 10–12 are not visible. Are they physically on page 0 of the table file? 14. **A**: read the raw page. ```sql 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)); ``` 15. **Observe**: ``` lp | t_xmin | t_xmax | xmin_committed | xmin_aborted ----+--------+--------+----------------+-------------- 1 | 744 | 0 | t | f 2 | 744 | 0 | t | f 3 | 744 | 0 | t | f 4 | 745 | 0 | f | t 5 | 745 | 0 | f | t 6 | 745 | 0 | f | t ``` Six tuples. The three "gone" rows are sitting right there, written by transaction 745 — the `txid_current()` session B printed before it died. They're readable: ```sql SELECT lp, t_data FROM heap_page_items(get_raw_page('orders',0)) WHERE lp > 3; ``` ``` lp | t_xmin | t_data ----+--------+---------------------------------------- 4 | 745 | \x0a0000001d756e636f6d6d69747465642d78 5 | 745 | \x0b0000001d756e636f6d6d69747465642d79 6 | 745 | \x0c0000001d756e636f6d6d69747465642d7a ``` `756e636f6d6d69747465642d78` is ASCII for `uncommitted-x`. Recovery replayed those inserts into the page just as faithfully as the committed ones. 16. **A**: check the WAL itself to see why. From the host shell: ```bash docker exec -i pg-wal /usr/lib/postgresql/16/bin/pg_waldump \ -p /var/lib/postgresql/data/pg_wal -s 0/15AEA20 -e 0/15B5D98 \ | grep -E '16437|Transaction' ``` (`16437` is the table's `relfilenode`, from `SELECT relfilenode FROM pg_class WHERE relname='orders'`.) 17. **Observe**: ``` tx: 744, lsn: 0/015B2590, desc: INSERT+INIT off: 1, blkref #0: rel 1663/5/16437 blk 0 tx: 744, lsn: 0/015B2678, desc: INSERT off: 2, blkref #0: rel 1663/5/16437 blk 0 tx: 744, lsn: 0/015B2700, desc: INSERT off: 3, blkref #0: rel 1663/5/16437 blk 0 tx: 744, lsn: 0/015B2788, desc: COMMIT 2026-07-22 15:13:13.650095 UTC tx: 745, lsn: 0/015B3E20, desc: INSERT off: 4, blkref #0: rel 1663/5/16437 blk 0 tx: 745, lsn: 0/015B3EB0, desc: INSERT off: 5, blkref #0: rel 1663/5/16437 blk 0 tx: 745, lsn: 0/015B3F40, desc: INSERT off: 6, blkref #0: rel 1663/5/16437 blk 0 ``` Six `INSERT` records. **One `COMMIT` record.** Transaction 745 has three inserts and no commit and no abort — nothing ever got the chance to write one. So the durability rule isn't "uncommitted changes aren't logged" — they're logged, and replayed, and land on disk. The rule is: **a transaction is committed if and only if its commit record is in the WAL.** Recovery restores *physical bytes*; visibility is decided afterward by MVCC, which finds xid 745 in neither the commit log nor the list of in-progress transactions, concludes it aborted, and stamps `xmin_aborted` on those tuples the first time anyone looks at them. Later, `VACUUM` collects them. Rollback after a crash costs nothing because there is nothing to undo — the tuples are simply never visible. This 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. 18. **A**: compare the two settings without crashing anything: ```sql 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'); 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; ``` 19. **Observe**: ``` inserted | flushed_to_disk | unflushed_bytes -----------+-----------------+----------------- 0/15BD1C0 | 0/15BD1C0 | 0 <- synchronous_commit = on 0/15BD270 | 0/15BD1C0 | 176 <- synchronous_commit = off ``` No race, no timing trick: `INSERT 0 1` came back, and 176 bytes of WAL — including that transaction's own commit record — are sitting in a memory buffer. `pg_current_wal_flush_lsn()` is the durability watermark, and your commit is above it. 20. Now make it cost something. **A**: a fresh table, and a large batch of individually-committed inserts: ```sql CREATE TABLE async_log (id serial PRIMARY KEY, note text); CHECKPOINT; ``` From the host shell, generate 400,000 single-row autocommit inserts and feed them in: ```bash 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 ``` 21. **Predict**: after ~6 seconds, from another terminal, `docker kill --signal=KILL pg-wal`. Every line in `acked.log` is a transaction Postgres told the client it had committed. How many of them come back? 22. **Host shell**: kill it, count the acknowledgements, restart, count the rows. ```bash 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;" ``` 23. **Observe**: ``` 197138 <- commits acknowledged to the client count | max --------+-------- 197103 | 197103 ``` **35 transactions that returned success no longer exist.** Not corrupted, not partially applied — ids 197104 through 197138 are simply not in the table, and the table is perfectly consistent without them. If those had been payments, the client-side ledger and the database now disagree, and nothing anywhere logged an error. 24. **Predict**: repeat it exactly, with `synchronous_commit = on`. Same 6 seconds, same kill. 25. **Observe**: ``` 46783 <- commits acknowledged to the client count | max -------+------- 46784 | 46784 ``` Zero lost — and one row *more* than the client saw acknowledged. That extra row is the honest direction of the error: transaction 46,784 was fsynced and durable, and the server died before its `INSERT 0 1` made it back through the socket. A client that retries it will find it already there. Losing an acknowledgement is a recoverable problem; losing an acknowledged transaction is not. Also read the *other* number in that output. In the same 6 seconds, `off` finished 197,138 commits and `on` finished 46,783 — **4.2×**. That throughput is what you are buying with those 35 transactions. 26. **A**: confirm where the difference comes from — 5,000 commits each way, with `SELECT pg_stat_reset_shared('wal');` in between: ```sql SELECT wal_records, wal_write, wal_sync FROM pg_stat_wal; ``` 27. **Observe**: ``` wal_records | wal_write | wal_sync sync on ------------+-----------+---------- 15195 | 5002 | 5002 sync off 15193 | 111 | 4 ``` Identical WAL *volume* — 15,195 vs 15,193 records for the same work. The setting doesn't reduce logging by a single byte. What changes is `wal_sync`: **5,002 fsyncs versus 4**. One durable point per commit, versus one every 200 ms because the WAL writer woke up. Wall clock for the batch: 1.22 s vs 0.58 s. ### 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? 28. **A**: run the 5,000-insert batch again, then: ```sql CHECKPOINT; SELECT redo_lsn, pg_current_wal_lsn(), pg_current_wal_lsn() - redo_lsn AS to_replay FROM pg_control_checkpoint(); ``` ``` redo_lsn | pg_current_wal_lsn | to_replay -----------+--------------------+----------- 0/4D3FF00 | 0/4D3FFB0 | 176 ``` 29. **Predict**: kill it right now. How much work does recovery do? 30. **Host shell**: `docker kill --signal=KILL pg-wal && docker start pg-wal`, then read the log. 31. **Observe**: ``` LOG: database system was not properly shut down; automatic recovery in progress LOG: redo starts at 0/4D3FF00 LOG: redo done at 0/4D3FF38 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s ``` 56 bytes replayed, 0.00 s. Compare the crash in Part 4, where nothing had been checkpointed for a while: ``` LOG: redo starts at 0/2056E90 LOG: redo done at 0/427FFC0 system usage: CPU: user: 0.12 s, system: 0.01 s, elapsed: 0.13 s ``` 35 MB of WAL, 0.13 s of replay. Same durability guarantee in both cases — no committed transaction was lost either time. The only thing the checkpoint changed is **how long you are down afterward**, and that's the trade the `max_wal_size` / `checkpoint_timeout` knobs control: checkpoint often and pay steady random I/O plus full-page writes forever, or checkpoint rarely and pay it all at once as downtime after a crash. On a busy production server that 0.13 s is minutes. ## 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 `SIGKILL`ed server that comes back printing `redo starts at 0/15AEA20`, the exact redo LSN you read before the crash, and `redo done at 0/15B5D98`, 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`, 35 transactions 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 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 4.2× 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`, and note there is no `DELETE` 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. - Set `log_checkpoints = on` (it already is in recent versions) and watch the `distance=` and `estimate=` figures in the checkpoint-complete 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. ## Further reading - [PostgreSQL Docs: Reliability and the Write-Ahead Log](https://www.postgresql.org/docs/current/wal.html) — including `wal-reliability`, on what `fsync` does and does not guarantee about disk caches. - [PostgreSQL Docs: `synchronous_commit`](https://www.postgresql.org/docs/current/runtime-config-wal.html#GUC-SYNCHRONOUS-COMMIT) - [PostgreSQL Docs: `pg_waldump`](https://www.postgresql.org/docs/current/pgwaldump.html) ## Cleanup ```bash docker stop pg-wal && docker rm pg-wal ```