Subject: Make postmaster environment dump easier to skim over

From: Andres Freund <[email-masked]>
Date: Tue, 26 Nov 2024 11:55:18 -0500

Hi,

I somewhat regularly start postmaster with log_min_messages DEBUG3-5. One
thing that makes that unnecessarily annoying is postmaster's environment dump
at startup.  It's visually hard to skip over, as it emits each environment
variable as a separate log message.

It's even worse if one uses log_error_verbosity=verbose or such, to get log
lines:

2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] DEBUG:  00000: postgres: PostmasterMain: initial environment dump:
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] LOCATION:  PostmasterMain, postmaster.c:887
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] DEBUG:  00000: -----------------------------------------
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] LOCATION:  PostmasterMain, postmaster.c:890
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] DEBUG:  00000: 	SHELL=/bin/bash
...
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] LOCATION:  PostmasterMain, postmaster.c:893
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] DEBUG:  00000: 	DISPLAY=:0
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] LOCATION:  PostmasterMain, postmaster.c:893
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] DEBUG:  00000: 	SHLVL=1
...
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] DEBUG:  00000: 	LC_TIME=C
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] LOCATION:  PostmasterMain, postmaster.c:893
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] DEBUG:  00000: -----------------------------------------
2024-11-26 11:34:17.739 EST [1097046][postmaster][:0][] LOCATION:  PostmasterMain, postmaster.c:895

isn't trivial to skim.

I think the dump is occasionally useful, so I don't think the best course is
to remove it entirely. But I think we could fairly easily improve the
situation by emitting all environment variables as a single elog message.

2024-11-26 11:35:58.877 EST [1097572][postmaster][:0][] DEBUG:  00000: postgres: PostmasterMain: initial environment dump:
	SHELL=/bin/bash
...
	DISPLAY=:0
	SHLVL=1
...
	LC_TIME=C
2024-11-26 11:35:58.877 EST [1097572][postmaster][:0][] LOCATION:  PostmasterMain, postmaster.c:879

is - IMNSHO - a heck of a lot more skimmable.

In the attached patch I chose to omit the "-----------------------------------------"
that we previously emmitted. IMO they're not really needed anymore now that
this is emitted as one message.

I'm not sure why the message includes "progname" and
PostmasterMain. Particularly the latter seems redundant with the elog
infrastructure today, the message is quite old (an elog since a033daf56639 in
2002 and an fprintf in the current location since ebb0a2014930, in 2000). But
I didn't touch that for now.

Alternatively we could just remove the message.

Greetings,

Andres Freund
>From 66aa0b81a25db80d2beb31df656a475c84b09d9b Mon Sep 17 00:00:00 2001
From: Andres Freund <[email-masked]>
Date: Tue, 26 Nov 2024 11:48:58 -0500
Subject: [PATCH v1] postmaster: Reduce verbosity of environment dump debug
 message

Emitting each variable is unnecessarily verbose / hard to skim over.

Author:
Reviewed-by:
Discussion: https://postgr.es/m/
Backpatch:
---
 src/backend/postmaster/postmaster.c | 19 ++++++++++---------
 1 file changed, 10 insertions(+), 9 deletions(-)

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index 78e66a06ac5..f17923adac1 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -839,20 +839,21 @@ PostmasterMain(int argc, char *argv[])
 #endif
 
 	/* For debugging: display postmaster environment */
+	if (message_level_is_interesting(DEBUG3))
 	{
 		extern char **environ;
 		char	  **p;
+		StringInfoData si;
 
-		ereport(DEBUG3,
-				(errmsg_internal("%s: PostmasterMain: initial environment dump:",
-								 progname)));
-		ereport(DEBUG3,
-				(errmsg_internal("-----------------------------------------")));
+		initStringInfo(&si);
+
+		appendStringInfo(&si, "%s: PostmasterMain: initial environment dump:",
+						 progname);
 		for (p = environ; *p; ++p)
-			ereport(DEBUG3,
-					(errmsg_internal("\t%s", *p)));
-		ereport(DEBUG3,
-				(errmsg_internal("-----------------------------------------")));
+			appendStringInfo(&si, "\n%s", *p);
+
+		ereport(DEBUG3, errmsg_internal("%s", si.data));
+		pfree(si.data);
 	}
 
 	/*
-- 
2.45.2.746.g06e570c0df.dirty