On Sun, Dec 3, 2023 at 4:16 AM Tom Lane <t...@sss.pgh.pa.us> wrote:
>
> Nathan Bossart <nathandboss...@gmail.com> writes:
> > On Sat, Dec 02, 2023 at 07:36:29PM +0530, Bharath Rupireddy wrote:
> >> I started to think if this code is needed at all in production. How
> >> about we do either of the following?
>
> > Well, the fact that this code is hidden behind an off-by-default macro
> > seems like a pretty strong indicator that it is not intended for
> > production.  But that doesn't mean we should remove it.
>
> Agreed, production is not the question here.  The question is whether
> it's of any use to developers either.  It looks to me that the code's
> been broken since v13, if not before, which very strongly suggests
> that nobody is using it.  Think I'd vote for nuking it rather than
> putting effort into fixing it.

How about something like the attached? Please see the commit message
for more detailed information.

--
Bharath Rupireddy
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
From 9963f25be8c8400365f592c0e0b125f4dd62d3d6 Mon Sep 17 00:00:00 2001
From: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Date: Sun, 3 Dec 2023 14:05:02 +0000
Subject: [PATCH v1] Remove WAL_DEBUG related code

At a high-level the code under WAL_DEBUG macro does the following:
1. Decodes (not logical decoding but DecodeXLogRecord()) every
generated WAL record using a special memory context and emits the
decoded info as a LOG message.

2. Emits messages at DEBUG level in AdvanceXLInsertBuffer(), at
LOG level in XLogFlush(), at LOG level in XLogBackgroundFlush().

3. Emits messages at LOG level for every record that the server
replays in the main redo loop.

Decoding of generated WAL records (1) if needed can be done by
either pg_walinspect or pg_waldump. The main redo apply loop is
anyway generating a LOG record with LSN of the record being
applied at certain intervals, so (3) is not needed.

Before this commit, compilation of the source code was failing
with WAL_DEBUG enabled. If compilation issues were fixed, some of
the TAP tests were failing.

With no real use of this code in production, instead of fixing
compilation issues and TAP test failures to maintain the code,
this commit removes code related to both WAL_DEBUG macro and
wal_debug GUC, converts the messages (2) to DEBUG2 level and
moves before and after page comparison check in generic_xlog.c
under USE_ASSERT_CHECKING macro.
---
 doc/src/sgml/config.sgml                  |  16 ---
 src/backend/access/transam/generic_xlog.c |   8 +-
 src/backend/access/transam/xlog.c         | 128 +++-------------------
 src/backend/access/transam/xlogrecovery.c |  38 -------
 src/backend/utils/misc/guc_tables.c       |  13 ---
 src/include/access/xlog.h                 |   4 -
 src/include/pg_config_manual.h            |   6 -
 src/test/recovery/t/018_wal_optimize.pl   |   1 -
 8 files changed, 20 insertions(+), 194 deletions(-)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 94d1eb2b81..3c4c93cf1b 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -11446,22 +11446,6 @@ LOG:  CleanUpLock: deleting: lock(0xb7acd844) id(24688,24696,0,0,0,1)
       </listitem>
      </varlistentry>
 
-     <varlistentry id="guc-wal-debug" xreflabel="wal_debug">
-      <term><varname>wal_debug</varname> (<type>boolean</type>)
-      <indexterm>
-       <primary><varname>wal_debug</varname> configuration parameter</primary>
-      </indexterm>
-      </term>
-      <listitem>
-       <para>
-        If on, emit WAL-related debugging output. This parameter is
-        only available if the <symbol>WAL_DEBUG</symbol> macro was
-        defined when <productname>PostgreSQL</productname> was
-        compiled.
-       </para>
-      </listitem>
-     </varlistentry>
-
     <varlistentry id="guc-ignore-checksum-failure" xreflabel="ignore_checksum_failure">
       <term><varname>ignore_checksum_failure</varname> (<type>boolean</type>)
       <indexterm>
diff --git a/src/backend/access/transam/generic_xlog.c b/src/backend/access/transam/generic_xlog.c
index abd9e1c749..75f951daff 100644
--- a/src/backend/access/transam/generic_xlog.c
+++ b/src/backend/access/transam/generic_xlog.c
@@ -244,12 +244,12 @@ computeDelta(PageData *pageData, Page curpage, Page targetpage)
 					   targetUpper, BLCKSZ,
 					   curUpper, BLCKSZ);
 
