On Mon, Mar 3, 2025 at 11:45 PM Fujii Masao <masao.fujii@oss.nttdata.com> wrote:
>
> When log_connection is empty string in postgresql.conf and I ran
> "psql -d "options=-clog_connections=all"", I got the following log message.
> You can see the total duration in this message is unexpected.
> It looks like this happens because creation_time wasn’t collected,
> as log_connections was empty before the fork.
>
> LOG: connection establishment times (ms): total: 1148052469, fork: 0, authentication: 0
Wow, yes, thanks for catching that. I didn't remember that you could
pass startup options like that. For that example,
process_startup_options() actually happens so late that we do not have
the intended value of log_connections until after we've already taken
all of the timings. As such, I propose we take those measurements
unconditionally (since we established they aren't too expensive when
compared to the cost of actually forking the backend) and then only
emit the message if log_connections is "timings". We are guaranteed to
have the intended value of log_connections by the time we are
ready-for-query. I've implemented this in [1].
- Melanie
[1] https://www.postgresql.org/message-id/CAAKRu_aoerKAOYKkc7-JGq2bixrYTbViK_7EeLNhFUGoT_omFw%40mail.gmail.com
