Lab 16: Cause a checkpoint storm, then stop it with one setting

Objective

A checkpoint writes every dirty buffer to disk so that recovery can start from a known-good point. It is one of the few pieces of PostgreSQL that periodically does a great deal of I/O all at once, and one of the few whose misconfiguration is directly visible in a log line.

By the end of this lab you will be able to read that log line completely — every field, including the ones people skip — and you will have produced a checkpoint storm on purpose and then removed it by changing one number.

The storm is worth building because it is a common production failure that presents as “the database gets slow every few minutes” and is almost never diagnosed from that symptom.

Architecture

One table, deliberately larger than a comfortable fraction of shared_buffers, updated repeatedly under two different max_wal_size settings.

flowchart TD
    W["write workload\nrepeated full-table UPDATE"] --> WAL["WAL accumulates"]
    WAL --> C1{"WAL since last checkpoint\n> max_wal_size?"}
    C1 -->|yes| R["requested checkpoint\nlog: checkpoint starting: wal"]
    T["checkpoint_timeout elapsed"] --> C2{"anything changed?"}
    C2 -->|yes| TC["timed checkpoint\nlog: checkpoint starting: time"]
    C2 -->|no| SK["skipped\nnum_done does not advance"]
    M["CHECKPOINT command"] --> IC["log: checkpoint starting: immediate force wait"]
    R --> S["pg_stat_checkpointer"]
    TC --> S
    IC --> S

Requirements

A PostgreSQL 18 cluster with superuser access, whose max_wal_size you can change. The lab lowers it to 96 MB temporarily, which on a busy server would itself be the incident.
log_checkpoints = on. It is on by default in recent versions; the lab sets it explicitly and does not reset it, because leaving it on is correct.

Scenario

Users report that the application “stutters” — normal for a few minutes, then a burst of slow queries, then normal again. There is no pattern in the application logs and the slow queries are not the same ones each time.

Tasks

Task 1 — The settings and the counters

LAB="$HOME/rbpg-lab-16"
mkdir -p "$LAB"

docker exec -i -u postgres rbpg-lab01 psql -X -c "CREATE DATABASE lab16;"
docker exec -u postgres rbpg-lab01 psql -X -c "ALTER SYSTEM SET log_checkpoints = on;"
docker exec -u postgres rbpg-lab01 psql -X -c "SELECT pg_reload_conf();"

docker exec -i -u postgres rbpg-lab01 psql -X -d lab16 <<'SQL'
CREATE TABLE t(id int PRIMARY KEY, payload text);
INSERT INTO t SELECT g, repeat('c',100) FROM generate_series(1,300000) g;
SQL

docker exec -u postgres rbpg-lab01 psql -X -c "
  SELECT name, setting, unit, context FROM pg_settings
  WHERE name IN ('checkpoint_timeout','checkpoint_completion_target',
                 'checkpoint_flush_after','checkpoint_warning',
                 'max_wal_size','min_wal_size','log_checkpoints',
                 'bgwriter_delay','bgwriter_lru_maxpages')
  ORDER BY name;" | tee "$LAB/settings.txt"

docker exec -u postgres rbpg-lab01 psql -X -c "SELECT * FROM pg_stat_checkpointer;" \
  | tee -a "$LAB/settings.txt"

Read-only / Safethe settings and the cumulative counters— Captured from the lab run of 2026-08-28.

$ a pg_settings query, then SELECT * FROM pg_stat_checkpointer

             name             | setting | unit | context 
------------------------------+---------+------+---------
bgwriter_delay               | 200     | ms   | sighup
bgwriter_lru_maxpages        | 100     |      | sighup
checkpoint_completion_target | 0.9     |      | sighup
checkpoint_flush_after       | 32      | 8kB  | sighup
checkpoint_timeout           | 300     | s    | sighup
checkpoint_warning           | 30      | s    | sighup
log_checkpoints              | on      |      | sighup
max_wal_size                 | 1024    | MB   | sighup
min_wal_size                 | 80      | MB   | sighup
(9 rows)

num_timed | num_requested | num_done | restartpoints_timed | restartpoints_req | restartpoints_done | write_time | sync_time | buffers_written | slru_written |          stats_reset          
-----------+---------------+----------+---------------------+-------------------+--------------------+------------+-----------+-----------------+--------------+-------------------------------
       5 |            31 |       27 |                   0 |                 0 |                  0 |    1212149 |      2074 |           37631 |           55 | 2026-08-28 00:09:02.920701+00
(1 row)

Read the first three counters carefully, because their relationship is the first diagnostic.

