Subject: Mysterious connections to PostgreSQL (no statement) coming from pgbouncer (mode = transaction)

From: Achilleas Mantzios <[email-masked]>
Date: Mon, 18 Nov 2024 22:03:03 +0200

Dear members,

Today I realized that I have connections coming from pgbouncer that do 
not execute any statement. Let me state the versions here :

* PostgreSQL 16.4 on x86_64-pc-linux-gnu, compiled by gcc (Debian 
12.2.0-14) 12.2.0, 64-bit

* Debian GNU/Linux 12 (bookworm),

* Linux smadb 6.7.12+bpo-amd64 #1 SMP PREEMPT_DYNAMIC Debian 
6.7.12-1~bpo12+1 (2024-05-06) x86_64 GNU/Linux

* pgbouncer : 1.23.1 (running in pool_mode=transaction)

We have been running pgbouncer (since 1.8) for quite some years, and 
today I realized I have connections to the DB from pgbouncer that don't 
do anything, do not execute any statement.

I realized this is the case, by noticing I got several disconnection LOG 
entries in PostgreSQL logs with no application_name set. It seemed weird 
to me, since all our connections are configured such that we run :

SET application_name=<tenant_name>; SET SEARCH_PATH='tenant''s search path';

Those represent a tiny minority of the total sessions, meaning that only 
a 0.8% (less than 1%) of disconnections exhibit this issue. And they 
come from regular business users, totally controlled by our own in-house 
app. We run jboss wildfly on the application server front, and all our 
connections come from the same data source definition, which always run 
the above commands in every case.

I know that a connection to pgbouncer without a statement will not 
result in a actual PgSQL connection. The server is only assigned by 
pgbouncer to the client on the first actual statement.

I logged with log_statement='all', log_min_duration_statement=0, and 
those yielded no useful info from the PgSQL logs , grepping with the 
relevant session gave log entries like :

postgres@smadb:~$ grep 673b8894.c922e data/log/postgresql-2024-11-18.log
10.9.0.10(57235) [823854] 673b8894.c922e 2024-11-18 20:33:56.361 EET 
[unknown] [unknown]@[unknown] line:1 LOG:  connection received: 
host=10.9.0.10 port=57235
10.9.0.10(57235) [823854] 673b8894.c922e 2024-11-18 20:33:56.381 EET 
[unknown] malexopoulou@dynacom line:2 LOG:  connection authenticated: 
identity="uid=malexopoulou,cn=users,
cn=accounts,dc=internal,dc=net" method=ldap 
(/var/lib/pgsql/data/pg_hba.conf:130)
10.9.0.10(57235) [823854] 673b8894.c922e 2024-11-18 20:33:56.381 EET 
[unknown] malexopoulou@dynacom line:3 LOG:  connection authorized: 
user=malexopoulou database=dynacom
10.9.0.10(57235) [823854] 673b8894.c922e 2024-11-18 20:34:56.668 EET 
[unknown] malexopoulou@dynacom line:4 LOG:  disconnection: session time: 
0:01:00.307 user=malexopoulou dat
abase=dynacom host=10.9.0.10 port=57235
postgres@smadb:~$

With no actual statement, which of course explains the "[unknown]" 
application_name, but not the actual cause of those connections.

Has anyone encountered anything like that?

---

From: "David G. Johnston" <[email-masked]>
Date: Mon, 18 Nov 2024 13:07:12 -0700

On Mon, Nov 18, 2024 at 1:03 PM Achilleas Mantzios <
[email-masked]> wrote:

> We have been running pgbouncer (since 1.8) for quite some years, and today
> I realized I have connections to the DB from pgbouncer that don't do
> anything, do not execute any statement.
>

Seems reasonable that a pooler would open connections to PostgreSQL to
prime the pool even before any demand is seen.  That way demand is
immediately given a functioning connection.

David J.

---

From: Achilleas Mantzios <[email-masked]>
Date: Mon, 18 Nov 2024 22:54:29 +0200

Στις 18/11/24 22:07, ο/η David G. Johnston έγραψε:
> On Mon, Nov 18, 2024 at 1:03 PM Achilleas Mantzios 
> <[email-masked]> wrote:
>
>     We have been running pgbouncer (since 1.8) for quite some years,
>     and today I realized I have connections to the DB from pgbouncer
>     that don't do anything, do not execute any statement.
>
>

Hello David,

I forgot to mention that in pgbouncer : min_pool_size=0 . So not reasonable.