Skip to main content
RunBook Academy

← All break/fix scenarios in PostgreSQL

intermediatepg-replication-lag~35 min

The replication lag alert fired every Sunday for a year, and the week it was telling the truth it had already been muted

Reported symptoms

  • ●A replication lag alert fires most Sundays between 03:00 and 07:00 and clears on its own by Monday morning
  • ●The reported lag climbs steadily during those hours, reaching several hundred seconds
  • ●Every investigation has found the standby healthy, fully caught up, and streaming normally
  • ●The alert was muted for weekends six months ago, then muted entirely three months ago
  • ●On a Tuesday the standby fell four hours behind during a bulk load and nobody was paged
  • ●That was discovered when a report run against the standby returned stale data
  • ●A second standby, added last year for a delayed-recovery use case, has always shown lag and is excluded from alerting entirely

Evidence

  • · The alert is built on now() minus pg_last_xact_replay_timestamp() collected from the standby
  • · Sampled during a quiet period, that metric read 0.95 seconds, then 9.0 seconds, then 17.05 seconds over consecutive samples
  • · Across the same samples the byte lag computed from the primary was 0 bytes and the standby reported fully caught up
  • · pg_stat_replication on the primary shows state streaming and replay_lag of a few milliseconds throughout
  • · The Sunday window corresponds to the quietest period of the week, when the primary commits almost nothing
  • · During the Tuesday incident byte lag reached 3.1 GB while the time-based metric was normal, because commits were arriving continuously
  • · The second standby is configured with recovery_min_apply_delay = 30s, and is behind on purpose
  • · A test with recovery_min_apply_delay confirmed a row was invisible on the standby at 9, 18 and 27 seconds and visible at 36 seconds, while byte lag remained 0
Diagnosis and resolutionclick to reveal

Root cause

The alert measured the wrong thing, and the wrong thing happens to look alarming exactly when the cluster is at its healthiest. `pg_last_xact_replay_timestamp()` returns the commit timestamp of the last transaction the standby replayed. `now() - pg_last_xact_replay_timestamp()` is therefore *time since the last commit arrived*, and on an idle primary that grows with the wall clock regardless of replication health. If the primary commits nothing for five minutes, the metric reads five minutes, and the standby is perfectly current. Measured directly on a healthy pair: the metric read 0.95 s, then 9.0 s, then 17.05 s across consecutive samples while byte lag stayed at 0 and the standby reported fully caught up. Nothing was behind. The primary had simply not committed anything. Sunday small hours are the quietest period of the week, so that is when the metric climbed highest and the pages arrived. A year of false alarms did what a year of false alarms does. The alert was muted for weekends, then muted entirely, and by Tuesday there was nothing watching. During that incident byte lag reached 3.1 GB while the time-based metric looked normal — because commits were arriving continuously, which is the condition under which time-based lag behaves itself and the condition under which real lag occurs. The metric is not merely noisy. It is anti-correlated with the thing it is supposed to detect. The second standby is a separate misunderstanding worth naming. It runs `recovery_min_apply_delay = 30s` and is behind **on purpose** — a delayed standby is a defence against a bad `DELETE`, giving an operator a window to stop replay before the damage arrives. Measured with a 30-second delay, a new row was invisible at 9, 18 and 27 seconds and visible at 36, while byte lag stayed 0: the WAL had arrived and was deliberately not yet applied. Excluding that standby from alerting means nobody is watching whether it is receiving WAL at all.

Remediation

Replace the metric. Byte lag is meaningful whether or not the primary is committing: ```sql -- on the primary SELECT application_name, state, pg_wal_lsn_diff(pg_current_wal_lsn(), replay_lsn) AS bytes_behind, replay_lag, CASE WHEN state <> 'streaming' THEN 'not streaming' WHEN pg_wal_lsn_diff(pg_current_wal_lsn(), replay_lsn) > 256*1024*1024 THEN 'behind' ELSE 'ok' END AS verdict FROM pg_stat_replication ORDER BY application_name; ``` `replay_lag` in `pg_stat_replication` is also usable — it is measured from WAL arrival rather than from wall clock, and it is NULL rather than misleading when there is nothing to measure. Add the standby-side check, which is the one that survives losing the primary. The primary-side view is unavailable exactly when the primary is what failed: ```sql -- on the standby SELECT pg_is_in_recovery() AS in_recovery, pg_last_wal_receive_lsn() = pg_last_wal_replay_lsn() AS caught_up, pg_wal_lsn_diff(pg_last_wal_receive_lsn(), pg_last_wal_replay_lsn()) AS unreplayed_bytes, (SELECT count(*) FROM pg_stat_wal_receiver) AS receiver_running; ``` `unreplayed_bytes` separates two very different failures: WAL arriving but not being applied, versus WAL not arriving at all. A single lag number cannot express that difference. Alert on the standby being **absent** before alerting on it being slow. A standby that is not connected has no row in `pg_stat_replication`, so every lag metric derived from that view returns NULL — and a monitoring system that renders NULL as zero will show a perfect graph for a standby that is not replicating at all. Handle the delayed standby explicitly rather than by exclusion. Alert on its `unreplayed_bytes` and on its receiver being connected, and set its apply-lag threshold to its configured delay plus a margin: ```sql SHOW recovery_min_apply_delay; ``` Unmute the alerts only once they have been tested, and tell the team the pages they receive from now on are real. That statement has to be earned before it can be made.

