Skip to main content
RunBook Academy

← All break/fix scenarios in PostgreSQL

intermediatepg-checkpoint~40 min

Write latency spiked every ninety seconds and the log had been saying why since the batch job was introduced

Reported symptoms

  • ●Write latency on the primary spikes from 3 ms to 400 ms roughly every ninety seconds during the nightly bulk load
  • ●The spikes last five to fifteen seconds each and the pattern repeats for the whole three-hour load window
  • ●Read latency is unaffected and CPU is under 30 percent throughout
  • ●Disk write throughput shows a matching sawtooth, idle between spikes and saturated during them
  • ●The bulk load itself takes three hours where the same volume of data loads in forty minutes on the staging cluster
  • ●Staging has identical hardware and an identical PostgreSQL version
  • ●An engineer proposed lowering checkpoint_completion_target to make checkpoints finish faster

Evidence

  • · The server log contains LOG: checkpoints are occurring too frequently (0 seconds apart), repeatedly, throughout the load window
  • · Each spike is preceded by LOG: checkpoint starting: wal - not checkpoint starting: time
  • · pg_stat_checkpointer shows num_requested rising by thirteen in a few seconds while num_timed does not move
  • · checkpoint completion lines show distance values of 49228 kB to 59186 kB, far below the configured max_wal_size
  • · max_wal_size on the production cluster is 96MB; on staging it is 4GB
  • · The production value was set three years ago when the cluster was small and has never been revisited
  • · Rerunning the identical workload with max_wal_size raised produced no WAL-driven checkpoints at all
  • · checkpoint_timeout is 300 seconds and checkpoint_completion_target is 0.9, giving a 270 second write window that is never used
Diagnosis and resolutionclick to reveal

Root cause

The cluster was generating WAL faster than `max_wal_size` allowed between checkpoints, so every checkpoint was triggered by WAL volume rather than by time. A time-driven checkpoint is paced. With `checkpoint_timeout` at 300 seconds and `checkpoint_completion_target` at 0.9, PostgreSQL has a 270-second window in which to write out dirty buffers gently, and the write load is spread thin enough to be invisible. A WAL-driven checkpoint has no such luxury. It fires because the WAL has reached its limit, and the next one is already approaching, so the writes are compressed into seconds. That is the sawtooth: idle disk, then saturation, then idle. The log distinguishes the two cases explicitly and had been doing so all along: `checkpoint starting: wal` rather than `checkpoint starting: time`. And when they come close enough together, PostgreSQL says so directly — `checkpoints are occurring too frequently (0 seconds apart)` — which is as close to a diagnosis as a database will ever hand you. The `distance` field in each completion line is the confirmation. Distances of 49 MB to 59 MB against a `max_wal_size` of 96 MB mean checkpoints are firing after less than a minute of WAL. On staging, with `max_wal_size` at 4 GB, the identical workload produced no WAL-driven checkpoints at all — same hardware, same version, same data, forty minutes instead of three hours. The production value of 96 MB was set three years ago when the cluster was small, and nothing revisited it as the workload grew. That is the whole fault. The proposal to lower `checkpoint_completion_target` would have made it worse. That setting controls how much of the interval is used for writing; lowering it compresses the same writes into a shorter window, which is precisely the thing already happening.

Remediation

Read the checkpoint log lines before changing anything. They contain the trigger, the volume, and the cost: ```bash grep -E 'checkpoint (starting|complete)|occurring too frequently' \ /var/log/postgresql/postgresql-18-main.log | tail -40 ``` A completion line reads like this, and every field in it is useful: ```text checkpoint complete: wrote 6573 buffers (40.1%), wrote 1 SLRU buffers; 0 WAL file(s) added, 4 removed, 0 recycled; write=0.215 s, sync=0.029 s, total=0.266 s; sync files=4, longest=0.025 s, average=0.008 s; distance=59186 kB, estimate=143962 kB ``` `distance` is how much WAL that checkpoint covered. If it is consistently close to `max_wal_size`, checkpoints are WAL-driven and `max_wal_size` is the constraint. Confirm from the counters, which separate the two triggers: ```sql SELECT num_timed, num_requested, num_done, write_time, sync_time, buffers_written, stats_reset FROM pg_stat_checkpointer; ``` `num_requested` climbing while `num_timed` stands still is the signature. On a healthy cluster the large majority of checkpoints are timed. Raise `max_wal_size` so that checkpoints are driven by time rather than volume. It is reloadable and needs no restart: ```sql ALTER SYSTEM SET max_wal_size = '4GB'; SELECT pg_reload_conf(); ``` Size it from the measured WAL generation rate: enough WAL to cover `checkpoint_timeout` at peak write rate, with margin. Undersizing produces this incident; oversizing costs disk and lengthens crash recovery, so it is a trade to make deliberately rather than by picking a large round number. Before raising it, confirm the WAL volume has room for the new value **plus** whatever archiving or replication slots may retain. `max_wal_size` is a checkpoint pacing target, not a cap, and a WAL volume sized exactly to it has no margin at all. Leave `checkpoint_completion_target` at 0.9. It is spreading writes across the interval, which is what you want; the problem is that the interval keeps ending early.