num_timed — checkpoints scheduled because checkpoint_timeout elapsed. On a healthy server this should dominate.
num_requested — checkpoints triggered by something else, almost always WAL volume exceeding max_wal_size.
num_done — checkpoints that actually did work.

Here num_timed + num_requested = 36 and num_done = 27. Nine checkpoints were skipped: the scheduled time arrived, nothing had been modified since the previous checkpoint, and there was nothing to write. That is normal and healthy on an idle server.

The ratio is the health check

num_requested should be a small fraction of num_timed. When it is the larger of the two, max_wal_size is smaller than the workload wants and checkpoints are being driven by WAL volume rather than by the schedule.

That is the shape of the problem this lab reproduces, and it is a single query to check on any server:

SELECT num_timed, num_requested,
       round(num_requested * 100.0 / nullif(num_timed + num_requested, 0), 1) AS pct_requested
FROM pg_stat_checkpointer;

Task 2 — Read a checkpoint log line completely

docker exec -u postgres rbpg-lab01 psql -X -d lab16 -c "UPDATE t SET payload = repeat('d',100);"
docker exec -u postgres rbpg-lab01 psql -X -c "CHECKPOINT;"
sleep 1
docker exec rbpg-lab01 grep -E "checkpoint (starting|complete)" \
  /var/log/postgresql/postgresql-18-main.log | tail -2 | tee "$LAB/checkpoint-log.txt"

Configuration changeone checkpoint, every field it reports— Captured from the lab run of 2026-08-28, after updating all 300,000 rows.

$ an UPDATE, then CHECKPOINT, then the last two checkpoint log lines

2026-08-28 01:34:42.366 UTC [9080] LOG:  checkpoint starting: immediate force wait
2026-08-28 01:34:42.932 UTC [9080] LOG:  checkpoint complete: wrote 12948 buffers (79.0%), wrote 1 SLRU buffers; 0 WAL file(s) added, 10 removed, 0 recycled; write=0.031 s, sync=0.505 s, total=0.566 s; sync files=307, longest=0.031 s, average=0.002 s; distance=163848 kB, estimate=240509 kB; lsn=0/CFA5A5A0, redo lsn=0/CFA5A548

Field by field:

immediate force wait — the reason flags. immediate means do not spread the writes out; force means do it even if nothing changed; wait means the command does not return until it finishes. All three come from the manual CHECKPOINT command. A scheduled checkpoint says time; a WAL-driven one says wal.
wrote 12948 buffers (79.0%) — 79% of shared_buffers was dirty. A high percentage here on every checkpoint means the working set is being rewritten between checkpoints.
0 WAL file(s) added, 10 removed, 0 recycled — segment file housekeeping. recycled means renamed for reuse, which is cheaper than added. Persistent added with no recycled suggests min_wal_size is too small.
write=0.031 s, sync=0.505 s, total=0.566 s — the split that matters. Writing took 31 ms; fsync took 505 ms, sixteen times longer. On this container the write goes to page cache and the sync is the real cost.
sync files=307, longest=0.031 s — 307 separate files were fsynced. longest is the worst single one; a large value here is a storage problem, not a PostgreSQL one.
distance=163848 kB, estimate=240509 kB — how much WAL this checkpoint covered, and the running estimate used to schedule the next one. Comparing distance against max_wal_size tells you immediately whether checkpoints are timed or WAL-driven.
lsn=... redo lsn=... — where the checkpoint record was written, and where recovery would start from. The gap between them is the WAL that would have to be replayed after a crash at this instant.

Task 3 — Cause the storm

docker exec -u postgres rbpg-lab01 psql -X -c "ALTER SYSTEM SET max_wal_size = '96MB';"
docker exec -u postgres rbpg-lab01 psql -X -c "SELECT pg_reload_conf();"
sleep 1

docker exec -u postgres rbpg-lab01 psql -X -c \
  "SELECT num_requested AS before FROM pg_stat_checkpointer;" | tee "$LAB/storm.txt"

for i in 1 2 3 4; do
  docker exec -u postgres rbpg-lab01 psql -X -d lab16 -c \
    "UPDATE t SET payload = repeat('e$i',50);" > /dev/null
done
sleep 3

docker exec -u postgres rbpg-lab01 psql -X -c \
  "SELECT num_timed, num_requested, num_done FROM pg_stat_checkpointer;" | tee -a "$LAB/storm.txt"
docker exec rbpg-lab01 grep "checkpoint starting" \
  /var/log/postgresql/postgresql-18-main.log | tail -4 | tee -a "$LAB/storm.txt"

Service impact possiblethirteen checkpoints in a few seconds, four of them within one second— Captured from the lab run of 2026-08-28. num_requested went from 32 to 45; num_timed did not move.

