On Tue, 29 Oct 2024 at 23:43, Vijaykumar Jain < vijaykumarjain.git...@gmail.com> wrote:
> > > On Tue, 29 Oct 2024 at 22:00, Daniel Westermann (DWE) < > daniel.westerm...@dbi-services.com> wrote: > >> Delays between "connection received" and "connection authenticated" >> because of localhost entries in hba >> >> Hi, >> >> we're facing a strange issue with delays between "connection received" >> and "connection authenticated". >> >> # select version(); >> version >> >> ----------------------------------------------------------------------------------------------------------------------------------- >> PostgreSQL 15.6 (Ubuntu 15.6-1.pgdg22.04+1) on x86_64-pc-linux-gnu, >> compiled by gcc (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0, 64-bit >> (1 ligne) >> >> I know, this is not the latest minor version. >> >> # \! cat /etc/os-release | head -1 >> PRETTY_NAME="Ubuntu 22.04.4 LTS" >> >> What we see in the log is this (around 4 seconds delay): >> >> 2024-05-07 15:29:50.244 CEST [369909] LOG: connection received: >> host=xx.xx.xx.100 port=48434 >> 2024-05-07 15:29:54.518 CEST [369909] LOG: connection authenticated: >> identity="xxxxxx" method=md5 (/etc/postgresql/15/main/pg_hba.conf:121) >> >> > Just before we get into os and name resolution stuff.. > > 1) if the database usage is really heavy with schema churn and or heavy > temp usage. can the catalog bloat result in slowless of pg_auth* objects > resulting in slow authentication? > a general check used to be checking the size of the catalog objects and > if needed vacuum full in single user mode .... to speed up auth lookup. > > i tried with pg latest on ubuntu 22, but did not see any issues. > > > So to simulate a similar issue, i understand once connected, it will look > up pg_auth* objects cascading to other catalogs for resolution ... > in one session: > PGPASSWORD=1234 psql -h localhost -p 5432 -d postgres -U postgres -c > 'select 1' > > in another session > > postgres@ubuntu:~$ cat /tmp/db1/postgresql.auto.conf > # Do not edit this file manually! > # It will be overwritten by the ALTER SYSTEM command. > trace_locks = 'on' > trace_lock_table = 1260 > > > postgres=# select 'pg_authid'::regclass::oid; > oid > ------ > 1260 > (1 row) > postgres=*# lock table pg_authid in access exclusive mode; > LOCK TABLE > postgres=*# rollback; > ROLLBACK > > > i tried to trace which locks are held when a connection is established > after auth. > > for example pg_authid , so i enable tracing on this object, and to mock > the delay i try to lock the table in access exclusive mode ... > note, this may not be the scenario, but i am trying to rule out pg related > delay due to bloat or locking > > > postgres@ubuntu:/tmp$ time PGPASSWORD=1234 psql -h localhost -p 5432 -d > postgres -U postgres -c 'select 1' > ?column? > ---------- > 1 > (1 row) > > > real 0m7.503s - -delay > user 0m0.001s > sys 0m0.005s > > postgres@ubuntu:/tmp$ #after rollback of pg_authid > > > from the logs > 2024-10-29 18:04:46.411 UTC [localhost(33424)] [62661] LOG: connection > received: host=localhost port=33424 > 2024-10-29 18:04:53.906 UTC [localhost(33424)] [62661] LOG: connection > authenticated: identity="postgres" method=md5 (/tmp/db1/pg_hba.conf:120) > > > what i tried here was, delay auth but after connection established till > lock held, which can be due to bloated catalog objects or long locks due to > temp objects churn? > > still it does not explain how the order of pg_hba deals with the delay ? > > anyways, fyi to rule out :) > > -- > Thanks, > Vijay > > Open to work > Resume - Vijaykumar Jain <https://github.com/cabecada> > sorry, sharing again.
