# 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 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)"](https://www.postgresql.org/docs/16/wal-intro.html). 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"](https://www.postgresql.org/docs/16/wal-async-commit.html), 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](https://www.postgresql.org/docs/16/wal-internals.html) 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](https://www.postgresql.org/docs/16/storage-page-layout.html) 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](https://www.postgresql.org/docs/16/mvcc-intro.html), and [The Internals of PostgreSQL, ch. 5](https://www.interdb.jp/pg/pgsql05.html) 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`](https://www.postgresql.org/docs/16/runtime-config-wal.html#GUC-FULL-PAGE-WRITES) If only one is new, make it #3. ## Environment - **Host:** macOS 26.5.2 (build 25F84), Apple Silicon (arm64) - **Docker:** Docker Desktop, Engine 29.6.2 — Linux VM kernel `6.12.76-linuxkit`, 16 GiB allocated to the VM - **Postgres image:** `postgres:16` — PostgreSQL 16.14 (Debian 16.14-1.pgdg13+1), digest `sha256:33f923b05f64ca54ac4401c01126a6b92afe839a0aa0a52bc5aeb5cc958e5f20` - **Captured:** 2026-07-26 Every LSN, xid, and byte count below is from that run. Yours will differ in the digits; the *relationships* between them are the exercise. ## 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/15AB6B0`. 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 within `wal_writer_delay` (200 ms by default). | **transactions committed in the last ~600 ms — after the client was told they succeeded.** The docs bound the risk window at three `wal_writer_delay`s. | 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 -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/15AB6E8 | 0/15AB6B0 | 0/15AB760 (1 row) ``` `redo_lsn` is the number that matters — the point recovery would start from if the server died right now. **Write it down.** (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/15AB6B0 | 0/15AF478 | 15816 (1 row) relblocknumber | isdirty ----------------+--------- 0 | t (1 row) ``` `redo_lsn` is unchanged — a `COMMIT` does not trigger a checkpoint. The WAL has grown by 15,816 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,816 bytes for three tiny rows?** (The exact figure is > illustrative — it depends on what else the backend touched. The > *composition* is the point.) Almost none of it is your rows. Dump > that exact WAL range: > > ```bash > 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%: > > ``` > rmgr: Heap2 len (rec/tot): 60/ 7616, tx: 0, lsn: 0/015AB760, prev 0/015AB6E8, desc: PRUNE snapshotConflictHorizon: 0, nredirected: 0, ndead: 1, blkref #0: rel 1663/5/1255 blk 82 FPW > rmgr: Heap2 len (rec/tot): 60/ 7376, tx: 0, lsn: 0/015AD538, prev 0/015AB760, desc: PRUNE snapshotConflictHorizon: 0, nredirected: 0, ndead: 1, blkref #0: rel 1663/5/1255 blk 45 FPW > ``` > > `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 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 -------------- 746 (1 row) ``` Leave B sitting exactly there. (Session A's transaction was 745.) 7. **A**: note where the WAL ends, then walk away from psql: ```sql SELECT pg_current_wal_lsn(); ``` ``` pg_current_wal_lsn -------------------- 0/15D3148 (1 row) ``` 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**: ``` 2026-07-25 16:07:30.957 UTC [29] LOG: database system was interrupted; last known up at 2026-07-25 16:06:12 UTC 2026-07-25 16:07:31.012 UTC [29] LOG: database system was not properly shut down; automatic recovery in progress 2026-07-25 16:07:31.015 UTC [29] LOG: redo starts at 0/15AB6B0 2026-07-25 16:07:31.016 UTC [29] LOG: invalid record length at 0/15D3148: expected at least 24, got 0 2026-07-25 16:07:31.016 UTC [29] LOG: redo done at 0/15D3110 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s 2026-07-25 16:07:31.018 UTC [27] LOG: checkpoint starting: end-of-recovery immediate wait 2026-07-25 16:07:31.025 UTC [27] LOG: checkpoint complete: wrote 37 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.003 s, sync=0.003 s, total=0.009 s; sync files=11, longest=0.002 s, average=0.001 s; distance=158 kB, estimate=158 kB; lsn=0/15D3148, redo lsn=0/15D3148 2026-07-25 16:07:31.027 UTC [1] LOG: database system is ready to accept connections ``` Read those three middle lines against your notes: - `redo starts at 0/15AB6B0` — character-for-character the `redo_lsn` you read in Part 1, step 5. Postgres found it in `pg_control` and began there. - `invalid record length at 0/15D3148: expected at least 24, got 0` is character-for-character the `pg_current_wal_lsn()` you read in step 7 — and it is *not* an error, despite reading like one. It is *how recovery knows where to stop*: `pg_current_wal_lsn()` is the byte where the *next* record would go, so recovery walks forward until it finds a header that is garbage or zeroes, which is exactly what that byte holds. Every crash recovery prints one. - `redo done at 0/15D3110` is 56 bytes *lower*, and that is the one worth pausing on. `redo done at` reports the LSN of the **start of the last record replayed**, not the end of the log. The last record in this run was 54 bytes (padded to 56), so `0/15D3110 + 56 = 0/15D3148`. Check it: ```bash 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 ``` ``` first record is after 0/15D3000, at 0/15D3080, skipping over 128 bytes rmgr: Standby len (rec/tot): 138/ 138, tx: 0, lsn: 0/015D3080, prev 0/015D2DB0, desc: INVALIDATIONS ; relcache init file inval dbid 1 tsid 1663; inval msgs: catcache 55 catcache 54 catcache 55 catcache 54 relcache 2696 relcache 2619 rmgr: Standby len (rec/tot): 54/ 54, tx: 0, lsn: 0/015D3110, prev 0/015D3080, desc: RUNNING_XACTS nextXid 747 latestCompletedXid 745 oldestRunningXid 746; 1 xacts: 746 ``` Note *which* record it is: `RUNNING_XACTS`, written by the background writer, listing `1 xacts: 746` — session B's still-open transaction. Nothing you typed produced the last record in the log. 11. **A** (reconnect): `SELECT * FROM orders ORDER BY id;` 12. **Observe**: ``` id | item ----+------------- 1 | committed-a 2 | committed-b 3 | committed-c (3 rows) ``` 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 | 745 | 0 | t | f 2 | 745 | 0 | t | f 3 | 745 | 0 | t | f 4 | 746 | 0 | f | t 5 | 746 | 0 | f | t 6 | 746 | 0 | f | t (6 rows) ``` Six tuples. The three "gone" rows are sitting right there, written by transaction 746 — the `txid_current()` session B printed before it died. They're readable: ```sql SELECT lp, t_xmin, t_data FROM heap_page_items(get_raw_page('orders',0)) WHERE lp > 3; ``` ``` lp | t_xmin | t_data ----+--------+---------------------------------------- 4 | 746 | \x0a0000001d756e636f6d6d69747465642d78 5 | 746 | \x0b0000001d756e636f6d6d69747465642d79 6 | 746 | \x0c0000001d756e636f6d6d69747465642d7a (3 rows) ``` `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/15AB6B0 -e 0/15D3148 \ | grep -E '16437|Transaction' ``` (`16437` is the table's `relfilenode`, from `SELECT relfilenode FROM pg_class WHERE relname='orders'`.) 17. **Observe**: ``` rmgr: Heap len (rec/tot): 71/ 71, tx: 745, lsn: 0/015AF258, prev 0/015AF220, desc: INSERT+INIT off: 1, flags: 0x00, blkref #0: rel 1663/5/16437 blk 0 rmgr: Heap len (rec/tot): 71/ 71, tx: 745, lsn: 0/015AF340, prev 0/015AF300, desc: INSERT off: 2, flags: 0x00, blkref #0: rel 1663/5/16437 blk 0 rmgr: Heap len (rec/tot): 71/ 71, tx: 745, lsn: 0/015AF3C8, prev 0/015AF388, desc: INSERT off: 3, flags: 0x00, blkref #0: rel 1663/5/16437 blk 0 rmgr: Transaction len (rec/tot): 34/ 34, tx: 745, lsn: 0/015AF450, prev 0/015AF410, desc: COMMIT 2026-07-25 16:06:24.624596 UTC rmgr: Heap len (rec/tot): 73/ 73, tx: 746, lsn: 0/015B0CA0, prev 0/015B0C68, desc: INSERT off: 4, flags: 0x00, blkref #0: rel 1663/5/16437 blk 0 rmgr: Heap len (rec/tot): 73/ 73, tx: 746, lsn: 0/015B0D30, prev 0/015B0CF0, desc: INSERT off: 5, flags: 0x00, blkref #0: rel 1663/5/16437 blk 0 rmgr: Heap len (rec/tot): 73/ 73, tx: 746, lsn: 0/015B0DC0, prev 0/015B0D80, desc: INSERT off: 6, flags: 0x00, blkref #0: rel 1663/5/16437 blk 0 ``` Six `INSERT` records. **One `COMMIT` record, 34 bytes long.** Transaction 746 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 746 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/15DA0C8 | 0/15DA0C8 | 0 <- synchronous_commit = on (1 row) inserted | flushed_to_disk | unflushed_bytes -----------+-----------------+----------------- 0/15DA178 | 0/15DA0C8 | 176 <- synchronous_commit = off (1 row) ``` 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 2>&1 ``` 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**: ``` 73044 <- commits acknowledged to the client count | max -------+------- 73013 | 73013 (1 row) ``` **31 transactions that returned success no longer exist.** Not corrupted, not partially applied — ids 73,014 through 73,044 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. The count is timing-dependent and *will* differ for you: it is however much WAL the WAL writer had not yet flushed at the instant of the kill, which §30.4 bounds at three `wal_writer_delay`s — about 600 ms of commits. What is not timing-dependent is that it is greater than zero. 24. **Predict**: repeat it exactly, with `synchronous_commit = on` (`DROP TABLE async_log`, recreate it, `CHECKPOINT`, and rerun the same load with the first line flipped to `on`). Same ~6 seconds, same kill. 25. **Observe**: ``` 15011 <- commits acknowledged to the client count | max -------+------- 15011 | 15011 (1 row) ``` Zero lost. Every acknowledgement the client received corresponds to a row that is still there. (The error can only ever go the *other* way with `on`: if the server dies after the `fsync` but before the `INSERT 0 1` gets back through the socket, the count in the table is one *higher* than the client saw, and a client that retries finds the row already present. 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 73,044 commits and `on` finished 15,011 — **4.9×** (illustrative; the ratio, not the digits, is the point). That throughput is what you are buying with those 31 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 ------------+-----------+---------- 15167 | 5001 | 5001 sync off 15167 | 105 | 4 ``` Identical WAL *volume* — 15,167 records both times, for the same work. The setting doesn't reduce logging by a single byte. What changes is `wal_sync`: **5,001 fsyncs versus 4**. One durable point per commit, versus one every 200 ms because the WAL writer woke up. Wall clock for the batch (illustrative): 2.55 s vs 0.51 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/27E4F78 | 0/27E5028 | 176 (1 row) ``` 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**: ``` 2026-07-25 16:10:28.946 UTC [29] LOG: database system was not properly shut down; automatic recovery in progress 2026-07-25 16:10:28.947 UTC [29] LOG: redo starts at 0/27E4F78 2026-07-25 16:10:28.947 UTC [29] LOG: redo done at 0/27E4FB0 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 400,000 inserts had been running since the last checkpoint: ``` 2026-07-25 16:09:07.631 UTC [29] LOG: database system was not properly shut down; automatic recovery in progress 2026-07-25 16:09:07.632 UTC [29] LOG: redo starts at 0/15FFED8 2026-07-25 16:09:07.684 UTC [29] LOG: redo done at 0/22A5FC0 system usage: CPU: user: 0.04 s, system: 0.00 s, elapsed: 0.05 s ``` `0/22A5FC0 - 0/15FFED8` = 13,263,080 bytes: **12.6 MB of WAL, 0.05 s of replay** — versus 56 bytes and 0.00 s. 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. Scale that 12.6 MB to a production `max_wal_size` of a few GB and the 0.05 s becomes 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/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`, 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 16 Docs §30.3: Write-Ahead Logging (WAL)](https://www.postgresql.org/docs/16/wal-intro.html) - [PostgreSQL 16 Docs §30.4: Asynchronous Commit](https://www.postgresql.org/docs/16/wal-async-commit.html) - [PostgreSQL 16 Docs §30.1: Reliability](https://www.postgresql.org/docs/16/wal-reliability.html) — what `fsync` does and does not guarantee about disk caches. - [PostgreSQL 16 Docs: `synchronous_commit`](https://www.postgresql.org/docs/16/runtime-config-wal.html#GUC-SYNCHRONOUS-COMMIT) - [PostgreSQL 16 Docs: `pg_waldump`](https://www.postgresql.org/docs/16/pgwaldump.html) ## 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. ```bash docker stop pg-wal && docker rm -v pg-wal rm -f bulk.sql acked.log ```