On Mon, Mar 3, 2025 at 11:45 PM Fujii Masao <masao.fu...@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