+#ifdef USE_ASSERT_CHECKING
+
 	/*
-	 * If xlog debug is enabled, then check produced delta.  Result of delta
-	 * application to curpage should be equivalent to targetpage.
+	 * Check produced delta. Result of delta application to curpage should be
+	 * equivalent to targetpage.
 	 */
-#ifdef WAL_DEBUG
-	if (XLOG_DEBUG)
 	{
 		PGAlignedBlock tmp;
 
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 6526bd4f43..e8d529b609 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -138,11 +138,6 @@ int			wal_retrieve_retry_interval = 5000;
 int			max_slot_wal_keep_size_mb = -1;
 int			wal_decode_buffer_size = 512 * 1024;
 bool		track_wal_io_timing = false;
-
-#ifdef WAL_DEBUG
-bool		XLOG_DEBUG = false;
-#endif
-
 int			wal_segment_size = DEFAULT_XLOG_SEG_SIZE;
 
 /*
@@ -644,10 +639,6 @@ static bool updateMinRecoveryPoint = true;
 static int	MyLockNo = 0;
 static bool holdingAllLocks = false;
 
-#ifdef WAL_DEBUG
-static MemoryContext walDebugCxt = NULL;
-#endif
-
 static void CleanupAfterArchiveRecovery(TimeLineID EndOfLogTLI,
 										XLogRecPtr EndOfLog,
 										TimeLineID newTLI);
@@ -997,70 +988,6 @@ XLogInsertRecord(XLogRecData *rdata,
 		}
 	}
 
-#ifdef WAL_DEBUG
-	if (XLOG_DEBUG)
-	{
-		static XLogReaderState *debug_reader = NULL;
-		XLogRecord *record;
-		DecodedXLogRecord *decoded;
-		StringInfoData buf;
-		StringInfoData recordBuf;
-		char	   *errormsg = NULL;
-		MemoryContext oldCxt;
-
-		oldCxt = MemoryContextSwitchTo(walDebugCxt);
-
-		initStringInfo(&buf);
-		appendStringInfo(&buf, "INSERT @ %X/%X: ", LSN_FORMAT_ARGS(EndPos));
-
-		/*
-		 * We have to piece together the WAL record data from the XLogRecData
-		 * entries, so that we can pass it to the rm_desc function as one
-		 * contiguous chunk.
-		 */
-		initStringInfo(&recordBuf);
-		for (; rdata != NULL; rdata = rdata->next)
-			appendBinaryStringInfo(&recordBuf, rdata->data, rdata->len);
-
-		/* We also need temporary space to decode the record. */
-		record = (XLogRecord *) recordBuf.data;
-		decoded = (DecodedXLogRecord *)
-			palloc(DecodeXLogRecordRequiredSpace(record->xl_tot_len));
-
-		if (!debug_reader)
-			debug_reader = XLogReaderAllocate(wal_segment_size, NULL,
-											  XL_ROUTINE(), NULL);
-
-		if (!debug_reader)
-		{
-			appendStringInfoString(&buf, "error decoding record: out of memory while allocating a WAL reading processor");
-		}
-		else if (!DecodeXLogRecord(debug_reader,
-								   decoded,
-								   record,
-								   EndPos,
-								   &errormsg))
-		{
-			appendStringInfo(&buf, "error decoding record: %s",
-							 errormsg ? errormsg : "no error message");
-		}
-		else
-		{
-			appendStringInfoString(&buf, " - ");
-
-			debug_reader->record = decoded;
-			xlog_outdesc(&buf, debug_reader);
-			debug_reader->record = NULL;
-		}
-		elog(LOG, "%s", buf.data);
-
-		pfree(decoded);
-		pfree(buf.data);
-		pfree(recordBuf.data);
-		MemoryContextSwitchTo(oldCxt);
-	}
-#endif
-
 	/*
 	 * Update our global variables
 	 */
@@ -1995,13 +1922,11 @@ AdvanceXLInsertBuffer(XLogRecPtr upto, TimeLineID tli, bool opportunistic)
 	}
 	LWLockRelease(WALBufMappingLock);
 
