From: | Melanie Plageman <melanieplageman(at)gmail(dot)com> |
---|---|
To: | Daniel Gustafsson <daniel(at)yesql(dot)se> |
Cc: | Fujii Masao <masao(dot)fujii(at)oss(dot)nttdata(dot)com>, Andres Freund <andres(at)anarazel(dot)de>, Bertrand Drouvot <bertranddrouvot(dot)pg(at)gmail(dot)com>, Guillaume Lelarge <guillaume(at)lelarge(dot)info>, PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org>, andrey(dot)chudnovskiy(at)microsoft(dot)com, Jelte Fennema-Nio <postgres(at)jeltef(dot)nl> |
Subject: | Re: Log connection establishment timings |
Date: | 2025-03-11 22:27:40 |
Message-ID: | CAAKRu_Zgk-_xLxpddscwYSzGXS_jbLS_fzK1TvjUBYFDEXuPMg@mail.gmail.com |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-hackers |
On Mon, Mar 10, 2025 at 5:03 PM Daniel Gustafsson <daniel(at)yesql(dot)se> wrote:
>
> > 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.
Thanks so much for the review!
> + /* 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).
I've added a comment about this in attached v14.
> + 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.
Done.
> +#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.
Is `IsClientBackend()` better? It doesn't sound immediately like it
includes WAL sender backends (replication connections), but those are
initiated by clients too, right?
I didn't change it in v14 because I wasn't sure it was better and
wanted to hear what you thought.
> + 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.
I've tried to clear this up.
> + {"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?
I forgot about log_duration and that log_disconnections prints the
connection duration. Thinking about it more and taking into account
something Bertrand suggested upthread, I decided to rename the option
"setup_durations". It's a bit long, but it does convey that these
durations are only about connection setup.
I also added more details about what this is both to docs and
postgresql.conf.sample. Thanks!
> + 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've changed it to "setup total=xxx ms, fork=xxx...". I also added
details about the component durations to the docs.
> > 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.
Yep, added the comment.
I did more manual testing of my patches, and I think they are mostly
ready for commit except for the IsConnectionBackend() macro (if we
have something to change it to).
I did notice one other thing, though. Because
process_startup_options() is called after all the existing
log_connections messages are emitted, setup_durations behaves a bit
differently than the other options. I actually think the other
log_connections options are not quite right, so perhaps it is okay
that the new option is different if it is more compliant.
For example, if you start from a freshly initdb'd cluster and do ALTER
SYSTEM SET log_connections='all', then restart or reload the conf file
and reconnect, you'll see the receipt, authentication, authorization,
and setup_durations messages. If you then `export PGOPTIONS="-c
log_connections="` and reconnect again, you'll see the receipt,
authentication, and authorization messages but not the setup_durations
message. The setup_durations message is emitted after we process
PGOPTIONS and set log_connections = ''. I think this behavior is okay,
though I'm not sure if/where it should be documented
- Melanie
Attachment | Content-Type | Size |
---|---|---|
v14-0001-Modularize-log_connections-output.patch | text/x-patch | 20.9 KB |
v14-0002-Add-connection-establishment-duration-logging.patch | text/x-patch | 17.1 KB |
From | Date | Subject | |
---|---|---|---|
Next Message | Masahiko Sawada | 2025-03-11 22:31:42 | Re: [Patch] remove duplicated smgrclose |
Previous Message | Alena Rybakina | 2025-03-11 22:24:22 | Re: Adding skip scan (including MDAM style range skip scan) to nbtree |