Re: Make postmaster environment dump easier to skim over

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)