$ lower max_wal_size to 96MB, run four full-table updates, then read the counters and the log

 before 
--------
   32
(1 row)

num_timed | num_requested | num_done 
-----------+---------------+----------
       5 |            45 |       38
(1 row)

2026-08-28 01:34:59.091 UTC [9080] LOG:  checkpoint starting: wal
2026-08-28 01:34:59.356 UTC [9080] LOG:  checkpoint starting: wal
2026-08-28 01:34:59.668 UTC [9080] LOG:  checkpoint starting: wal
2026-08-28 01:34:59.984 UTC [9080] LOG:  checkpoint starting: wal

checkpoint starting: wal thirteen times, four of them inside a single second. num_timed did not move at all — none of these was scheduled.

Task 4 — The warning the server was already giving you

docker exec rbpg-lab01 grep -i "checkpoints are occurring too frequently" \
  /var/log/postgresql/postgresql-18-main.log | tail -3 | tee -a "$LAB/storm.txt"

Read-only / Safethe server naming the problem in plain language— Captured from the lab run of 2026-08-28.

$ grep the log for the checkpoint frequency warning

2026-08-28 01:34:59.356 UTC [9080] LOG:  checkpoints are occurring too frequently (0 seconds apart)
2026-08-28 01:34:59.668 UTC [9080] LOG:  checkpoints are occurring too frequently (0 seconds apart)
2026-08-28 01:34:59.984 UTC [9080] LOG:  checkpoints are occurring too frequently (0 seconds apart)

This message is emitted when two checkpoints occur closer together than checkpoint_warning (30 seconds by default). It is one of the few PostgreSQL log messages that names both the problem and, implicitly, the fix.

Look at the completion lines to see the consequence:

docker exec rbpg-lab01 grep "checkpoint complete" \
  /var/log/postgresql/postgresql-18-main.log | tail -2

Read-only / Safeeach checkpoint covering a fraction of the distance it should— Captured from the lab run of 2026-08-28. Compare distance here with the 163848 kB in Task 2.

$ grep the log for the last two checkpoint complete lines

2026-08-28 01:34:59.668 UTC [9080] LOG:  checkpoint complete: wrote 3216 buffers (19.6%), wrote 0 SLRU buffers; 0 WAL file(s) added, 3 removed, 0 recycled; write=0.274 s, sync=0.019 s, total=0.313 s; sync files=3, longest=0.016 s, average=0.007 s; distance=55532 kB, estimate=135119 kB; lsn=0/FA6FB8C8, redo lsn=0/F78588F8
2026-08-28 01:34:59.983 UTC [9080] LOG:  checkpoint complete: wrote 3970 buffers (24.2%), wrote 0 SLRU buffers; 0 WAL file(s) added, 1 removed, 2 recycled; write=0.273 s, sync=0.022 s, total=0.316 s; sync files=3, longest=0.016 s, average=0.008 s; distance=49228 kB, estimate=126530 kB; lsn=0/FD7690D0, redo lsn=0/FA86BC28

distance=49228 kB — roughly 48 MB per checkpoint, against 96 MB of max_wal_size. Each one writes a few thousand buffers and syncs, over and over.

Why frequent checkpoints cost far more than the checkpoints themselves

The obvious cost is the I/O of writing dirty buffers repeatedly. The larger cost is the one Lab 15 measured: full page writes.

The first modification of any page after a checkpoint writes the whole 8 kB page into the WAL. Checkpoint every five minutes and a hot page costs one full page image per five minutes. Checkpoint every 300 milliseconds, as this storm did, and the same page costs a full page image roughly every 300 milliseconds.

So the storm is self-reinforcing. More checkpoints produce more full page images, which produce more WAL, which crosses max_wal_size sooner, which triggers the next checkpoint sooner. A server can settle into this state and stay there, doing several times the I/O the workload actually requires.

The symptom is exactly what the scenario described: periodic stalls, at an interval nobody can correlate with anything in the application.

Task 5 — Fix it with one number

docker exec -u postgres rbpg-lab01 psql -X -c "ALTER SYSTEM SET max_wal_size = '4GB';"
docker exec -u postgres rbpg-lab01 psql -X -c "SELECT pg_reload_conf();"
sleep 1

docker exec -u postgres rbpg-lab01 psql -X -c \
  "SELECT num_requested AS before FROM pg_stat_checkpointer;" | tee "$LAB/resolved.txt"

for i in 1 2 3 4; do
  docker exec -u postgres rbpg-lab01 psql -X -d lab16 -c \
    "UPDATE t SET payload = repeat('f$i',50);" > /dev/null