-#ifdef WAL_DEBUG
-	if (XLOG_DEBUG && npages > 0)
-	{
-		elog(DEBUG1, "initialized %d pages, up to %X/%X",
-			 npages, LSN_FORMAT_ARGS(NewPageEndPtr));
-	}
-#endif
+	if (npages > 0)
+		ereport(DEBUG2,
+				(errmsg_internal("initialized %d pages, up to %X/%X",
+								 npages,
+								 LSN_FORMAT_ARGS(NewPageEndPtr))));
 }
 
 /*
@@ -2639,13 +2564,11 @@ XLogFlush(XLogRecPtr record)
 	if (record <= LogwrtResult.Flush)
 		return;
 
-#ifdef WAL_DEBUG
-	if (XLOG_DEBUG)
-		elog(LOG, "xlog flush request %X/%X; write %X/%X; flush %X/%X",
-			 LSN_FORMAT_ARGS(record),
-			 LSN_FORMAT_ARGS(LogwrtResult.Write),
-			 LSN_FORMAT_ARGS(LogwrtResult.Flush));
-#endif
+	ereport(DEBUG2,
+			(errmsg_internal("xlog flush request %X/%X; current write position %X/%X, flush position %X/%X",
+							 LSN_FORMAT_ARGS(record),
+							 LSN_FORMAT_ARGS(LogwrtResult.Write),
+							 LSN_FORMAT_ARGS(LogwrtResult.Flush))));
 
 	START_CRIT_SECTION();
 
@@ -2901,14 +2824,12 @@ XLogBackgroundFlush(void)
 		WriteRqst.Flush = 0;
 	}
 
-#ifdef WAL_DEBUG
-	if (XLOG_DEBUG)
-		elog(LOG, "xlog bg flush request write %X/%X; flush: %X/%X, current is write %X/%X; flush %X/%X",
-			 LSN_FORMAT_ARGS(WriteRqst.Write),
-			 LSN_FORMAT_ARGS(WriteRqst.Flush),
-			 LSN_FORMAT_ARGS(LogwrtResult.Write),
-			 LSN_FORMAT_ARGS(LogwrtResult.Flush));
-#endif
+	ereport(DEBUG2,
+			(errmsg_internal("xlog background flush request write position %X/%X, flush position %X/%X; current write position %X/%X, flush position %X/%X",
+							 LSN_FORMAT_ARGS(WriteRqst.Write),
+							 LSN_FORMAT_ARGS(WriteRqst.Flush),
+							 LSN_FORMAT_ARGS(LogwrtResult.Write),
+							 LSN_FORMAT_ARGS(LogwrtResult.Flush))));
 
 	START_CRIT_SECTION();
 
@@ -4654,23 +4575,6 @@ XLOGShmemInit(void)
 	int			i;
 	ControlFileData *localControlFile;
 
-#ifdef WAL_DEBUG
-
-	/*
-	 * Create a memory context for WAL debugging that's exempt from the normal
-	 * "no pallocs in critical section" rule. Yes, that can lead to a PANIC if
-	 * an allocation fails, but wal_debug is not for production use anyway.
-	 */
-	if (walDebugCxt == NULL)
-	{
-		walDebugCxt = AllocSetContextCreate(TopMemoryContext,
-											"WAL Debug",
-											ALLOCSET_DEFAULT_SIZES);
-		MemoryContextAllowInCriticalSection(walDebugCxt, true);
-	}
-#endif
-
-
 	XLogCtl = (XLogCtlData *)
 		ShmemInitStruct("XLOG Ctl", XLOGShmemSize(), &foundXLog);
 
diff --git a/src/backend/access/transam/xlogrecovery.c b/src/backend/access/transam/xlogrecovery.c
index c61566666a..c0b6dc67fa 100644
--- a/src/backend/access/transam/xlogrecovery.c
+++ b/src/backend/access/transam/xlogrecovery.c
@@ -396,9 +396,6 @@ static bool read_tablespace_map(List **tablespaces);
 static void xlogrecovery_redo(XLogReaderState *record, TimeLineID replayTLI);
 static void CheckRecoveryConsistency(void);
 static void rm_redo_error_callback(void *arg);
-#ifdef WAL_DEBUG
-static void xlog_outrec(StringInfo buf, XLogReaderState *record);
-#endif
 static void xlog_block_info(StringInfo buf, XLogReaderState *record);
 static void checkTimeLineSwitch(XLogRecPtr lsn, TimeLineID newTLI,
 								TimeLineID prevTLI, TimeLineID replayTLI);
@@ -1703,25 +1700,6 @@ PerformWalRecovery(void)
 				ereport_startup_progress("redo in progress, elapsed time: %ld.%02d s, current LSN: %X/%X",
 										 LSN_FORMAT_ARGS(xlogreader->ReadRecPtr));
 
