From 66288a9afcb682876c7c056aa56cfa8da91fc2d2 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Date: Wed, 8 Dec 2021 05:15:56 +0000
Subject: [PATCH v4] add log messages for recovery

The messages at LOG level would be helpful to know what's happening
with the system while in recovery. Although these messages seem to
be filling up the server logs, but the advantages we gain with them
are plenty. Of course, having a good log consumption and rotation
mechanism will help the server logs not fill up the disk.

These LOG messages will help us know how much time a restore command
takes to fetch the WAL file, what is the current WAL file the server
is recovering and where is it recovering from.

As a developer or admin, one can monitor these logs and do bunch of
things:
1) see how many WAL files left to be recovered by looking at the WAL
files in the archive location or pg_wal directory or from primary
2) provide an approximate estimation of when the server will come up
or how much more the recovery takes by looking at these previous LOG
messages, one can know the number of WAL files that server recovered
over a minute and with the help of left-over WAL files calculated
---
 src/backend/access/transam/xlog.c        | 18 +++++++++++++++++-
 src/backend/access/transam/xlogarchive.c |  2 +-
 2 files changed, 18 insertions(+), 2 deletions(-)

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index d894af310a..56b40884f1 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -3787,6 +3787,10 @@ XLogFileRead(XLogSegNo segno, int emode, TimeLineID tli,
 					 xlogfname);
 			set_ps_display(activitymsg);
 
+			ereport(LOG,
+					(errmsg("waiting for WAL segment \"%s\" from archive",
+							xlogfname)));
+
 			if (!RestoreArchivedFile(path, xlogfname,
 									 "RECOVERYXLOG",
 									 wal_segment_size,
@@ -3829,6 +3833,19 @@ XLogFileRead(XLogSegNo segno, int emode, TimeLineID tli,
 				 xlogfname);
 		set_ps_display(activitymsg);
 
+		if (source == XLOG_FROM_ARCHIVE)
+			ereport(LOG,
+					(errmsg("recovering WAL segment \"%s\" received from archive",
+							xlogfname)));
+		else if (source == XLOG_FROM_PG_WAL)
+			ereport(LOG,
+					(errmsg("recovering WAL segment \"%s\" received from pg_wal",
+							xlogfname)));
+		else if (source == XLOG_FROM_STREAM)
+			ereport(LOG,
+					(errmsg("recovering WAL segment \"%s\" received from primary",
+							xlogfname)));
+
 		/* Track source of data in assorted state variables */
 		readSource = source;
 		XLogReceiptSource = source;
@@ -3919,7 +3936,6 @@ XLogFileReadAnyTLI(XLogSegNo segno, int emode, XLogSource source)
 							  XLOG_FROM_ARCHIVE, true);
 			if (fd != -1)
 			{
-				elog(DEBUG1, "got WAL segment from archive");
 				if (!expectedTLEs)
 					expectedTLEs = tles;
 				return fd;
diff --git a/src/backend/access/transam/xlogarchive.c b/src/backend/access/transam/xlogarchive.c
index 4ddeac1fb9..1f724f4acf 100644
--- a/src/backend/access/transam/xlogarchive.c
+++ b/src/backend/access/transam/xlogarchive.c
@@ -214,7 +214,7 @@ RestoreArchivedFile(char *path, const char *xlogfname,
 			else
 			{
 				ereport(LOG,
-						(errmsg("restored log file \"%s\" from archive",
+						(errmsg("restored WAL segment \"%s\" from archive",
 								xlogfname)));
 				strcpy(path, xlogpath);
 				return true;
-- 
2.25.1

