Re: Log connection establishment timings

> On 7 Mar 2025, at 23:08, Melanie Plageman <melanieplageman(at)gmail(dot)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