done
sleep 3

docker exec -u postgres rbpg-lab01 psql -X -c \
  "SELECT num_timed, num_requested, num_done FROM pg_stat_checkpointer;" | tee -a "$LAB/resolved.txt"

Configuration changeidentical work, and num_requested does not move at all— Captured from the lab run of 2026-08-28. Four full-table updates, zero WAL-driven checkpoints.

$ raise max_wal_size to 4GB, run the same four updates, read the counters

 before 
--------
   45
(1 row)

num_timed | num_requested | num_done 
-----------+---------------+----------
       5 |            45 |       38
(1 row)

45 before, 45 after. The identical workload that produced thirteen checkpoints at 96 MB produced none at 4 GB. The next checkpoint on this server will be a timed one, on schedule.

What max_wal_size actually means, and how to size it

It is not a hard limit on the size of pg_wal. It is a soft target: the amount of WAL the server will allow to accumulate before deciding a checkpoint is overdue. pg_wal can and does exceed it — during a long checkpoint, or when a replication slot or a failing archive command is retaining segments.

Size it from your own measurements. You want max_wal_size comfortably larger than the WAL your workload produces in one checkpoint_timeout, so that checkpoints are driven by the clock rather than by volume. Lab 15 gives you the WAL rate; multiply by checkpoint_timeout and leave headroom for the busiest period, not the average.

The cost of a larger value is disk space in pg_wal and a longer crash recovery. Both are usually a much better trade than a storm.

Task 6 — What checkpoint_completion_target buys

docker exec -u postgres rbpg-lab01 psql -X -c "
  SELECT (SELECT setting::int   FROM pg_settings WHERE name='checkpoint_timeout')           AS timeout_s,
         (SELECT setting::float FROM pg_settings WHERE name='checkpoint_completion_target') AS target,
         (SELECT setting::int   FROM pg_settings WHERE name='checkpoint_timeout')
         * (SELECT setting::float FROM pg_settings WHERE name='checkpoint_completion_target') AS write_window_s;"

Read-only / Safethe writes are spread over 270 of every 300 seconds— Captured from the lab run of 2026-08-28.

$ compute checkpoint_timeout times checkpoint_completion_target from pg_settings

 timeout_s | target | write_window_s 
-----------+--------+----------------
     300 |    0.9 |            270
(1 row)

current_setting returns the unit; pg_settings.setting does not

The natural way to write that query fails:

ERROR:  invalid input syntax for type integer: "5min"

current_setting('checkpoint_timeout') returns the value as configured, including its unit — 5min, not 300. pg_settings.setting holds the numeric value, with pg_settings.unit telling you what it is in. Use the view when you need arithmetic.

A related trap in the same family, from the query in Task 1:

ERROR:  function round(double precision, integer) does not exist

round(x, n) exists only for numeric. Cast first: round(x::numeric, 2).

checkpoint_completion_target = 0.9 means the writes are spread across 270 of the 300 seconds between checkpoints rather than issued as fast as possible. That converts a sharp I/O spike into a low background rate, which is why 0.9 has been the default since PostgreSQL 14 and why there is rarely a reason to lower it.

Finally, the cumulative split:

docker exec -u postgres rbpg-lab01 psql -X -c "
  SELECT num_timed, num_requested, num_done, write_time, sync_time,
         round((sync_time*100.0/nullif(write_time+sync_time,0))::numeric,2) AS sync_pct,
         buffers_written
  FROM pg_stat_checkpointer;"

Read-only / Safecumulative write and sync time in milliseconds— Captured from the lab run of 2026-08-28, after the whole lab.

$ psql -X -c "SELECT num_timed, num_requested, num_done, write_time, sync_time, round((sync_time*100.0/nullif(write_time+sync_time,0))::numeric,2) AS sync_pct, buffers_written FROM pg_stat_checkpointer;"

 num_timed | num_requested | num_done | write_time | sync_time | sync_pct | buffers_written 
-----------+---------------+----------+------------+-----------+----------+-----------------
       5 |            45 |       38 |    1214793 |      2839 |     0.23 |          105314
(1 row)

write_time dominates here because most of those checkpoints were spread over their full window — the time is mostly waiting, deliberately, not working. That is the healthy pattern. It is sync_time growing that indicates storage struggling to keep up.

Validation

test -s "$LAB/settings.txt"       && echo "OK settings"
test -s "$LAB/checkpoint-log.txt" && echo "OK checkpoint-log"
test -s "$LAB/storm.txt"          && echo "OK storm"
test -s "$LAB/resolved.txt"       && echo "OK resolved"

