Thread: Re: Log connection establishment timings

Re: Log connection establishment timings

From
Jelte Fennema-Nio
Date:
On Mon, 16 Dec 2024 at 22:00, Melanie Plageman
<melanieplageman@gmail.com> wrote:
> Users wishing to debug slow connection establishment have little
> visibility into which steps take the most time. We don't expose any
> stats and none of the logging includes durations.

Two thoughts:
1. Would it make sense to also expose these timings in some pg_stat_xyz view?
2. As a user I'd be curious to know how much of the time is spent on
the network/client vs inside postgres. For example for the scram/sasl
handshake, how much of the authentication_time is spent waiting on the
first "read" after the server has called sendAuthRequest.



Re: Log connection establishment timings

From
Melanie Plageman
Date:
On Mon, Dec 16, 2024 at 6:26 PM Jelte Fennema-Nio <postgres@jeltef.nl> wrote:
>
> Two thoughts:
> 1. Would it make sense to also expose these timings in some pg_stat_xyz view?

So, right now there isn't an obvious place this would fit. There are
dynamic statistics views that are per connection -- like
pg_stat_ssl/gssapi. We could perhaps add authentication duration to
one of these. But I don't think this really helps users with the use
case I imagine for connection establishment logging. I thought that
people would look at the logs to see how their connection times have
changed over time -- for example if authentication started taking
longer. This also means a cumulative statistics view wouldn't be very
helpful. We could add a view to calculate connection establishment
median, standard deviation, average, etc, but that doesn't seem as
useful as the history of timings and how they have changed over that
time.

> 2. As a user I'd be curious to know how much of the time is spent on
> the network/client vs inside postgres. For example for the scram/sasl
> handshake, how much of the authentication_time is spent waiting on the
> first "read" after the server has called sendAuthRequest.

Well, with the current patch you can compare authentication duration
to total connection establishment duration to see how much time was
spent on authentication vs the rest of connection establishment.
Or do you mean adding another more granular level of timing: after
sendAuthRequest until PerformAuthentication() returns?
I'm not totally clear what "read" means in this context.

- Melanie