Verification

The new alert stays quiet through a full quiet period. Watch a Sunday deliberately and confirm no page arrives while byte lag stays at zero. The new alert **fires** when the standby is genuinely behind. Test it: pause replay on the standby, confirm the page arrives, resume: ```sql -- on the standby SELECT pg_wal_replay_pause(); -- generate write traffic on the primary, wait for the alert, then: SELECT pg_wal_replay_resume(); ``` An alert that has never fired has never been shown to work, and that is what the last year consisted of. The absence alert fires when a standby is stopped. Stop it deliberately, confirm the page, start it again. The delayed standby produces no routine alerts but does produce one when its receiver disconnects. Confirm both halves. Byte lag and the standby-side check agree with each other on a healthy pair. On the measured pair both read zero with `state = streaming` and a `replay_lag` of a few milliseconds.

Prevention

**Alert on byte lag, not on time since the last replayed commit.** `pg_wal_lsn_diff(pg_current_wal_lsn(), replay_lsn)` is meaningful on an idle primary; `now() - pg_last_xact_replay_timestamp()` is not, and it produces its loudest false alarms precisely when the system is healthiest. **Alert on the standby being absent before alerting on it being slow.** A missing row in `pg_stat_replication` is the most serious condition and no lag threshold can express it. **Never render NULL as zero.** A NULL sample is missing data. Rendered as zero it becomes an assertion of health that nobody made. **Collect from both sides.** The primary-side view disappears when the primary does. **Treat a muted alert as an open incident.** Muting is a decision to stop watching, and it should carry an owner and a date the way any other outage does. This one was muted for three months and the mute was the reason nobody was paged. **Test every alert by causing the condition.** `pg_wal_replay_pause()` makes a standby genuinely lag, on demand, without harming anything. There is no excuse for an untested replication alert. **Model a delayed standby as delayed, not as excluded.** It is behind on purpose, and it still needs monitoring for the things that can actually go wrong with it — a disconnected receiver, or WAL not arriving. **Review alerts by their false-positive rate.** An alert that fires weekly and is right once a year is training people to ignore it, and that training is what turns a four-hour lag into a discovery made by a stale report.

Reported symptoms

A replication lag alert fires most Sundays between 03:00 and 07:00 and clears on its own by Monday. The reported lag climbs steadily to several hundred seconds.

Every investigation has found the standby healthy, fully caught up, and streaming normally.

The alert was muted for weekends six months ago, then muted entirely three months ago.

On a Tuesday the standby fell four hours behind during a bulk load and nobody was paged. It was discovered when a report run against the standby returned stale data.

A second standby, added last year for a delayed-recovery use case, has always shown lag and is excluded from alerting entirely.

Evidence provided

The alert is built on now() - pg_last_xact_replay_timestamp(), collected from the standby.

Read-only / Safethe metric climbing on a standby that is not behind
$ watch the standby's apply lag and its caught-up flag together
 apply_lag_time  | fully_caught_up 
-----------------+-----------------
00:00:00.951159 | t
00:00:09.003664 | t
00:00:17.054691 | t
Read-only / Safebyte lag across the same window
$ psql -c "SELECT pg_size_pretty(pg_wal_lsn_diff(pg_current_wal_lsn(), replay_lsn)) AS bytes_behind, replay_lag FROM pg_stat_replication;"
 bytes_behind | replay_lag 
--------------+------------
0 bytes      | 
(1 row)

The Sunday window is the quietest period of the week.

During the Tuesday incident, byte lag reached 3.1 GB while the time-based metric looked normal.

The second standby runs recovery_min_apply_delay = 30s:

