Log connection establishment timings
Melanie Plageman <melanieplageman@gmail.com>
From: Melanie Plageman <melanieplageman@gmail.com>
To: Pg Hackers <pgsql-hackers@postgresql.org>
Cc: Daniel Gustafsson <daniel@yesql.se>, andrey.chudnovskiy@microsoft.com, Jelte Fennema-Nio <postgres@jeltef.nl>
Date: 2024-12-16T21:00:02Z
Lists: pgsql-hackers
Attachments
- v1-0001-Add-connection-establishment-duration-logging.patch (text/x-patch) patch v1-0001
Hi, 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. The attached patch logs durations for authentication, forking the Postgres backend, and the end-to-end connection establishment duration starting from when the postmaster calls accept() and ending the first time the forked backend is ready for query. As an example of how this could be useful, I artificially slowed down authentication and you can see that that is now visible in logs: LOG: backend ready for query. pid=86341. socket=10. connection establishment times (ms): total: 8, fork: 0, authentication: 0 LOG: backend ready for query. pid=86794. socket=10. connection establishment times (ms): total: 108, fork: 0, authentication: 100 Two notes on implementation: To make this portable, the timestamps captured in the postmaster (socket creation time, fork initiation time) are passed through the ClientSocket and BackendStartupData structures instead of simply saved in backend local memory inherited by the child process. Secondly, I used TimestampTz for the times, but it is pretty unclear to me when instr_time should be used vs TimestampTz for such things. instr_time says it is more portable, but there are all sorts of places that use TimestampTz that would probably need to be portable. Also, INSTR_TIME_SUBTRACT() isn't overflow safe, which must be because the actual data type of ticks is platform dependent and so the caller is responsible for not passing it values that would overflow when subtracted. - Melanie
Commits
-
Replace deprecated log_connections values in docs and tests
- cb1456423d39 18.0 landed