grep -q "checkpoint complete"    "$LAB/checkpoint-log.txt" && echo "OK full log line captured"
grep -q "checkpoint starting: wal" "$LAB/storm.txt"        && echo "OK WAL-driven checkpoints captured"
grep -q "too frequently"         "$LAB/storm.txt"          && echo "OK warning captured"

Questions to answer without looking anything up:

num_timed = 200, num_requested = 4000. What is wrong and which setting do you change?
num_done is lower than num_timed + num_requested. Is that a problem?
A checkpoint reports write=0.03 s, sync=12.4 s. Would raising checkpoint_completion_target help?
Why does a checkpoint storm increase WAL volume as well as I/O?
max_wal_size is 4 GB and pg_wal is 40 GB. Has the setting failed?

Expected Outcome

You can read a checkpoint log line completely, and you have the one query that turns “the database stutters” into a diagnosis:

SELECT num_timed, num_requested,
       round(num_requested * 100.0 / nullif(num_timed + num_requested, 0), 1) AS pct_requested,
       write_time, sync_time, buffers_written
FROM pg_stat_checkpointer;

A high pct_requested means max_wal_size is too small for the workload, and the fix is one setting applied by a reload — no restart, no downtime, and it removes both the I/O storm and the full-page-write amplification that comes with it.

Troubleshooting

pg_stat_bgwriter does not have the checkpoint columns. They moved to pg_stat_checkpointer in PostgreSQL 17. A runbook or dashboard written against 16 or earlier queries columns that no longer exist.

No checkpoint log lines appear. log_checkpoints must be on. Its boot_val is on in 18.6 and its context is sighup, so it needs only a reload — but confirm rather than assume, with SELECT setting, boot_val, source FROM pg_settings WHERE name = 'log_checkpoints';, because a configuration file may have turned it off.

The storm will not reproduce. max_wal_size is not small enough relative to the write rate, or the write burst is too short. The condition you want is num_requested rising while num_timed does not.

checkpoint_completion_target appears to do nothing. It spreads the write phase across a fraction of the interval; it does not change how much is written. Its effect shows in write_time and in the shape of the I/O, not in buffers_written.

checkpoints too frequent warnings appear with max_wal_size already raised. The reload has not happened, or a later configuration source is overriding it. SELECT setting, source, sourcefile FROM pg_settings WHERE name = 'max_wal_size'; settles it.

pg_wal is larger than max_wal_size and checkpoints are healthy. max_wal_size is a pacing target, not a cap. Segments held for an archive that is failing, or by a replication slot, are retained regardless — check pg_stat_archiver and pg_replication_slots.

Cleanup

docker exec -u postgres rbpg-lab01 psql -X -c "ALTER SYSTEM RESET max_wal_size;"
docker exec -u postgres rbpg-lab01 psql -X -c "SELECT pg_reload_conf();"
docker exec -u postgres rbpg-lab01 psql -X -c "DROP DATABASE IF EXISTS lab16;"
docker exec -u postgres rbpg-lab01 psql -X -c "SHOW max_wal_size;"

log_checkpoints is deliberately left on. It costs one log line per checkpoint and it is the only record you will have of the next storm.

Production notes

Watch the requested-versus-timed checkpoint ratio, not the absolute counts. A high proportion of requested checkpoints is the server telling you max_wal_size is too small for the workload, and the fix is one setting applied by a reload.
The server writes checkpoints are occurring too frequently into the log with the interval and a recommendation. It is one of the few diagnostics PostgreSQL volunteers unprompted, and it is routinely never read.
Raising max_wal_size reduces both the checkpoint I/O storm and the full-page-write amplification that comes with it, at the cost of longer crash recovery and more disk held by pg_wal. Size the volume for the new value.
checkpoint_completion_target at its 0.9 default spreads the writes; leave it there unless you have a measured reason. Lowering it concentrates the same work into a shorter window.
Alert on pg_wal filesystem usage separately from the data volume. A full pg_wal is a PANIC and a cluster that will not restart; a full data volume is bad but recoverable.

What You Learned

A checkpoint log line is complete evidence: buffers written, the fraction of the pool, the write and sync times, and the distance in WAL.
Timed and requested checkpoints mean different things. Requested means the WAL volume reached max_wal_size before the timer expired.
The counters live in pg_stat_checkpointer from PostgreSQL 17, not in pg_stat_bgwriter.
The server warns you itself with checkpoints are occurring too frequently, including the interval and what to do.
One setting fixes it, applied by a reload. No restart and no downtime.
max_wal_size is a pacing target, not a cap, so pg_wal can legitimately exceed it when an archive is failing or a slot is holding segments.

Objectives

Prerequisites