Thread: Re: Make postmaster environment dump easier to skim over

Re: Make postmaster environment dump easier to skim over

From
Heikki Linnakangas
Date:
On 26/11/2024 18:55, Andres Freund wrote:
> 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.

I never do that and therefore didn't realize that we print that :-).

> 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.

+1

> 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.

+1 for removing PostmasterMain. The progname might be useful I guess, 
but it'd not clear from the message that that's what "postgres" is. 
Maybe change it to "progname: \"%s\", initial environment: ".

-- 
Heikki Linnakangas
Neon (https://neon.tech)