Read-only / Safea delayed standby, behind on purpose, with byte lag at zero
$ insert on the primary, then query the standby every nine seconds
    after 9s:  ERROR:  relation "delayed_marker" does not exist
  after 18s: ERROR:  relation "delayed_marker" does not exist
  after 27s: ERROR:  relation "delayed_marker" does not exist
  after 36s: 1
bytes_behind | replay_lag 
--------------+------------
0 bytes      | 
(1 row)

Work the evidence before reading on

  1. The apply lag climbed from 0.95 s to 17 s while byte lag stayed at 0. What is the metric actually measuring?
  2. Why does it climb hardest on Sunday mornings?
  3. On Tuesday the standby was 3.1 GB behind and the metric was normal. Why?
  4. The delayed standby shows lag and byte lag zero. Which is right?

Root cause

The metric is anti-correlated with the thing it detects

Sunday small hours are the quietest period of the week, so that is when it climbed highest and the pages arrived.

A year of false alarms did what a year of false alarms does

The delayed standby is behind on purpose

recovery_min_apply_delay = 30s is a defence against a bad DELETE: it gives an operator a window to stop replay before the damage arrives. The measurement above shows the mechanism exactly — the row was invisible at 9, 18 and 27 seconds and visible at 36, while byte lag stayed 0. The WAL had arrived and was deliberately not yet applied.

Excluding that standby from alerting means nobody is watching whether it is receiving WAL at all, which is the thing that can actually go wrong with it.

Resolution

Replace the metric. Byte lag is meaningful whether or not the primary is committing:

-- on the primary
SELECT application_name, state,
       pg_wal_lsn_diff(pg_current_wal_lsn(), replay_lsn) AS bytes_behind,
       replay_lag,
       CASE
         WHEN state <> 'streaming' THEN 'not streaming'
         WHEN pg_wal_lsn_diff(pg_current_wal_lsn(), replay_lsn) > 256*1024*1024 THEN 'behind'
         ELSE 'ok'
       END AS verdict
FROM pg_stat_replication
ORDER BY application_name;

replay_lag from pg_stat_replication is also usable — it is measured from WAL arrival rather than wall clock, and it is NULL rather than misleading when there is nothing to measure.

Add the standby-side check, which survives losing the primary:

-- on the standby
SELECT pg_is_in_recovery() AS in_recovery,
       pg_last_wal_receive_lsn() = pg_last_wal_replay_lsn() AS caught_up,
       pg_wal_lsn_diff(pg_last_wal_receive_lsn(), pg_last_wal_replay_lsn()) AS unreplayed_bytes,
       (SELECT count(*) FROM pg_stat_wal_receiver) AS receiver_running;

unreplayed_bytes separates two very different failures — WAL arriving but not applied, versus WAL not arriving — which a single lag number cannot express.

Handle the delayed standby explicitly rather than by exclusion: alert on its unreplayed_bytes and on its receiver being connected, and set its apply-lag threshold to its configured delay plus a margin.

Unmute only once the alerts have been tested, and tell the team the pages they get from now on are real. That statement has to be earned.

Verification

The new alert stays quiet through a full quiet period. Watch a Sunday deliberately and confirm no page arrives while byte lag stays zero.

The new alert fires when the standby is genuinely behind. Test it:

-- on the standby
SELECT pg_wal_replay_pause();
-- generate write traffic on the primary, wait for the alert, then:
SELECT pg_wal_replay_resume();

An alert that has never fired has never been shown to work, and that is what the last year consisted of.

The absence alert fires when a standby is stopped — stop it, confirm the page, start it again.

The delayed standby produces no routine alerts but does produce one when its receiver disconnects. Confirm both halves.

On a healthy pair, byte lag and the standby-side check agree. Measured:

 application_name |   state   | bytes_behind |   replay_lag    | verdict 
------------------+-----------+--------------+-----------------+---------
 lab21-standby    | streaming |            0 | 00:00:00.002621 | ok
 oldprimary       | streaming |            0 | 00:00:00.00193  | ok

Prevention

Alert on byte lag, not on time since the last replayed commit.

Alert on the standby being absent before alerting on it being slow.

Never render NULL as zero. A NULL sample is missing data; rendered as zero it becomes an assertion of health nobody made.

Collect from both sides. The primary-side view disappears when the primary does.

Treat a muted alert as an open incident, with an owner and a date.

Test every alert by causing the condition. pg_wal_replay_pause() makes a standby genuinely lag, on demand, harmlessly. There is no excuse for an untested replication alert.

Model a delayed standby as delayed, not as excluded.

Review alerts by their false-positive rate. One that fires weekly and is right once a year is training people to ignore it — and that training is what turned a four-hour lag into a discovery made by a stale report.