Verification

`checkpoints are occurring too frequently` stops appearing in the log. Not less often — at all. Checkpoint starts are `time` rather than `wal`: ```bash grep -c 'checkpoint starting: wal' /var/log/postgresql/postgresql-18-main.log grep -c 'checkpoint starting: time' /var/log/postgresql/postgresql-18-main.log ``` `num_requested` stops climbing during the load window while `num_timed` advances normally. Reset the statistics first so the comparison is about tonight rather than about all history: ```sql SELECT pg_stat_reset_shared('checkpointer'); -- run the load, then: SELECT num_timed, num_requested, num_done, write_time, sync_time FROM pg_stat_checkpointer; ``` `distance` in the completion lines is well below `max_wal_size`, which means the checkpoint fired for its own reasons rather than being forced. The write-latency sawtooth is gone, and the bulk load completes in a time comparable to staging. The staging comparison is the strongest available check, because it isolates configuration from hardware. `pg_wal` stays within the new expectation and the WAL volume retains headroom. Check this explicitly after raising `max_wal_size` — you have deliberately allowed more WAL to accumulate.

Prevention

**Alert on `checkpoints are occurring too frequently`.** PostgreSQL is naming the problem in plain language. This is one of the highest-value log alerts a cluster can have, and it costs one grep. **Alert on the ratio of requested to timed checkpoints.** A healthy cluster is mostly timed: ```sql SELECT num_timed, num_requested, round(100.0 * num_requested / nullif(num_timed + num_requested, 0), 1) AS pct_requested FROM pg_stat_checkpointer; ``` A rising `pct_requested` is the leading indicator, visible long before latency moves. **Set `log_checkpoints` on** — it is on by default in modern PostgreSQL, and the completion lines are the primary instrument for this class of problem. Do not turn them off to reduce log volume. **Revisit `max_wal_size` when the workload changes.** A value chosen for a small cluster three years ago is not a value; it is a leftover. Tie the review to capacity planning rather than to incidents. **Compare production against staging when they differ in behaviour.** Identical hardware and version with a fortyfold difference in load time is a configuration difference, and diffing `pg_settings` between them is a five-minute check that would have ended this immediately: ```sql SELECT name, setting FROM pg_settings WHERE source <> 'default' ORDER BY name; ``` **Do not lower `checkpoint_completion_target` in response to checkpoint pain.** It compresses the same writes into a shorter window. The instinct to make checkpoints "finish faster" is exactly backwards: you want them to finish *slower*, spread across the whole interval. **Size the WAL volume for `max_wal_size` plus retention, not for `max_wal_size`.** Unarchived segments and replication slots are retained regardless of it.

Reported symptoms

Write latency on the primary spikes from 3 ms to 400 ms roughly every ninety seconds during the nightly bulk load. Each spike lasts five to fifteen seconds, and the pattern repeats for the whole three-hour window.

Read latency is unaffected. CPU is under 30 percent. Disk write throughput shows a matching sawtooth — idle between spikes, saturated during them.

The load takes three hours. The same volume loads in forty minutes on staging, which has identical hardware and an identical PostgreSQL version.

An engineer has proposed lowering checkpoint_completion_target so that checkpoints finish faster.

Evidence provided

