A customer of ours complained that if you have an inactive primary, monitoring the apply lag on a standby reports monotonically increasing lag. The reason for this is that the apply lag is only updated on COMMIT records, which of course don't occur in inactive servers. But CHECKPOINT records do occur, so the WAL insert pointer continues to move forward, which is what causes the spurious lag.
(I think newer releases are protected from this problem because they don't emit checkpoints during periods of inactivity. I didn't verify this.) This patch fixes the problem by using the checkpoint timestamp to update the lag tracker in the standby. This requires a little change in where this update is invoked, because previously it was done only for the XACT rmgr; this makes the patch a little bigger than it should. -- Álvaro Herrera PostgreSQL Expert, https://www.2ndQuadrant.com/
>From 859cd9db48cdde68c7767359e7cdae5b72a3011f Mon Sep 17 00:00:00 2001 From: Alvaro Herrera <alvhe...@alvh.no-ip.org> Date: Fri, 10 Jan 2020 10:37:44 -0300 Subject: [PATCH] Use checkpoint timestamp to update apply lag tracker Previously we only used transaction commit records, which makes the wal pointer in standby lag behind when the primary is idle. --- src/backend/access/transam/xlog.c | 37 ++++++++++++++++++++++--------- 1 file changed, 26 insertions(+), 11 deletions(-) diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 7f4f784c0e..59679b31ec 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -5562,8 +5562,8 @@ exitArchiveRecovery(TimeLineID endTLI, XLogRecPtr endOfLog) * * If the record contains a timestamp, returns true, and saves the timestamp * in *recordXtime. If the record type has no timestamp, returns false. - * Currently, only transaction commit/abort records and restore points contain - * timestamps. + * Currently, only transaction commit/abort records, restore points and + * checkpoints contain timestamps. */ static bool getRecordTimestamp(XLogReaderState *record, TimestampTz *recordXtime) @@ -5577,6 +5577,13 @@ getRecordTimestamp(XLogReaderState *record, TimestampTz *recordXtime) *recordXtime = ((xl_restore_point *) XLogRecGetData(record))->rp_time; return true; } + if (rmid == RM_XLOG_ID && (info == XLOG_CHECKPOINT_ONLINE || + info == XLOG_CHECKPOINT_SHUTDOWN)) + { + *recordXtime = + time_t_to_timestamptz(((CheckPoint *) XLogRecGetData(record))->time); + return true; + } if (rmid == RM_XACT_ID && (xact_info == XLOG_XACT_COMMIT || xact_info == XLOG_XACT_COMMIT_PREPARED)) { @@ -5745,9 +5752,6 @@ recoveryStopsBefore(XLogReaderState *record) /* * Same as recoveryStopsBefore, but called after applying the record. - * - * We also track the timestamp of the latest applied COMMIT/ABORT - * record in XLogCtl->recoveryLastXTime. */ static bool recoveryStopsAfter(XLogReaderState *record) @@ -5755,7 +5759,6 @@ recoveryStopsAfter(XLogReaderState *record) uint8 info; uint8 xact_info; uint8 rmid; - TimestampTz recordXtime; /* * Ignore recovery target settings when not in archive recovery (meaning @@ -5823,10 +5826,6 @@ recoveryStopsAfter(XLogReaderState *record) { TransactionId recordXid; - /* Update the last applied transaction timestamp */ - if (getRecordTimestamp(record, &recordXtime)) - SetLatestXTime(recordXtime); - /* Extract the XID of the committed/aborted transaction */ if (xact_info == XLOG_XACT_COMMIT_PREPARED) { @@ -5865,7 +5864,7 @@ recoveryStopsAfter(XLogReaderState *record) { recoveryStopAfter = true; recoveryStopXid = recordXid; - recoveryStopTime = recordXtime; + getRecordTimestamp(record, &recoveryStopTime); recoveryStopLSN = InvalidXLogRecPtr; recoveryStopName[0] = '\0'; @@ -6049,6 +6048,19 @@ recoveryApplyDelay(XLogReaderState *record) return true; } +/* + * Track the timestamp of the latest applied time-bearing WAL record in + * XLogCtl->recoveryLastXTime. + */ +static void +updateRecoveryXTime(XLogReaderState *record) +{ + TimestampTz recordXtime; + + if (getRecordTimestamp(record, &recordXtime)) + SetLatestXTime(recordXtime); +} + /* * Save timestamp of latest processed commit/abort record. * @@ -7255,6 +7267,9 @@ StartupXLOG(void) WalSndWakeup(); } + /* update last recovery time */ + updateRecoveryXTime(xlogreader); + /* Exit loop if we reached inclusive recovery target */ if (recoveryStopsAfter(xlogreader)) { -- 2.20.1