We have a k8s cluster and postgres pods are running in it. Our backend services connect to postgres K8s service. I am trying to introduce PgBouncer as proxy when connecting to postgres pods. Postgres has ssl mode enabled and we have our own ROOT_CA, and an intermediate CA that is signed by the ROOT_CA. We create certificates for postgres signed by this intermediate CA. I am using the same intermediate CA to sign certificates for pgbouncer and creating a Self signed certificate for pgbouncer. I am mounting these certificates on pgbouncer pod. When I configure the backend service to redirect traffic to pgbouncer service and through pgbouncer to postgres,I am seeing below error:
2022-10-06 11:43:13.030 1 DEBUG parse_ini_file: 'verbose' = '2' ok:1
2022-10-06 11:43:13.033 1 NOISE event: 128, SBuf: 192, PgSocket: 400, IOBuf: 4108
2022-10-06 11:43:13.033 1 LOG file descriptor limit: 1048576 (H:1048576), max_client_conn: 100, max fds possible: 110
2022-10-06 11:43:13.033 1 DEBUG pktbuf_dynamic(128): 0x55a4515583c0
2022-10-06 11:43:13.033 1 DEBUG make_room(0x55a4515583c0, 4): realloc newlen=256
2022-10-06 11:43:13.033 1 DEBUG pktbuf_dynamic(128): 0x55a4515585c0
2022-10-06 11:43:13.034 1 NOISE connect(3, unix:/tmp/.s.PGSQL.5432) = No such file or directory
2022-10-06 11:43:13.034 1 DEBUG adns_create_context: udns 0.4
2022-10-06 11:43:13.034 1 DEBUG add_listen: 0.0.0.0:5432
2022-10-06 11:43:13.035 1 NOISE old TCP_DEFER_ACCEPT on 7 = 0
2022-10-06 11:43:13.035 1 NOISE install TCP_DEFER_ACCEPT on 7
2022-10-06 11:43:13.035 1 LOG listening on 0.0.0.0:5432
2022-10-06 11:43:13.035 1 DEBUG add_listen: ::/5432
2022-10-06 11:43:13.035 1 NOISE old TCP_DEFER_ACCEPT on 8 = 0
2022-10-06 11:43:13.035 1 NOISE install TCP_DEFER_ACCEPT on 8
2022-10-06 11:43:13.035 1 LOG listening on ::/5432
2022-10-06 11:43:13.035 1 DEBUG add_listen: unix:/tmp/.s.PGSQL.5432
2022-10-06 11:43:13.036 1 LOG listening on unix:/tmp/.s.PGSQL.5432
2022-10-06 11:43:13.036 1 LOG process up: pgbouncer 1.9.0, libevent 2.1.8-stable (epoll), adns: udns 0.4, tls: LibreSSL 2.6.5
2022-10-06 11:43:16.166 1 NOISE new fd from accept=10
2022-10-06 11:43:16.167 1 NOISE resync: done=0, parse=0, recv=0
2022-10-06 11:43:16.167 1 NOISE C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 pkt='!' len=8
2022-10-06 11:43:16.167 1 NOISE C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 C: req SSL
2022-10-06 11:43:16.167 1 NOISE C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 P: nak
2022-10-06 11:43:16.167 1 NOISE resync: done=8, parse=8, recv=8
2022-10-06 11:43:16.167 1 DEBUG C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 P: got connection: 127.0.0.6:38446 -> 127.0.0.6:5432
2022-10-06 11:43:16.167 1 NOISE safe_accept(7) = Resource temporarily unavailable
2022-10-06 11:43:16.167 1 NOISE resync: done=0, parse=0, recv=0
2022-10-06 11:43:16.167 1 NOISE C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 pkt='!' len=69
2022-10-06 11:43:16.168 1 DEBUG C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 got var: user=<user_name>
2022-10-06 11:43:16.168 1 DEBUG C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 got var: database=<database_name>
2022-10-06 11:43:16.168 1 DEBUG C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 using application_name: pg_isready
2022-10-06 11:43:16.168 1 NOISE cstr_get_pair: "host"="postgres-cluster"
2022-10-06 11:43:16.168 1 NOISE cstr_get_pair: "port"="5432"
2022-10-06 11:43:16.168 1 NOISE cstr_get_pair: "auth_user"="<user_name>"
2022-10-06 11:43:16.168 1 DEBUG pktbuf_dynamic(128): 0x55a4515686c0
2022-10-06 11:43:16.168 1 LOG C-0x55a451568fb0: (nodb)/(nouser)@127.0.0.6:38446 registered new auto-database: db=<database_name>
2022-10-06 11:43:16.168 1 DEBUG C-0x55a451568fb0: <user_name>/(nouser)@127.0.0.6:38446 pause_client
2022-10-06 11:43:16.168 1 NOISE S-0x55a45156ddf0: <database_name>/<user_name>@(bad-af):0 inet socket: postgres-db-pg-cluster
2022-10-06 11:43:16.168 1 NOISE S-0x55a45156ddf0: <database_name>/<user_name>@(bad-af):0 dns socket: postgres-db-pg-cluster
2022-10-06 11:43:16.168 1 NOISE dns: new req: postgres-cluster
2022-10-06 11:43:16.168 1 DEBUG zone_register(postgres-cluster)
2022-10-06 11:43:16.168 1 NOISE udns_timer_setter: ctx=0x55a4515665e0 timeout=0
2022-10-06 11:43:16.168 1 NOISE dns: udns_launch_query(postgres-cluster)=0x55a4515688e0
2022-10-06 11:43:16.168 1 NOISE udns_timer_cb
2022-10-06 11:43:16.168 1 NOISE udns_timer_setter: ctx=0x55a4515665e0 timeout=4
2022-10-06 11:43:16.168 1 DEBUG launch_new_connection: already progress
2022-10-06 11:43:16.168 1 NOISE udns_io_cb
2022-10-06 11:43:16.168 1 NOISE udns_result_a4: postgres-cluster: 1 ips
2022-10-06 11:43:16.168 1 NOISE DNS: postgres-cluster[0] = 10.43.169.137:0 [STREAM]
2022-10-06 11:43:16.168 1 NOISE dns: deliver_info(postgres-cluster) addr=10.43.169.137:0
2022-10-06 11:43:16.168 1 DEBUG S-0x55a45156ddf0: <database_name>/<user_name>@(bad-af):0 dns_callback: inet4: 10.43.169.137:5432
2022-10-06 11:43:16.168 1 DEBUG S-0x55a45156ddf0: <database_name>/<user_name>@10.43.169.137:5432 launching new connection to server
2022-10-06 11:43:16.169 1 NOISE udns_timer_setter: ctx=0x55a4515665e0 timeout=-1
2022-10-06 11:43:16.169 1 DEBUG launch_new_connection: already progress
2022-10-06 11:43:16.169 1 DEBUG S-0x55a45156ddf0: <database_name>/<user_name>@10.43.169.137:5432 S: connect ok
2022-10-06 11:43:16.169 1 LOG S-0x55a45156ddf0: <database_name>/<user_name>@10.43.169.137:5432 new connection to server (from 10.42.2.120:54000)
2022-10-06 11:43:16.169 1 NOISE S-0x55a45156ddf0: <database_name>/<user_name>@10.43.169.137:5432 P: SSL request
2022-10-06 11:43:16.169 1 DEBUG launch_new_connection: already progress
2022-10-06 11:43:16.175 1 NOISE resync: done=0, parse=0, recv=0
2022-10-06 11:43:16.175 1 NOISE S-0x55a45156ddf0: <database_name>/<user_name>@10.43.169.137:5432 launching tls
2022-10-06 11:43:16.175 1 NOISE resync: done=1, parse=1, recv=1
2022-10-06 11:43:16.175 1 NOISE tls_handshake: err=-2
2022-10-06 11:43:16.175 1 DEBUG launch_new_connection: already progress
2022-10-06 11:43:16.183 1 NOISE tls_handshake: err=-2
2022-10-06 11:43:16.183 1 DEBUG launch_new_connection: already progress
2022-10-06 11:43:16.184 1 NOISE tls_handshake: err=-1
**2022-10-06 11:43:16.184 1 WARNING TLS handshake error: handshake failed: error:1401E418:SSL routines:CONNECT_CR_FINISHED:tlsv1 alert unknown ca**
2022-10-06 11:43:16.184 1 LOG S-0x55a45156ddf0: <database_name>/<user_name>@10.43.169.137:5432 closing because: server conn crashed? (age=0)
2022-10-06 11:43:16.184 1 NOISE tls_close
Postgres logs show below error:
"postgres","aorsdb","authentication","connection authenticated:
identity=""postgres"" method=md5
(/home/postgres/pgdata/pgroot/data/pg_hba.conf:12)
"postgres","aorsdb","authentication","connection authorized:
user=postgres database=aorsdb application_name=pgwatch2 SSL enabled
(protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256) "could
not accept SSL connection: certificate verify failed
Can anyone suggest what might be wrong and what I can look at? pgbouncer.ini file:
[databases]
* = host=postgres-cluster port=5432 auth_user=postgres
[pgbouncer]
listen_addr = *
listen_port = 5432
pool_mode = session
max_client_conn = 100
ignore_startup_parameters = extra_float_digits
server_tls_sslmode = require
server_tls_key_file = /etc/pgbouncer/certs/server.key
server_tls_cert_file = /etc/pgbouncer/certs/server.crt
server_tls_ca_file = /etc/pgbouncer/certs/ca.crt
verbose = 2
Few questions:
I have done multiple things like mounting certificates in pgbouncer pod signed by the ROOT_CA itself, mounting certificate chain for pgbouncer(Generated certificate, Intermediate CA, ROOT CA) but no luck so far.
For me when I just use Intermediate_CA for pgbouncer, I can see it working properly and SSL connection getting established. Problem seems to be that postgres was not able to validate the SSL certificate that I was mounting in pgbouncer pod.