Read-only / SafePostgreSQL naming the problem, repeatedly
$ grep 'occurring too frequently' /var/log/postgresql/postgresql-18-main.log | tail -3
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)
Read-only / Safethe trigger is wal, not time
$ grep 'checkpoint starting' /var/log/postgresql/postgresql-18-main.log | tail -4
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
Read-only / Safethe completion line, and the field that confirms it
$ grep 'checkpoint complete' /var/log/postgresql/postgresql-18-main.log | tail -1
2026-08-28 01:34:59.356 UTC [9080] LOG:  checkpoint complete: wrote 6573 buffers (40.1%), wrote 1 SLRU buffers; 0 WAL file(s) added, 4 removed, 0 recycled; write=0.215 s, sync=0.029 s, total=0.266 s; sync files=4, longest=0.025 s, average=0.008 s; distance=59186 kB, estimate=143962 kB; lsn=0/F762F898, redo lsn=0/F421D818

num_requested rose by thirteen in a few seconds while num_timed did not move.

max_wal_size in production is 96MB. On staging it is 4GB. The production value was set three years ago when the cluster was small.

Rerunning the identical workload with max_wal_size raised produced no WAL-driven checkpoints at all.

Work the evidence before reading on

  1. checkpoint starting: wal versus checkpoint starting: time — what is the difference, and why does it matter to latency?
  2. distance=59186 kB against max_wal_size = 96MB. What does that ratio tell you?
  3. Staging is forty minutes and production is three hours on identical hardware. Where would you look first?
  4. Would lowering checkpoint_completion_target help?

Root cause

Two kinds of checkpoint, and only one of them is gentle

The value was a leftover

96 MB was chosen three years ago for a small cluster and nothing revisited it as the workload grew. Staging, at 4 GB, ran the identical workload with no WAL-driven checkpoints at all — same hardware, same version, same data, forty minutes against three hours.

The proposed fix points the wrong way

Resolution

Read the log lines first. They carry the trigger, the volume and the cost:

grep -E 'checkpoint (starting|complete)|occurring too frequently' \
  /var/log/postgresql/postgresql-18-main.log | tail -40

Confirm from the counters, which separate the two triggers:

SELECT num_timed, num_requested, num_done,
       write_time, sync_time, buffers_written, stats_reset
FROM pg_stat_checkpointer;

num_requested climbing while num_timed stands still is the signature. On a healthy cluster the large majority of checkpoints are timed.

Raise max_wal_size so checkpoints are driven by time. It is reloadable:

ALTER SYSTEM SET max_wal_size = '4GB';
SELECT pg_reload_conf();

Size it from the measured WAL generation rate — enough to cover checkpoint_timeout at peak write rate, with margin. Undersizing produces this incident; oversizing costs disk and lengthens crash recovery, so choose deliberately rather than picking a large round number.

Leave checkpoint_completion_target at 0.9.

Verification

checkpoints are occurring too frequently stops appearing. Not less often — at all.

Checkpoint starts are time rather than wal:

grep -c 'checkpoint starting: wal'  /var/log/postgresql/postgresql-18-main.log
grep -c 'checkpoint starting: time' /var/log/postgresql/postgresql-18-main.log

num_requested stops climbing during the load window. Reset the statistics first, so the comparison is about tonight rather than all history:

SELECT pg_stat_reset_shared('checkpointer');
-- run the load, then:
SELECT num_timed, num_requested, num_done, write_time, sync_time FROM pg_stat_checkpointer;

distance in the completion lines sits well below max_wal_size.

The write-latency sawtooth is gone and the load completes in a time comparable to staging. That comparison is the strongest check available, because it isolates configuration from hardware.

pg_wal stays within the new expectation and the WAL volume retains headroom.

Prevention

Alert on checkpoints are occurring too frequently. One of the highest-value log alerts a cluster can have, and it costs one grep.

Alert on the ratio of requested to timed checkpoints, which moves long before latency does:

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

Keep log_checkpoints on. The completion lines are the primary instrument for this class of problem; do not disable them to reduce log volume.

Revisit max_wal_size when the workload changes. A value chosen for a small cluster three years ago is not a value, it is a leftover.

Diff pg_settings between production and staging when they behave differently. A five-minute check that would have ended this immediately:

SELECT name, setting FROM pg_settings WHERE source <> 'default' ORDER BY name;

Do not lower checkpoint_completion_target in response to checkpoint pain.

Size the WAL volume for max_wal_size plus retention.