Re: Log connection establishment timings

On 2025/03/07 8:16, Melanie Plageman wrote:
> On Thu, Mar 6, 2025 at 2:10 PM Andres Freund <andres(at)anarazel(dot)de> wrote:
>>
>> I think it'd be better to use absolute times and store them as such in
>> ConnectionTimes or whatever. That way we have information about when a
>> connection was established for some future SQL functions and for debugging
>> problems.
>
> Attached v12 does this (uses timestamps instead of instr_time).

Thanks for updating the patch!

Here are the comments for v1:

With the patch, any unambiguous prefix of a valid boolean value,
like 'y', is no longer accepted even though it's currently valid
for boolean GUCs. I don’t have a strong opinion on whether
we should maintain compatibility for this, but I wanted to
mention it for the record. If we do, we might need to use
parse_bool() to interpret the values.

+ * NONE is an alias for when no connection logging should be done.

The comment about "NONE" should be removed since LOG_CONNECTION_NONE was deleted.

+typedef enum LogConnectionOption
+{
+ LOG_CONNECTION_RECEIVED = (1 << 0),
+ LOG_CONNECTION_AUTHENTICATED = (1 << 1),

Since the GUC is named log_connections, I'm tempted to name
LOG_CONNECTIONS_XXX and LogConnectionsOption here instead.
This is just a suggestion. If others prefer the current names,
I’m fine with that.

Comments for v2:

+ if (IsConnectionBackend(child_type))
+ conn_timing.fork_end = GetCurrentTimestamp();

In SubPostmasterMain(), GetCurrentTimestamp() is called twice to
set fork_end. It seems unnecessary. We can remove the above call?

+ /* Capture authentication start time for logging */
+ conn_timing.auth_start = GetCurrentTimestamp();

In the EXEC_BACKEND case, the authentication start time differs
from when the authentication timeout begins. But shouldn't these
be the same?

Regards,

--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION