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

Reply via email to