-#ifdef WAL_DEBUG
-			if (XLOG_DEBUG ||
-				(record->xl_rmid == RM_XACT_ID && trace_recovery_messages <= DEBUG2) ||
-				(record->xl_rmid != RM_XACT_ID && trace_recovery_messages <= DEBUG3))
-			{
-				StringInfoData buf;
-
-				initStringInfo(&buf);
-				appendStringInfo(&buf, "REDO @ %X/%X; LSN %X/%X: ",
-								 LSN_FORMAT_ARGS(xlogreader->ReadRecPtr),
-								 LSN_FORMAT_ARGS(xlogreader->EndRecPtr));
-				xlog_outrec(&buf, xlogreader);
-				appendStringInfoString(&buf, " - ");
-				xlog_outdesc(&buf, xlogreader);
-				elog(LOG, "%s", buf.data);
-				pfree(buf.data);
-			}
-#endif
-
 			/* Handle interrupt signals of startup process */
 			HandleStartupProcInterrupts();
 
@@ -2256,22 +2234,6 @@ xlog_outdesc(StringInfo buf, XLogReaderState *record)
 	rmgr.rm_desc(buf, record);
 }
 
-#ifdef WAL_DEBUG
-
-static void
-xlog_outrec(StringInfo buf, XLogReaderState *record)
-{
-	appendStringInfo(buf, "prev %X/%X; xid %u",
-					 LSN_FORMAT_ARGS(XLogRecGetPrev(record)),
-					 XLogRecGetXid(record));
-
-	appendStringInfo(buf, "; len %u",
-					 XLogRecGetDataLen(record));
-
-	xlog_block_info(buf, record);
-}
-#endif							/* WAL_DEBUG */
-
 /*
  * Returns a string giving information about all the blocks in an
  * XLogRecord.
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 6474e35ec0..db332a06ba 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -1702,19 +1702,6 @@ struct config_bool ConfigureNamesBool[] =
 	},
 #endif
 
-#ifdef WAL_DEBUG
-	{
-		{"wal_debug", PGC_SUSET, DEVELOPER_OPTIONS,
-			gettext_noop("Emit WAL-related debugging output."),
-			NULL,
-			GUC_NOT_IN_SAMPLE
-		},
-		&XLOG_DEBUG,
-		false,
-		NULL, NULL, NULL
-	},
-#endif
-
 	{
 		{"integer_datetimes", PGC_INTERNAL, PRESET_OPTIONS,
 			gettext_noop("Shows whether datetimes are integer based."),
diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h
index a14126d164..50dc6140a5 100644
--- a/src/include/access/xlog.h
+++ b/src/include/access/xlog.h
@@ -123,10 +123,6 @@ extern PGDLLIMPORT int wal_level;
 /* Do we need to WAL-log information required only for logical replication? */
 #define XLogLogicalInfoActive() (wal_level >= WAL_LEVEL_LOGICAL)
 
-#ifdef WAL_DEBUG
-extern PGDLLIMPORT bool XLOG_DEBUG;
-#endif
-
 /*
  * OR-able request flag bits for checkpoints.  The "cause" bits are used only
  * for logging purposes.  Note: the flags must be defined so that it's
diff --git a/src/include/pg_config_manual.h b/src/include/pg_config_manual.h
index 8a6e67a445..5b9b01f4b7 100644
--- a/src/include/pg_config_manual.h
+++ b/src/include/pg_config_manual.h
@@ -354,12 +354,6 @@
  */
 /* #define LOCK_DEBUG */
 
-/*
- * Enable debugging print statements for WAL-related operations; see
- * also the wal_debug GUC var.
- */
-/* #define WAL_DEBUG */
-
 /*
  * Enable tracing of resource consumption during sort operations;
  * see also the trace_sort GUC var.  For 8.1 this is enabled by default.
diff --git a/src/test/recovery/t/018_wal_optimize.pl b/src/test/recovery/t/018_wal_optimize.pl
index 1d613eaede..bb6082f956 100644
--- a/src/test/recovery/t/018_wal_optimize.pl
+++ b/src/test/recovery/t/018_wal_optimize.pl
@@ -53,7 +53,6 @@ wal_level = $wal_level
 max_prepared_transactions = 1
 wal_log_hints = on
 wal_skip_threshold = 0
-#wal_debug = on
 ));
 	$node->start;
 
-- 
2.34.1

Reply via email to