Re: Log connection establishment timings - Mailing list pgsql-hackers

> On 7 Mar 2025, at 23:08, Melanie Plageman <melanieplageman@gmail.com> wrote:

Sorry for being late to the party.  I like this functionality and would
definitely like to see it in v18.

> An unrelated note about the attached v13:
> I changed the language from log_connections "stages" to "options" and
> "aspects" depending on the context. I also changed the name of the
> option introduced in 0002 to "durations".

I like the use options/aspects here, it works better than stages IMO.

A few comments on the patch:

+   /* For backwards compatibility, we accept these tokens by themselves */
+   static const struct config_enum_entry compat_options[] = {
+       {"off", 0},
+       {"false", 0},
+       {"no", 0},
+       {"0", 0},
+       {"on", LOG_CONNECTION_ON},
+       {"true", LOG_CONNECTION_ON},
+       {"yes", LOG_CONNECTION_ON},
+       {"1", LOG_CONNECTION_ON},
+   };
It's not documented here that the backwards compatibility will turn the
LOG_CONNECTION_ON value into a set of the new fine-grained value.  A brief
mention would be good for future code reading (or a hint to look for details in
src/include/tcop/backend_startup.h).

+   LOG_CONNECTION_ON =
+       LOG_CONNECTION_RECEIPT |
+       LOG_CONNECTION_AUTHENTICATION |
+       LOG_CONNECTION_AUTHORIZATION,
+   LOG_CONNECTION_ALL =
+       LOG_CONNECTION_ON,
Nitpick I know, but reusing the backwards compatible _ON for _ALL makes it seem
like they are the other way around (_ALL being for backwards compat).  0002
makes it less so but I would prefer to spend the extra lines of code and spell
out both.

+#define IsConnectionBackend(backend_type) \
This feels like a slightly too generic name to fully convey what it does.  I
don't have a better one off the cuff but I had to refer back multiple times to
remind myself what it did.

+   backend at the time the connection is ready for use. The log
I'm not sure if "ready for use" will be clear for all readers?  The other
options are using a bit more precise language.

+   {"durations", LOG_CONNECTION_DURATIONS},
I think "durations" is a good name for this, but we risk causing some confusion
in postgresql.conf when set, as it will end up like this:

    log_connections = durations
    #log_disconnections = off
    #log_duration = off

How log_connections=durations and log_duration=off are related might not be
immediately obvious to new users.  Can we avoid confusion by adding comments on
these log entries perhaps?

+   errmsg("connection ready: total=%.3f ms, fork=%.3f ms, authentication=%.3f ms",
The use of "total" here makes it seem like (fork+authentication)=total.  Not
sure if we can do better and still be descriptive.  Maybe it's a case of
documenting it if there are questions or complaints?

> I'm a bit torn about having the tests in authentication/001_password.

Agreed, they're not a great fit and it's not where I would look for them.  That
being said, paying for spinning up a new cluster for just this also doesn't
seem great.  Maybe adding a comment in the test file explaining why they are in
there could help readers.

--
Daniel Gustafsson