[13:19:06.321](0.071s) # setting up data directory
# Checking port 51829
# Found port 51829
Name: primary
Data directory: /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
Backup directory: /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/backup
Archive directory: /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/archives
Connection string: port=51829 host=/tmp/aXxR29YrxK
Log file: /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log
[13:19:06.354](0.033s) # initializing database system by copying initdb template
# Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
# Running: /tmp/cirrus-ci-build/src/test/ssl/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
### Starting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log -o --cluster-name=primary start
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 30740
[13:19:06.704](0.350s) ok 1 - ssl_library parameter
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31078
[13:19:08.649](1.945s) # testing password-protected keys
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
# pg_ctl restart failed; logfile:
2024-03-16 13:19:06.564 UTC [30740][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:06.564 UTC [30740][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:06.595 UTC [30752][startup] LOG:  database system was shut down at 2024-03-16 13:17:08 UTC
2024-03-16 13:19:06.607 UTC [30740][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:06.649 UTC [30769][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.655 UTC [30769][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.655 UTC [30769][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.693 UTC [30769][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-16 13:19:06.705 UTC [30769][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.058 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.717 UTC [30795][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.718 UTC [30795][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.718 UTC [30795][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.729 UTC [30795][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-16 13:19:06.731 UTC [30795][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.813 UTC [30818][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.814 UTC [30818][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.814 UTC [30818][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.819 UTC [30818][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-16 13:19:06.825 UTC [30818][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.885 UTC [30828][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.886 UTC [30828][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.886 UTC [30828][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.890 UTC [30828][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-16 13:19:06.892 UTC [30828][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.905 UTC [30834][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.906 UTC [30834][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.906 UTC [30834][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.908 UTC [30834][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-16 13:19:06.910 UTC [30834][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.962 UTC [30844][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.962 UTC [30844][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.962 UTC [30844][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.973 UTC [30844][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-16 13:19:07.040 UTC [30844][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.078 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.102 UTC [30870][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.102 UTC [30870][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.102 UTC [30870][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.126 UTC [30870][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-16 13:19:07.236 UTC [30870][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.134 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.410 UTC [30918][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.411 UTC [30918][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.411 UTC [30918][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.422 UTC [30918][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-16 13:19:07.518 UTC [30918][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.108 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.546 UTC [30933][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.546 UTC [30933][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.546 UTC [30933][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.561 UTC [30933][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-16 13:19:07.705 UTC [30933][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.159 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.858 UTC [30988][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.859 UTC [30988][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.859 UTC [30988][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.860 UTC [30988][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-16 13:19:07.915 UTC [30988][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.061 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.982 UTC [31013][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.986 UTC [31013][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.986 UTC [31013][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.993 UTC [31013][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-16 13:19:08.146 UTC [31013][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.167 user=postgres database=postgres host=[local]
2024-03-16 13:19:08.272 UTC [30740][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:08.272 UTC [30740][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:08.280 UTC [30740][postmaster] LOG:  background worker "logical replication launcher" (PID 30762) exited with exit code 1
2024-03-16 13:19:08.292 UTC [30750][checkpointer] LOG:  shutting down
2024-03-16 13:19:08.293 UTC [30750][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:08.361 UTC [30750][checkpointer] LOG:  checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.069 s, sync=0.001 s, total=0.069 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45479 kB, estimate=45479 kB; lsn=0/4194660, redo lsn=0/4194660
2024-03-16 13:19:08.374 UTC [30740][postmaster] LOG:  database system is shut down
2024-03-16 13:19:08.520 UTC [31078][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:08.520 UTC [31078][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:08.521 UTC [31078][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:08.534 UTC [31089][startup] LOG:  database system was shut down at 2024-03-16 13:19:08 UTC
2024-03-16 13:19:08.540 UTC [31078][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:08.658 UTC [31078][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:08.658 UTC [31078][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:08.667 UTC [31078][postmaster] LOG:  background worker "logical replication launcher" (PID 31098) exited with exit code 1
2024-03-16 13:19:08.667 UTC [31086][checkpointer] LOG:  shutting down
2024-03-16 13:19:08.667 UTC [31086][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:08.743 UTC [31086][checkpointer] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.076 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41946D8, redo lsn=0/41946D8
2024-03-16 13:19:08.826 UTC [31078][postmaster] LOG:  database system is shut down
2024-03-16 13:19:08.965 UTC [31165][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-16 13:19:08.965 UTC [31165][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:19:09.023](0.374s) ok 2 - restart fails with password-protected key file with wrong password
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
pg_ctl: PID file "/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/postmaster.pid" does not exist
Is server running?
trying to start server anyway
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31188
[13:19:09.230](0.206s) ok 3 - restart succeeds with password-protected key file
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
# pg_ctl restart failed; logfile:
2024-03-16 13:19:06.564 UTC [30740][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:06.564 UTC [30740][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:06.595 UTC [30752][startup] LOG:  database system was shut down at 2024-03-16 13:17:08 UTC
2024-03-16 13:19:06.607 UTC [30740][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:06.649 UTC [30769][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.655 UTC [30769][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.655 UTC [30769][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.693 UTC [30769][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-16 13:19:06.705 UTC [30769][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.058 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.717 UTC [30795][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.718 UTC [30795][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.718 UTC [30795][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.729 UTC [30795][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-16 13:19:06.731 UTC [30795][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.813 UTC [30818][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.814 UTC [30818][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.814 UTC [30818][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.819 UTC [30818][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-16 13:19:06.825 UTC [30818][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.885 UTC [30828][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.886 UTC [30828][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.886 UTC [30828][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.890 UTC [30828][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-16 13:19:06.892 UTC [30828][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.905 UTC [30834][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.906 UTC [30834][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.906 UTC [30834][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.908 UTC [30834][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-16 13:19:06.910 UTC [30834][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.962 UTC [30844][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.962 UTC [30844][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.962 UTC [30844][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.973 UTC [30844][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-16 13:19:07.040 UTC [30844][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.078 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.102 UTC [30870][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.102 UTC [30870][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.102 UTC [30870][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.126 UTC [30870][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-16 13:19:07.236 UTC [30870][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.134 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.410 UTC [30918][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.411 UTC [30918][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.411 UTC [30918][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.422 UTC [30918][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-16 13:19:07.518 UTC [30918][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.108 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.546 UTC [30933][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.546 UTC [30933][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.546 UTC [30933][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.561 UTC [30933][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-16 13:19:07.705 UTC [30933][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.159 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.858 UTC [30988][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.859 UTC [30988][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.859 UTC [30988][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.860 UTC [30988][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-16 13:19:07.915 UTC [30988][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.061 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.982 UTC [31013][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.986 UTC [31013][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.986 UTC [31013][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.993 UTC [31013][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-16 13:19:08.146 UTC [31013][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.167 user=postgres database=postgres host=[local]
2024-03-16 13:19:08.272 UTC [30740][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:08.272 UTC [30740][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:08.280 UTC [30740][postmaster] LOG:  background worker "logical replication launcher" (PID 30762) exited with exit code 1
2024-03-16 13:19:08.292 UTC [30750][checkpointer] LOG:  shutting down
2024-03-16 13:19:08.293 UTC [30750][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:08.361 UTC [30750][checkpointer] LOG:  checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.069 s, sync=0.001 s, total=0.069 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45479 kB, estimate=45479 kB; lsn=0/4194660, redo lsn=0/4194660
2024-03-16 13:19:08.374 UTC [30740][postmaster] LOG:  database system is shut down
2024-03-16 13:19:08.520 UTC [31078][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:08.520 UTC [31078][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:08.521 UTC [31078][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:08.534 UTC [31089][startup] LOG:  database system was shut down at 2024-03-16 13:19:08 UTC
2024-03-16 13:19:08.540 UTC [31078][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:08.658 UTC [31078][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:08.658 UTC [31078][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:08.667 UTC [31078][postmaster] LOG:  background worker "logical replication launcher" (PID 31098) exited with exit code 1
2024-03-16 13:19:08.667 UTC [31086][checkpointer] LOG:  shutting down
2024-03-16 13:19:08.667 UTC [31086][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:08.743 UTC [31086][checkpointer] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.076 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41946D8, redo lsn=0/41946D8
2024-03-16 13:19:08.826 UTC [31078][postmaster] LOG:  database system is shut down
2024-03-16 13:19:08.965 UTC [31165][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-16 13:19:08.965 UTC [31165][postmaster] LOG:  database system is shut down
2024-03-16 13:19:09.115 UTC [31188][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:09.115 UTC [31188][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:09.115 UTC [31188][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:09.145 UTC [31213][startup] LOG:  database system was shut down at 2024-03-16 13:19:08 UTC
2024-03-16 13:19:09.153 UTC [31188][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:09.240 UTC [31188][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:09.240 UTC [31188][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:09.245 UTC [31188][postmaster] LOG:  background worker "logical replication launcher" (PID 31217) exited with exit code 1
2024-03-16 13:19:09.249 UTC [31211][checkpointer] LOG:  shutting down
2024-03-16 13:19:09.249 UTC [31211][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:09.250 UTC [31211][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194750, redo lsn=0/4194750
2024-03-16 13:19:09.256 UTC [31188][postmaster] LOG:  database system is shut down
2024-03-16 13:19:09.413 UTC [31255][postmaster] FATAL:  could not set SSL protocol version range
2024-03-16 13:19:09.413 UTC [31255][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-16 13:19:09.413 UTC [31255][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:19:09.442](0.213s) ok 4 - restart fails with incorrect SSL protocol bounds
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
pg_ctl: PID file "/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/postmaster.pid" does not exist
Is server running?
trying to start server anyway
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31282
[13:19:09.550](0.108s) ok 5 - restart succeeds with correct SSL protocol bounds
[13:19:09.550](0.000s) # running client tests
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31320
[13:19:09.797](0.246s) ok 6 - server doesn't accept non-SSL connections
[13:19:09.797](0.000s) ok 7 - server doesn't accept non-SSL connections: matches
[13:19:09.887](0.090s) ok 8 - connect without server root cert sslmode=require
[13:19:09.887](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr
[13:19:09.927](0.040s) ok 10 - connect without server root cert sslmode=verify-ca
[13:19:09.927](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[13:19:09.977](0.050s) ok 12 - connect without server root cert sslmode=verify-full
[13:19:09.977](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches
[13:19:10.040](0.063s) ok 14 - connect with wrong server root cert sslmode=require
[13:19:10.040](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches
[13:19:10.081](0.041s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[13:19:10.081](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[13:19:10.134](0.053s) ok 18 - connect with wrong server root cert sslmode=verify-full
[13:19:10.134](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[13:19:10.207](0.073s) ok 20 - connect with server CA cert, without root CA
[13:19:10.208](0.000s) ok 21 - connect with server CA cert, without root CA: matches
[13:19:10.273](0.066s) ok 22 - connect with correct server CA cert file sslmode=require
[13:19:10.273](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[13:19:10.340](0.067s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[13:19:10.341](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[13:19:10.410](0.069s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[13:19:10.410](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[13:19:10.488](0.078s) ok 28 - cert root file that contains two certificates, order 1
[13:19:10.488](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[13:19:10.575](0.087s) ok 30 - cert root file that contains two certificates, order 2
[13:19:10.575](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[13:19:10.635](0.060s) ok 32 - connect with sslcertmode=disable
[13:19:10.635](0.000s) ok 33 - connect with sslcertmode=disable: no stderr
[13:19:10.690](0.055s) ok 34 - connect with sslcertmode=allow
[13:19:10.690](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[13:19:10.749](0.059s) ok 36 - connect with sslcertmode=require fails without a client certificate
[13:19:10.749](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[13:19:10.818](0.068s) ok 38 - sslcrl option with invalid file name
[13:19:10.818](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[13:19:10.858](0.040s) ok 40 - CRL belonging to a different CA
[13:19:10.858](0.000s) ok 41 - CRL belonging to a different CA: matches
[13:19:10.931](0.073s) ok 42 - directory CRL belonging to a different CA
[13:19:10.931](0.000s) ok 43 - directory CRL belonging to a different CA: matches
[13:19:10.978](0.046s) ok 44 - CRL with a non-revoked cert
[13:19:10.978](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[13:19:11.041](0.063s) ok 46 - directory CRL with a non-revoked cert
[13:19:11.041](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr
[13:19:11.103](0.062s) ok 48 - mismatch between host name and server certificate sslmode=require
[13:19:11.103](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[13:19:11.155](0.052s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[13:19:11.155](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[13:19:11.182](0.027s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[13:19:11.183](0.000s) ok 53 - mismatch between host name and server certificate sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31692
[13:19:11.472](0.289s) ok 54 - IP address in the Common Name
[13:19:11.472](0.000s) ok 55 - IP address in the Common Name: no stderr
[13:19:11.523](0.052s) ok 56 - mismatch between host name and server certificate IP address
[13:19:11.524](0.000s) ok 57 - mismatch between host name and server certificate IP address: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31771
[13:19:11.921](0.397s) ok 58 - IP address in a dNSName
[13:19:11.921](0.000s) ok 59 - IP address in a dNSName: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31839
[13:19:12.236](0.314s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[13:19:12.236](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[13:19:12.302](0.067s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[13:19:12.303](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[13:19:12.386](0.084s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[13:19:12.386](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[13:19:12.434](0.047s) ok 66 - host name not matching with X.509 Subject Alternative Names
[13:19:12.434](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[13:19:12.475](0.041s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[13:19:12.475](0.000s) ok 69 - host name not matching with X.509 Subject Alternative Names wildcard: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31921
[13:19:12.787](0.312s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[13:19:12.787](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[13:19:12.844](0.056s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[13:19:12.844](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[13:19:12.894](0.050s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[13:19:12.894](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 31989
[13:19:13.305](0.411s) ok 76 - host matching an IPv4 address (Subject Alternative Name 1)
[13:19:13.305](0.000s) ok 77 - host matching an IPv4 address (Subject Alternative Name 1): no stderr
[13:19:13.358](0.053s) ok 78 - host matching an IPv4 address in alternate form (Subject Alternative Name 1)
[13:19:13.358](0.000s) ok 79 - host matching an IPv4 address in alternate form (Subject Alternative Name 1): no stderr
[13:19:13.407](0.049s) ok 80 - host not matching an IPv4 address (Subject Alternative Name 1)
[13:19:13.407](0.000s) ok 81 - host not matching an IPv4 address (Subject Alternative Name 1): matches
[13:19:13.455](0.048s) ok 82 - host matching an IPv6 address (Subject Alternative Name 2)
[13:19:13.456](0.000s) ok 83 - host matching an IPv6 address (Subject Alternative Name 2): no stderr
[13:19:13.507](0.052s) ok 84 - host matching an IPv6 address in alternate form (Subject Alternative Name 2)
[13:19:13.507](0.000s) ok 85 - host matching an IPv6 address in alternate form (Subject Alternative Name 2): no stderr
[13:19:13.562](0.055s) ok 86 - host matching an IPv6 address in mixed form (Subject Alternative Name 2)
[13:19:13.563](0.000s) ok 87 - host matching an IPv6 address in mixed form (Subject Alternative Name 2): no stderr
[13:19:13.637](0.074s) ok 88 - host not matching an IPv6 address (Subject Alternative Name 2)
[13:19:13.637](0.000s) ok 89 - host not matching an IPv6 address (Subject Alternative Name 2): matches
[13:19:13.697](0.060s) ok 90 - IPv6 host with CIDR mask does not match
[13:19:13.697](0.000s) ok 91 - IPv6 host with CIDR mask does not match: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32111
[13:19:14.008](0.311s) ok 92 - certificate with both a CN and SANs 1
[13:19:14.008](0.000s) ok 93 - certificate with both a CN and SANs 1: no stderr
[13:19:14.062](0.053s) ok 94 - certificate with both a CN and SANs 2
[13:19:14.062](0.000s) ok 95 - certificate with both a CN and SANs 2: no stderr
[13:19:14.135](0.073s) ok 96 - certificate with both a CN and SANs ignores CN
[13:19:14.135](0.000s) ok 97 - certificate with both a CN and SANs ignores CN: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32180
[13:19:14.490](0.355s) ok 98 - certificate with both a CN and IP SANs matches CN
[13:19:14.490](0.000s) ok 99 - certificate with both a CN and IP SANs matches CN: no stderr
[13:19:14.539](0.049s) ok 100 - certificate with both a CN and IP SANs matches SAN 1
[13:19:14.539](0.000s) ok 101 - certificate with both a CN and IP SANs matches SAN 1: no stderr
[13:19:14.581](0.042s) ok 102 - certificate with both a CN and IP SANs matches SAN 2
[13:19:14.582](0.000s) ok 103 - certificate with both a CN and IP SANs matches SAN 2: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32261
[13:19:14.866](0.284s) ok 104 - certificate with both an IP CN and IP SANs 1
[13:19:14.866](0.000s) ok 105 - certificate with both an IP CN and IP SANs 1: no stderr
[13:19:15.234](0.368s) ok 106 - certificate with both an IP CN and IP SANs 2
[13:19:15.234](0.000s) ok 107 - certificate with both an IP CN and IP SANs 2: no stderr
[13:19:15.276](0.041s) ok 108 - certificate with both an IP CN and IP SANs ignores CN
[13:19:15.276](0.000s) ok 109 - certificate with both an IP CN and IP SANs ignores CN: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32331
[13:19:15.530](0.254s) ok 110 - certificate with both an IP CN and DNS SANs matches CN
[13:19:15.530](0.000s) ok 111 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[13:19:15.563](0.033s) ok 112 - certificate with both an IP CN and DNS SANs matches SAN 1
[13:19:15.563](0.000s) ok 113 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[13:19:15.605](0.042s) ok 114 - certificate with both an IP CN and DNS SANs matches SAN 2
[13:19:15.605](0.000s) ok 115 - certificate with both an IP CN and DNS SANs matches SAN 2: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32363
[13:19:15.874](0.268s) ok 116 - server certificate without CN or SANs sslmode=verify-ca
[13:19:15.874](0.000s) ok 117 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[13:19:15.919](0.045s) ok 118 - server certificate without CN or SANs sslmode=verify-full
[13:19:15.919](0.000s) ok 119 - server certificate without CN or SANs sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32394
[13:19:16.166](0.247s) ok 120 - sslrootcert=system does not connect with private CA
[13:19:16.166](0.000s) ok 121 - sslrootcert=system does not connect with private CA: matches
[13:19:16.198](0.032s) ok 122 - sslrootcert=system only accepts sslmode=verify-full
[13:19:16.199](0.000s) ok 123 - sslrootcert=system only accepts sslmode=verify-full: matches
[13:19:16.289](0.091s) ok 124 - sslrootcert=system connects with overridden SSL_CERT_FILE
[13:19:16.289](0.000s) ok 125 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[13:19:16.332](0.043s) ok 126 - sslrootcert=system defaults to sslmode=verify-full
[13:19:16.332](0.000s) ok 127 - sslrootcert=system defaults to sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32431
[13:19:16.653](0.321s) ok 128 - connects without client-side CRL
[13:19:16.654](0.000s) ok 129 - connects without client-side CRL: no stderr
[13:19:16.698](0.044s) ok 130 - does not connect with client-side CRL file
[13:19:16.698](0.000s) ok 131 - does not connect with client-side CRL file: matches
[13:19:16.771](0.073s) ok 132 - does not connect with client-side CRL directory
[13:19:16.771](0.000s) ok 133 - does not connect with client-side CRL directory: matches
# Running: psql -X -A -F , -P null=_null_ -d sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=invalid -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[13:19:16.803](0.033s) ok 134 - pg_stat_ssl view without client certificate: exit code 0
[13:19:16.804](0.000s) ok 135 - pg_stat_ssl view without client certificate: no stderr
[13:19:16.804](0.000s) ok 136 - pg_stat_ssl view without client certificate: matches
[13:19:16.832](0.028s) ok 137 - connection success with correct range of TLS protocol versions
[13:19:16.832](0.000s) ok 138 - connection success with correct range of TLS protocol versions: no stderr
[13:19:16.848](0.016s) ok 139 - connection failure with incorrect range of TLS protocol versions
[13:19:16.849](0.000s) ok 140 - connection failure with incorrect range of TLS protocol versions: matches
[13:19:16.872](0.024s) ok 141 - connection failure with an incorrect SSL protocol minimum bound
[13:19:16.872](0.000s) ok 142 - connection failure with an incorrect SSL protocol minimum bound: matches
[13:19:16.908](0.035s) ok 143 - connection failure with an incorrect SSL protocol maximum bound
[13:19:16.908](0.000s) ok 144 - connection failure with an incorrect SSL protocol maximum bound: matches
[13:19:16.908](0.000s) # running server tests
[13:19:16.937](0.029s) ok 145 - certificate authorization fails without client cert
[13:19:16.937](0.000s) ok 146 - certificate authorization fails without client cert: matches
[13:19:17.013](0.076s) ok 147 - certificate authorization succeeds with correct client cert in PEM format
[13:19:17.013](0.000s) ok 148 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[13:19:17.102](0.089s) ok 149 - certificate authorization succeeds with correct client cert in DER format
[13:19:17.103](0.000s) ok 150 - certificate authorization succeeds with correct client cert in DER format: no stderr
[13:19:17.157](0.055s) ok 151 - certificate authorization succeeds with correct client cert in encrypted PEM format
[13:19:17.157](0.000s) ok 152 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[13:19:17.207](0.050s) ok 153 - certificate authorization succeeds with correct client cert in encrypted DER format
[13:19:17.207](0.000s) ok 154 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[13:19:17.261](0.053s) ok 155 - certificate authorization succeeds with correct client cert and sslcertmode=require
[13:19:17.261](0.000s) ok 156 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[13:19:17.329](0.069s) ok 157 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[13:19:17.330](0.000s) ok 158 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[13:19:17.393](0.063s) ok 159 - certificate authorization fails with correct client cert and sslcertmode=disable
[13:19:17.393](0.000s) ok 160 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[13:19:17.458](0.065s) ok 161 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[13:19:17.458](0.000s) ok 162 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[13:19:17.505](0.046s) ok 163 - certificate authorization succeeds with DN mapping
[13:19:17.505](0.000s) ok 164 - certificate authorization succeeds with DN mapping: no stderr
[13:19:17.505](0.000s) ok 165 - certificate authorization succeeds with DN mapping: log matches
[13:19:17.554](0.049s) ok 166 - certificate authorization succeeds with DN regex mapping
[13:19:17.555](0.000s) ok 167 - certificate authorization succeeds with DN regex mapping: no stderr
[13:19:17.616](0.061s) ok 168 - certificate authorization succeeds with CN mapping
[13:19:17.616](0.000s) ok 169 - certificate authorization succeeds with CN mapping: no stderr
[13:19:17.616](0.000s) ok 170 - certificate authorization succeeds with CN mapping: log matches
[13:19:17.616](0.000s) not ok 171 # TODO & SKIP Need Pty support
[13:19:17.617](0.000s) not ok 172 # TODO & SKIP Need Pty support
[13:19:17.617](0.000s) not ok 173 # TODO & SKIP Need Pty support
[13:19:17.617](0.000s) not ok 174 # TODO & SKIP Need Pty support
# Running: psql -X -A -F , -P null=_null_ -d sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[13:19:17.653](0.037s) ok 175 - pg_stat_ssl with client certificate: exit code 0
[13:19:17.654](0.000s) ok 176 - pg_stat_ssl with client certificate: no stderr
[13:19:17.654](0.000s) ok 177 - pg_stat_ssl with client certificate: matches
[13:19:17.687](0.033s) ok 178 - certificate authorization fails because of file permissions
[13:19:17.687](0.000s) ok 179 - certificate authorization fails because of file permissions: matches
[13:19:17.729](0.041s) ok 180 - certificate authorization fails with client cert belonging to another user
[13:19:17.729](0.000s) ok 181 - certificate authorization fails with client cert belonging to another user: matches
[13:19:17.772](0.043s) ok 182 - certificate authorization fails with revoked client cert
[13:19:17.772](0.000s) ok 183 - certificate authorization fails with revoked client cert: matches
[13:19:17.773](0.000s) ok 184 - certificate authorization fails with revoked client cert: log does not match
[13:19:17.846](0.073s) ok 185 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[13:19:17.846](0.000s) ok 186 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[13:19:17.847](0.000s) ok 187 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[13:19:17.877](0.030s) ok 188 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[13:19:17.877](0.000s) ok 189 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[13:19:17.877](0.000s) ok 190 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[13:19:17.919](0.042s) ok 191 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[13:19:17.920](0.000s) ok 192 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[13:19:17.920](0.000s) ok 193 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: log matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32625
[13:19:18.357](0.437s) ok 194 - intermediate client certificate is provided by client
[13:19:18.357](0.000s) ok 195 - intermediate client certificate is provided by client: no stderr
[13:19:18.409](0.052s) ok 196 - intermediate client certificate is missing
[13:19:18.410](0.000s) ok 197 - intermediate client certificate is missing: matches
[13:19:18.436](0.026s) ok 198 - logged client certificate Subjects are truncated if they're too long
[13:19:18.436](0.000s) ok 199 - logged client certificate Subjects are truncated if they're too long: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32694
[13:19:18.709](0.274s) ok 200 - intermediate client certificate is untrusted
[13:19:18.710](0.000s) ok 201 - intermediate client certificate is untrusted: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32755
[13:19:18.959](0.249s) ok 202 - certificate authorization fails with revoked client cert with server-side CRL directory
[13:19:18.959](0.000s) ok 203 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[13:19:18.993](0.034s) ok 204 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[13:19:18.994](0.000s) ok 205 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory: matches
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32803
[13:19:19.251](0.258s) not ok 206 - connect with valid stapled ocsp response when sslocspstapling=1
[13:19:19.252](0.000s) 
[13:19:19.252](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at t/001_ssltests.pl line 923.
[13:19:19.252](0.000s) #          got: '2'
#     expected: '0'
[13:19:19.252](0.000s) not ok 207 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[13:19:19.252](0.000s) 
[13:19:19.252](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at t/001_ssltests.pl line 923.
[13:19:19.252](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 51829 failed: SSL error: ocsp callback failure'
#     expected: ''
[13:19:19.350](0.098s) ok 208 - connect without requesting ocsp response when sslocspstapling=0
[13:19:19.350](0.000s) ok 209 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32879
[13:19:19.872](0.522s) ok 210 - failed with a revoked ocsp response when sslocspstapling=1
[13:19:20.020](0.148s) ok 211 - connect without requesting ocsp response when sslocspstapling=0
[13:19:20.021](0.000s) ok 212 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32914
[13:19:20.340](0.320s) ok 213 - failed with a revoked ocsp response when sslocspstapling=1
[13:19:20.436](0.095s) ok 214 - connect without requesting ocsp response when sslocspstapling=0
[13:19:20.436](0.000s) ok 215 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32959
[13:19:20.833](0.397s) ok 216 - failed with an expired ocsp response when sslocspstapling=1
[13:19:20.910](0.077s) ok 217 - connect without requesting ocsp response when sslocspstapling=0
[13:19:20.910](0.000s) ok 218 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 32980
[13:19:21.178](0.269s) not ok 219 - connect with valid stapled ocsp response when sslocspstapling=1
[13:19:21.179](0.000s) 
[13:19:21.179](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at t/001_ssltests.pl line 1001.
[13:19:21.179](0.000s) #          got: '2'
#     expected: '0'
[13:19:21.179](0.000s) not ok 220 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[13:19:21.179](0.000s) 
[13:19:21.179](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at t/001_ssltests.pl line 1001.
[13:19:21.180](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 51829 failed: SSL error: ocsp callback failure'
#     expected: ''
[13:19:21.257](0.077s) ok 221 - connect without requesting ocsp response when sslocspstapling=0
[13:19:21.257](0.000s) ok 222 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 33011
[13:19:21.632](0.375s) ok 223 - failed with a revoked ocsp response when sslocspstapling=1
[13:19:21.713](0.082s) ok 224 - connect without requesting ocsp response when sslocspstapling=0
[13:19:21.713](0.000s) ok 225 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 33063
[13:19:21.989](0.276s) ok 226 - failed with a revoked ocsp response when sslocspstapling=1
[13:19:22.058](0.068s) ok 227 - connect without requesting ocsp response when sslocspstapling=0
[13:19:22.058](0.000s) ok 228 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 33123
[13:19:22.421](0.363s) ok 229 - failed with an expired ocsp response when sslocspstapling=1
[13:19:22.481](0.060s) ok 230 - connect without requesting ocsp response when sslocspstapling=0
[13:19:22.481](0.000s) ok 231 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 33173
[13:19:22.748](0.267s) ok 232 - failed with an expired ocsp response when sslocspstapling=1
[13:19:22.817](0.069s) ok 233 - connect without requesting ocsp response when sslocspstapling=0
[13:19:22.817](0.000s) ok 234 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
# pg_ctl restart failed; logfile:
2024-03-16 13:19:06.564 UTC [30740][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:06.564 UTC [30740][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:06.595 UTC [30752][startup] LOG:  database system was shut down at 2024-03-16 13:17:08 UTC
2024-03-16 13:19:06.607 UTC [30740][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:06.649 UTC [30769][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.655 UTC [30769][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.655 UTC [30769][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.693 UTC [30769][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-16 13:19:06.705 UTC [30769][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.058 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.717 UTC [30795][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.718 UTC [30795][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.718 UTC [30795][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.729 UTC [30795][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-16 13:19:06.731 UTC [30795][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.813 UTC [30818][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.814 UTC [30818][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.814 UTC [30818][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.819 UTC [30818][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-16 13:19:06.825 UTC [30818][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.885 UTC [30828][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.886 UTC [30828][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.886 UTC [30828][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.890 UTC [30828][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-16 13:19:06.892 UTC [30828][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.905 UTC [30834][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.906 UTC [30834][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.906 UTC [30834][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.908 UTC [30834][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-16 13:19:06.910 UTC [30834][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-16 13:19:06.962 UTC [30844][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:06.962 UTC [30844][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:06.962 UTC [30844][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:06.973 UTC [30844][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-16 13:19:07.040 UTC [30844][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.078 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.102 UTC [30870][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.102 UTC [30870][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.102 UTC [30870][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.126 UTC [30870][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-16 13:19:07.236 UTC [30870][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.134 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.410 UTC [30918][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.411 UTC [30918][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.411 UTC [30918][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.422 UTC [30918][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-16 13:19:07.518 UTC [30918][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.108 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.546 UTC [30933][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.546 UTC [30933][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.546 UTC [30933][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.561 UTC [30933][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-16 13:19:07.705 UTC [30933][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.159 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.858 UTC [30988][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.859 UTC [30988][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.859 UTC [30988][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.860 UTC [30988][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-16 13:19:07.915 UTC [30988][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.061 user=postgres database=postgres host=[local]
2024-03-16 13:19:07.982 UTC [31013][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:19:07.986 UTC [31013][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:19:07.986 UTC [31013][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-16 13:19:07.993 UTC [31013][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-16 13:19:08.146 UTC [31013][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.167 user=postgres database=postgres host=[local]
2024-03-16 13:19:08.272 UTC [30740][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:08.272 UTC [30740][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:08.280 UTC [30740][postmaster] LOG:  background worker "logical replication launcher" (PID 30762) exited with exit code 1
2024-03-16 13:19:08.292 UTC [30750][checkpointer] LOG:  shutting down
2024-03-16 13:19:08.293 UTC [30750][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:08.361 UTC [30750][checkpointer] LOG:  checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.069 s, sync=0.001 s, total=0.069 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45479 kB, estimate=45479 kB; lsn=0/4194660, redo lsn=0/4194660
2024-03-16 13:19:08.374 UTC [30740][postmaster] LOG:  database system is shut down
2024-03-16 13:19:08.520 UTC [31078][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:08.520 UTC [31078][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:08.521 UTC [31078][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:08.534 UTC [31089][startup] LOG:  database system was shut down at 2024-03-16 13:19:08 UTC
2024-03-16 13:19:08.540 UTC [31078][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:08.658 UTC [31078][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:08.658 UTC [31078][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:08.667 UTC [31078][postmaster] LOG:  background worker "logical replication launcher" (PID 31098) exited with exit code 1
2024-03-16 13:19:08.667 UTC [31086][checkpointer] LOG:  shutting down
2024-03-16 13:19:08.667 UTC [31086][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:08.743 UTC [31086][checkpointer] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.076 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41946D8, redo lsn=0/41946D8
2024-03-16 13:19:08.826 UTC [31078][postmaster] LOG:  database system is shut down
2024-03-16 13:19:08.965 UTC [31165][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-16 13:19:08.965 UTC [31165][postmaster] LOG:  database system is shut down
2024-03-16 13:19:09.115 UTC [31188][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:09.115 UTC [31188][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:09.115 UTC [31188][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:09.145 UTC [31213][startup] LOG:  database system was shut down at 2024-03-16 13:19:08 UTC
2024-03-16 13:19:09.153 UTC [31188][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:09.240 UTC [31188][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:09.240 UTC [31188][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:09.245 UTC [31188][postmaster] LOG:  background worker "logical replication launcher" (PID 31217) exited with exit code 1
2024-03-16 13:19:09.249 UTC [31211][checkpointer] LOG:  shutting down
2024-03-16 13:19:09.249 UTC [31211][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:09.250 UTC [31211][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194750, redo lsn=0/4194750
2024-03-16 13:19:09.256 UTC [31188][postmaster] LOG:  database system is shut down
2024-03-16 13:19:09.413 UTC [31255][postmaster] FATAL:  could not set SSL protocol version range
2024-03-16 13:19:09.413 UTC [31255][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-16 13:19:09.413 UTC [31255][postmaster] LOG:  database system is shut down
2024-03-16 13:19:09.481 UTC [31282][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:09.481 UTC [31282][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:09.481 UTC [31282][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:09.524 UTC [31290][startup] LOG:  database system was shut down at 2024-03-16 13:19:09 UTC
2024-03-16 13:19:09.532 UTC [31282][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:09.563 UTC [31282][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:09.563 UTC [31282][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:09.568 UTC [31282][postmaster] LOG:  background worker "logical replication launcher" (PID 31302) exited with exit code 1
2024-03-16 13:19:09.572 UTC [31287][checkpointer] LOG:  shutting down
2024-03-16 13:19:09.572 UTC [31287][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:09.573 UTC [31287][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41947C8, redo lsn=0/41947C8
2024-03-16 13:19:09.578 UTC [31282][postmaster] LOG:  database system is shut down
2024-03-16 13:19:09.715 UTC [31320][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:09.715 UTC [31320][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:09.715 UTC [31320][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:09.734 UTC [31333][startup] LOG:  database system was shut down at 2024-03-16 13:19:09 UTC
2024-03-16 13:19:09.748 UTC [31320][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:09.793 UTC [31357][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55378
2024-03-16 13:19:09.794 UTC [31357][client backend] [[unknown]][0/1:0] FATAL:  no pg_hba.conf entry for host "127.0.0.1", user "ssltestuser", database "trustdb", no encryption
2024-03-16 13:19:09.794 UTC [31357][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "localhost", forward lookup not checked.
2024-03-16 13:19:09.838 UTC [31363][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55388
2024-03-16 13:19:09.853 UTC [31363][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:09.853 UTC [31363][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:09.883 UTC [31363][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=invalid sslmode=require$$
2024-03-16 13:19:09.890 UTC [31363][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.053 user=ssltestuser database=trustdb host=localhost port=55388
2024-03-16 13:19:09.918 UTC [31388][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55404
2024-03-16 13:19:09.921 UTC [31388][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:19:09.949 UTC [31395][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55408
2024-03-16 13:19:09.969 UTC [31395][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:19:10.017 UTC [31407][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55416
2024-03-16 13:19:10.035 UTC [31407][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:19:10.064 UTC [31415][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55426
2024-03-16 13:19:10.080 UTC [31415][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:19:10.122 UTC [31429][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55436
2024-03-16 13:19:10.129 UTC [31429][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:19:10.165 UTC [31441][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55450
2024-03-16 13:19:10.192 UTC [31441][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:19:10.246 UTC [31462][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55454
2024-03-16 13:19:10.258 UTC [31462][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.258 UTC [31462][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.269 UTC [31462][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require$$
2024-03-16 13:19:10.275 UTC [31462][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=localhost port=55454
2024-03-16 13:19:10.301 UTC [31476][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55468
2024-03-16 13:19:10.330 UTC [31476][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.330 UTC [31476][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.332 UTC [31476][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca$$
2024-03-16 13:19:10.332 UTC [31476][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=localhost port=55468
2024-03-16 13:19:10.374 UTC [31491][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55472
2024-03-16 13:19:10.399 UTC [31491][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.399 UTC [31491][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.400 UTC [31491][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-full$$
2024-03-16 13:19:10.401 UTC [31491][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=localhost port=55472
2024-03-16 13:19:10.452 UTC [31511][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55474
2024-03-16 13:19:10.468 UTC [31511][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.468 UTC [31511][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.474 UTC [31511][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/both-cas-1.crt sslmode=verify-ca$$
2024-03-16 13:19:10.477 UTC [31511][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=localhost port=55474
2024-03-16 13:19:10.528 UTC [31531][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55488
2024-03-16 13:19:10.559 UTC [31531][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.559 UTC [31531][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.561 UTC [31531][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/both-cas-2.crt sslmode=verify-ca$$
2024-03-16 13:19:10.562 UTC [31531][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=localhost port=55488
2024-03-16 13:19:10.614 UTC [31552][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55492
2024-03-16 13:19:10.621 UTC [31552][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.621 UTC [31552][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.631 UTC [31552][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require sslcertmode=disable$$
2024-03-16 13:19:10.637 UTC [31552][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=localhost port=55492
2024-03-16 13:19:10.667 UTC [31562][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55494
2024-03-16 13:19:10.676 UTC [31562][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.676 UTC [31562][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.681 UTC [31562][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require sslcertmode=allow$$
2024-03-16 13:19:10.685 UTC [31562][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=localhost port=55494
2024-03-16 13:19:10.721 UTC [31575][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55502
2024-03-16 13:19:10.743 UTC [31575][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.743 UTC [31575][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.753 UTC [31575][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=localhost port=55502
2024-03-16 13:19:10.794 UTC [31583][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55510
2024-03-16 13:19:10.812 UTC [31583][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.812 UTC [31583][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.814 UTC [31583][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslcrl=invalid$$
2024-03-16 13:19:10.822 UTC [31583][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=localhost port=55510
2024-03-16 13:19:10.849 UTC [31592][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55514
2024-03-16 13:19:10.859 UTC [31592][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:19:10.922 UTC [31605][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55530
2024-03-16 13:19:10.933 UTC [31605][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:19:10.958 UTC [31615][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55544
2024-03-16 13:19:10.965 UTC [31615][client backend] [[unknown]][11/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:10.965 UTC [31615][client backend] [[unknown]][11/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:10.973 UTC [31615][client backend] [001_ssltests.pl][11/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslcrl=ssl/root+server.crl$$
2024-03-16 13:19:10.980 UTC [31615][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=localhost port=55544
2024-03-16 13:19:11.006 UTC [31624][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55554
2024-03-16 13:19:11.035 UTC [31624][client backend] [[unknown]][12/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:11.035 UTC [31624][client backend] [[unknown]][12/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:11.037 UTC [31624][client backend] [001_ssltests.pl][12/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslcrldir=ssl/root+server-crldir$$
2024-03-16 13:19:11.037 UTC [31624][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=localhost port=55554
2024-03-16 13:19:11.091 UTC [31635][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55566
2024-03-16 13:19:11.098 UTC [31635][client backend] [[unknown]][13/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:11.098 UTC [31635][client backend] [[unknown]][13/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:11.099 UTC [31635][client backend] [001_ssltests.pl][13/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=require host=wronghost.test$$
2024-03-16 13:19:11.105 UTC [31635][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=localhost port=55566
2024-03-16 13:19:11.131 UTC [31645][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55574
2024-03-16 13:19:11.150 UTC [31645][client backend] [[unknown]][14/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:11.150 UTC [31645][client backend] [[unknown]][14/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:11.151 UTC [31645][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-ca host=wronghost.test$$
2024-03-16 13:19:11.153 UTC [31645][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=55574
2024-03-16 13:19:11.171 UTC [31661][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55580
2024-03-16 13:19:11.189 UTC [31320][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:11.189 UTC [31320][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:11.197 UTC [31320][postmaster] LOG:  background worker "logical replication launcher" (PID 31349) exited with exit code 1
2024-03-16 13:19:11.211 UTC [31331][checkpointer] LOG:  shutting down
2024-03-16 13:19:11.212 UTC [31331][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:11.212 UTC [31331][checkpointer] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194840, redo lsn=0/4194840
2024-03-16 13:19:11.218 UTC [31320][postmaster] LOG:  database system is shut down
2024-03-16 13:19:11.335 UTC [31692][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:11.336 UTC [31692][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:11.336 UTC [31692][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:11.350 UTC [31702][startup] LOG:  database system was shut down at 2024-03-16 13:19:11 UTC
2024-03-16 13:19:11.364 UTC [31692][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:11.418 UTC [31722][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55584
2024-03-16 13:19:11.424 UTC [31722][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:11.424 UTC [31722][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:11.467 UTC [31722][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:19:11.473 UTC [31722][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.059 user=ssltestuser database=trustdb host=localhost port=55584
2024-03-16 13:19:11.507 UTC [31740][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55600
2024-03-16 13:19:11.532 UTC [31692][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:11.532 UTC [31692][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:11.550 UTC [31692][postmaster] LOG:  background worker "logical replication launcher" (PID 31707) exited with exit code 1
2024-03-16 13:19:11.550 UTC [31700][checkpointer] LOG:  shutting down
2024-03-16 13:19:11.550 UTC [31700][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:11.551 UTC [31700][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41948B8, redo lsn=0/41948B8
2024-03-16 13:19:11.557 UTC [31692][postmaster] LOG:  database system is shut down
2024-03-16 13:19:11.707 UTC [31771][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:11.708 UTC [31771][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:11.708 UTC [31771][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:11.749 UTC [31783][startup] LOG:  database system was shut down at 2024-03-16 13:19:11 UTC
2024-03-16 13:19:11.757 UTC [31771][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:11.877 UTC [31805][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55610
2024-03-16 13:19:11.892 UTC [31805][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:11.892 UTC [31805][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:11.916 UTC [31805][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:19:11.928 UTC [31805][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.052 user=ssltestuser database=trustdb host=localhost port=55610
2024-03-16 13:19:11.932 UTC [31771][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:11.932 UTC [31771][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:11.937 UTC [31771][postmaster] LOG:  background worker "logical replication launcher" (PID 31788) exited with exit code 1
2024-03-16 13:19:11.949 UTC [31781][checkpointer] LOG:  shutting down
2024-03-16 13:19:11.949 UTC [31781][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:11.950 UTC [31781][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194930, redo lsn=0/4194930
2024-03-16 13:19:11.956 UTC [31771][postmaster] LOG:  database system is shut down
2024-03-16 13:19:12.098 UTC [31839][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:12.098 UTC [31839][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:12.098 UTC [31839][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:12.119 UTC [31861][startup] LOG:  database system was shut down at 2024-03-16 13:19:11 UTC
2024-03-16 13:19:12.138 UTC [31839][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:12.175 UTC [31879][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55616
2024-03-16 13:19:12.184 UTC [31879][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:12.184 UTC [31879][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:12.231 UTC [31879][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns1.alt-name.pg-ssltest.test$$
2024-03-16 13:19:12.238 UTC [31879][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.065 user=ssltestuser database=trustdb host=localhost port=55616
2024-03-16 13:19:12.282 UTC [31893][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55628
2024-03-16 13:19:12.293 UTC [31893][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:12.293 UTC [31893][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:12.298 UTC [31893][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns2.alt-name.pg-ssltest.test$$
2024-03-16 13:19:12.305 UTC [31893][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=55628
2024-03-16 13:19:12.366 UTC [31897][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55638
2024-03-16 13:19:12.375 UTC [31897][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:12.375 UTC [31897][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:12.382 UTC [31897][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=foo.wildcard.pg-ssltest.test$$
2024-03-16 13:19:12.388 UTC [31897][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=localhost port=55638
2024-03-16 13:19:12.424 UTC [31907][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55652
2024-03-16 13:19:12.466 UTC [31911][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55668
2024-03-16 13:19:12.483 UTC [31839][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:12.483 UTC [31839][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:12.490 UTC [31839][postmaster] LOG:  background worker "logical replication launcher" (PID 31873) exited with exit code 1
2024-03-16 13:19:12.491 UTC [31855][checkpointer] LOG:  shutting down
2024-03-16 13:19:12.491 UTC [31855][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:12.491 UTC [31855][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41949A8, redo lsn=0/41949A8
2024-03-16 13:19:12.496 UTC [31839][postmaster] LOG:  database system is shut down
2024-03-16 13:19:12.650 UTC [31921][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:12.650 UTC [31921][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:12.650 UTC [31921][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:12.679 UTC [31936][startup] LOG:  database system was shut down at 2024-03-16 13:19:12 UTC
2024-03-16 13:19:12.687 UTC [31921][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:12.726 UTC [31942][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55678
2024-03-16 13:19:12.755 UTC [31942][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:12.755 UTC [31942][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:12.783 UTC [31942][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=single.alt-name.pg-ssltest.test$$
2024-03-16 13:19:12.788 UTC [31942][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.064 user=ssltestuser database=trustdb host=localhost port=55678
2024-03-16 13:19:12.818 UTC [31952][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55682
2024-03-16 13:19:12.883 UTC [31956][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55694
2024-03-16 13:19:12.936 UTC [31921][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:12.936 UTC [31921][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:12.949 UTC [31921][postmaster] LOG:  background worker "logical replication launcher" (PID 31940) exited with exit code 1
2024-03-16 13:19:12.949 UTC [31934][checkpointer] LOG:  shutting down
2024-03-16 13:19:12.949 UTC [31934][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:12.949 UTC [31934][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194A20, redo lsn=0/4194A20
2024-03-16 13:19:12.955 UTC [31921][postmaster] LOG:  database system is shut down
2024-03-16 13:19:13.102 UTC [31989][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:13.102 UTC [31989][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:13.102 UTC [31989][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:13.140 UTC [31997][startup] LOG:  database system was shut down at 2024-03-16 13:19:12 UTC
2024-03-16 13:19:13.148 UTC [31989][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:13.265 UTC [32022][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55710
2024-03-16 13:19:13.272 UTC [32022][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:13.272 UTC [32022][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:13.301 UTC [32022][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:19:13.306 UTC [32022][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.045 user=ssltestuser database=trustdb host=localhost port=55710
2024-03-16 13:19:13.334 UTC [32033][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55712
2024-03-16 13:19:13.340 UTC [32033][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:13.340 UTC [32033][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:13.354 UTC [32033][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.000.002.001$$
2024-03-16 13:19:13.360 UTC [32033][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=localhost port=55712
2024-03-16 13:19:13.390 UTC [32040][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55724
2024-03-16 13:19:13.431 UTC [32051][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55738
2024-03-16 13:19:13.445 UTC [32051][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:13.445 UTC [32051][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:13.447 UTC [32051][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=2001:DB8::1$$
2024-03-16 13:19:13.449 UTC [32051][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=55738
2024-03-16 13:19:13.482 UTC [32064][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55754
2024-03-16 13:19:13.488 UTC [32064][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:13.488 UTC [32064][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:13.490 UTC [32064][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=2001:db8:0:0:0:0:0:1$$
2024-03-16 13:19:13.492 UTC [32064][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=ssltestuser database=trustdb host=localhost port=55754
2024-03-16 13:19:13.550 UTC [32071][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55766
2024-03-16 13:19:13.556 UTC [32071][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:13.556 UTC [32071][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:13.558 UTC [32071][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=2001:db8::0.0.0.1$$
2024-03-16 13:19:13.561 UTC [32071][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=localhost port=55766
2024-03-16 13:19:13.627 UTC [32080][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55768
2024-03-16 13:19:13.678 UTC [32090][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=55772
2024-03-16 13:19:13.722 UTC [31989][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:13.722 UTC [31989][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:13.742 UTC [31989][postmaster] LOG:  background worker "logical replication launcher" (PID 32003) exited with exit code 1
2024-03-16 13:19:13.743 UTC [31995][checkpointer] LOG:  shutting down
2024-03-16 13:19:13.743 UTC [31995][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:13.744 UTC [31995][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194A98, redo lsn=0/4194A98
2024-03-16 13:19:13.750 UTC [31989][postmaster] LOG:  database system is shut down
2024-03-16 13:19:13.897 UTC [32111][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:13.897 UTC [32111][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:13.897 UTC [32111][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:13.917 UTC [32119][startup] LOG:  database system was shut down at 2024-03-16 13:19:13 UTC
2024-03-16 13:19:13.925 UTC [32111][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:13.969 UTC [32140][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51056
2024-03-16 13:19:13.981 UTC [32140][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:13.981 UTC [32140][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:14.004 UTC [32140][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns1.alt-name.pg-ssltest.test$$
2024-03-16 13:19:14.007 UTC [32140][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.038 user=ssltestuser database=trustdb host=localhost port=51056
2024-03-16 13:19:14.050 UTC [32154][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51058
2024-03-16 13:19:14.056 UTC [32154][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:14.056 UTC [32154][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:14.058 UTC [32154][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns2.alt-name.pg-ssltest.test$$
2024-03-16 13:19:14.064 UTC [32154][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=localhost port=51058
2024-03-16 13:19:14.115 UTC [32163][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51072
2024-03-16 13:19:14.165 UTC [32111][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:14.165 UTC [32111][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:14.172 UTC [32111][postmaster] LOG:  background worker "logical replication launcher" (PID 32131) exited with exit code 1
2024-03-16 13:19:14.174 UTC [32117][checkpointer] LOG:  shutting down
2024-03-16 13:19:14.174 UTC [32117][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:14.175 UTC [32117][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194B10, redo lsn=0/4194B10
2024-03-16 13:19:14.181 UTC [32111][postmaster] LOG:  database system is shut down
2024-03-16 13:19:14.346 UTC [32180][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:14.346 UTC [32180][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:14.346 UTC [32180][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:14.362 UTC [32190][startup] LOG:  database system was shut down at 2024-03-16 13:19:14 UTC
2024-03-16 13:19:14.371 UTC [32180][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:14.442 UTC [32207][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51074
2024-03-16 13:19:14.450 UTC [32207][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:14.450 UTC [32207][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:14.485 UTC [32207][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=common-name.pg-ssltest.test$$
2024-03-16 13:19:14.491 UTC [32207][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.049 user=ssltestuser database=trustdb host=localhost port=51074
2024-03-16 13:19:14.518 UTC [32221][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51088
2024-03-16 13:19:14.532 UTC [32221][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:14.532 UTC [32221][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:14.533 UTC [32221][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:19:14.542 UTC [32221][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=localhost port=51088
2024-03-16 13:19:14.566 UTC [32225][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51102
2024-03-16 13:19:14.574 UTC [32225][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:14.574 UTC [32225][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:14.576 UTC [32225][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=2001:db8::1$$
2024-03-16 13:19:14.583 UTC [32225][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.017 user=ssltestuser database=trustdb host=localhost port=51102
2024-03-16 13:19:14.597 UTC [32180][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:14.597 UTC [32180][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:14.603 UTC [32180][postmaster] LOG:  background worker "logical replication launcher" (PID 32196) exited with exit code 1
2024-03-16 13:19:14.604 UTC [32187][checkpointer] LOG:  shutting down
2024-03-16 13:19:14.604 UTC [32187][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:14.605 UTC [32187][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194B88, redo lsn=0/4194B88
2024-03-16 13:19:14.610 UTC [32180][postmaster] LOG:  database system is shut down
2024-03-16 13:19:14.751 UTC [32261][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:14.751 UTC [32261][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:14.751 UTC [32261][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:14.777 UTC [32280][startup] LOG:  database system was shut down at 2024-03-16 13:19:14 UTC
2024-03-16 13:19:14.785 UTC [32261][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:14.835 UTC [32293][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51116
2024-03-16 13:19:14.850 UTC [32293][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:14.850 UTC [32293][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:14.862 UTC [32293][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.2$$
2024-03-16 13:19:14.868 UTC [32293][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.038 user=ssltestuser database=trustdb host=localhost port=51116
2024-03-16 13:19:14.887 UTC [32298][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51122
2024-03-16 13:19:14.900 UTC [32298][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:14.900 UTC [32298][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:14.902 UTC [32298][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=2001:db8::1$$
2024-03-16 13:19:14.906 UTC [32298][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=localhost port=51122
2024-03-16 13:19:15.264 UTC [32321][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51130
2024-03-16 13:19:15.284 UTC [32261][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:15.284 UTC [32261][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:15.290 UTC [32261][postmaster] LOG:  background worker "logical replication launcher" (PID 32283) exited with exit code 1
2024-03-16 13:19:15.292 UTC [32274][checkpointer] LOG:  shutting down
2024-03-16 13:19:15.292 UTC [32274][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:15.293 UTC [32274][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194C00, redo lsn=0/4194C00
2024-03-16 13:19:15.300 UTC [32261][postmaster] LOG:  database system is shut down
2024-03-16 13:19:15.430 UTC [32331][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:15.430 UTC [32331][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:15.431 UTC [32331][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:15.450 UTC [32338][startup] LOG:  database system was shut down at 2024-03-16 13:19:15 UTC
2024-03-16 13:19:15.458 UTC [32331][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:15.505 UTC [32343][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51144
2024-03-16 13:19:15.512 UTC [32343][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:15.512 UTC [32343][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:15.526 UTC [32343][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:19:15.531 UTC [32343][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=localhost port=51144
2024-03-16 13:19:15.551 UTC [32347][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51156
2024-03-16 13:19:15.557 UTC [32347][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:15.557 UTC [32347][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:15.559 UTC [32347][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns1.alt-name.pg-ssltest.test$$
2024-03-16 13:19:15.562 UTC [32347][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=51156
2024-03-16 13:19:15.588 UTC [32350][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51170
2024-03-16 13:19:15.594 UTC [32350][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:15.594 UTC [32350][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:15.596 UTC [32350][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns2.alt-name.pg-ssltest.test$$
2024-03-16 13:19:15.599 UTC [32350][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=51170
2024-03-16 13:19:15.613 UTC [32331][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:15.613 UTC [32331][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:15.622 UTC [32331][postmaster] LOG:  background worker "logical replication launcher" (PID 32341) exited with exit code 1
2024-03-16 13:19:15.622 UTC [32336][checkpointer] LOG:  shutting down
2024-03-16 13:19:15.623 UTC [32336][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:15.623 UTC [32336][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194C78, redo lsn=0/4194C78
2024-03-16 13:19:15.628 UTC [32331][postmaster] LOG:  database system is shut down
2024-03-16 13:19:15.783 UTC [32363][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:15.783 UTC [32363][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:15.783 UTC [32363][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:15.801 UTC [32366][startup] LOG:  database system was shut down at 2024-03-16 13:19:15 UTC
2024-03-16 13:19:15.809 UTC [32363][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:15.839 UTC [32372][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51172
2024-03-16 13:19:15.846 UTC [32372][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:15.846 UTC [32372][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:15.870 UTC [32372][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-ca host=common-name.pg-ssltest.test$$
2024-03-16 13:19:15.873 UTC [32372][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.039 user=ssltestuser database=trustdb host=localhost port=51172
2024-03-16 13:19:15.910 UTC [32380][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51186
2024-03-16 13:19:15.926 UTC [32363][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:15.926 UTC [32363][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:15.941 UTC [32363][postmaster] LOG:  background worker "logical replication launcher" (PID 32369) exited with exit code 1
2024-03-16 13:19:15.941 UTC [32364][checkpointer] LOG:  shutting down
2024-03-16 13:19:15.941 UTC [32364][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:15.942 UTC [32364][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194CF0, redo lsn=0/4194CF0
2024-03-16 13:19:15.947 UTC [32363][postmaster] LOG:  database system is shut down
2024-03-16 13:19:16.060 UTC [32394][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:16.060 UTC [32394][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:16.060 UTC [32394][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:16.085 UTC [32400][startup] LOG:  database system was shut down at 2024-03-16 13:19:15 UTC
2024-03-16 13:19:16.094 UTC [32394][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:16.158 UTC [32407][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51196
2024-03-16 13:19:16.162 UTC [32407][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:19:16.233 UTC [32415][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51208
2024-03-16 13:19:16.245 UTC [32415][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:16.245 UTC [32415][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:16.285 UTC [32415][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=system hostaddr=127.0.0.1 sslmode=verify-full host=common-name.pg-ssltest.test$$
2024-03-16 13:19:16.288 UTC [32415][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.063 user=ssltestuser database=trustdb host=localhost port=51208
2024-03-16 13:19:16.320 UTC [32420][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51212
2024-03-16 13:19:16.348 UTC [32394][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:16.348 UTC [32394][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:16.356 UTC [32394][postmaster] LOG:  background worker "logical replication launcher" (PID 32404) exited with exit code 1
2024-03-16 13:19:16.356 UTC [32398][checkpointer] LOG:  shutting down
2024-03-16 13:19:16.356 UTC [32398][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:16.357 UTC [32398][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194D68, redo lsn=0/4194D68
2024-03-16 13:19:16.364 UTC [32394][postmaster] LOG:  database system is shut down
2024-03-16 13:19:16.509 UTC [32431][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:16.509 UTC [32431][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:16.509 UTC [32431][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:16.533 UTC [32438][startup] LOG:  database system was shut down at 2024-03-16 13:19:16 UTC
2024-03-16 13:19:16.541 UTC [32431][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:16.592 UTC [32443][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51214
2024-03-16 13:19:16.609 UTC [32443][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:16.609 UTC [32443][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:16.649 UTC [32443][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca$$
2024-03-16 13:19:16.657 UTC [32443][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.068 user=ssltestuser database=trustdb host=localhost port=51214
2024-03-16 13:19:16.681 UTC [32447][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51222
2024-03-16 13:19:16.696 UTC [32447][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-16 13:19:16.762 UTC [32450][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51238
2024-03-16 13:19:16.771 UTC [32450][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-16 13:19:16.790 UTC [32453][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51252
2024-03-16 13:19:16.797 UTC [32453][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:16.797 UTC [32453][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:16.798 UTC [32453][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-16 13:19:16.805 UTC [32453][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.015 user=ssltestuser database=trustdb host=localhost port=51252
2024-03-16 13:19:16.821 UTC [32455][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51256
2024-03-16 13:19:16.827 UTC [32455][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:16.827 UTC [32455][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256)
2024-03-16 13:19:16.828 UTC [32455][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require ssl_min_protocol_version=TLSv1.2 ssl_max_protocol_version=TLSv1.2$$
2024-03-16 13:19:16.834 UTC [32455][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=51256
2024-03-16 13:19:16.927 UTC [32469][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51260
2024-03-16 13:19:16.933 UTC [32469][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-03-16 13:19:16.986 UTC [32475][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51266
2024-03-16 13:19:16.993 UTC [32475][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:16.993 UTC [32475][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.009 UTC [32475][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client.key$$
2024-03-16 13:19:17.010 UTC [32475][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb host=localhost port=51266
2024-03-16 13:19:17.072 UTC [32485][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51282
2024-03-16 13:19:17.081 UTC [32485][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:17.081 UTC [32485][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.098 UTC [32485][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client-der.key$$
2024-03-16 13:19:17.102 UTC [32485][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=certdb host=localhost port=51282
2024-03-16 13:19:17.141 UTC [32501][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51298
2024-03-16 13:19:17.149 UTC [32501][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:17.149 UTC [32501][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.153 UTC [32501][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-03-16 13:19:17.154 UTC [32501][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=localhost port=51298
2024-03-16 13:19:17.183 UTC [32513][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51314
2024-03-16 13:19:17.192 UTC [32513][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:17.192 UTC [32513][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.194 UTC [32513][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-03-16 13:19:17.195 UTC [32513][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=ssltestuser database=certdb host=localhost port=51314
2024-03-16 13:19:17.240 UTC [32520][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51328
2024-03-16 13:19:17.250 UTC [32520][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:17.250 UTC [32520][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.252 UTC [32520][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcertmode=require sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client.key$$
2024-03-16 13:19:17.255 UTC [32520][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.017 user=ssltestuser database=certdb host=localhost port=51328
2024-03-16 13:19:17.294 UTC [32529][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51332
2024-03-16 13:19:17.319 UTC [32529][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:17.319 UTC [32529][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.320 UTC [32529][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcertmode=allow sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client.key$$
2024-03-16 13:19:17.321 UTC [32529][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=certdb host=localhost port=51332
2024-03-16 13:19:17.369 UTC [32535][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51336
2024-03-16 13:19:17.389 UTC [32535][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-03-16 13:19:17.419 UTC [32539][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51346
2024-03-16 13:19:17.445 UTC [32539][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:19:17.481 UTC [32547][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51358
2024-03-16 13:19:17.489 UTC [32547][client backend] [[unknown]][11/1:0] LOG:  connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:8)
2024-03-16 13:19:17.489 UTC [32547][client backend] [[unknown]][11/1:0] LOG:  connection authorized: user=ssltestuser database=certdb_dn application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.500 UTC [32547][client backend] [001_ssltests.pl][11/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost dbname=certdb_dn user=ssltestuser sslcert=ssl/client-dn.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client-dn.key$$
2024-03-16 13:19:17.507 UTC [32547][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=certdb_dn host=localhost port=51358
2024-03-16 13:19:17.523 UTC [32553][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51366
2024-03-16 13:19:17.531 UTC [32553][client backend] [[unknown]][12/1:0] LOG:  connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:9)
2024-03-16 13:19:17.531 UTC [32553][client backend] [[unknown]][12/1:0] LOG:  connection authorized: user=ssltestuser database=certdb_dn_re application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.550 UTC [32553][client backend] [001_ssltests.pl][12/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost dbname=certdb_dn_re user=ssltestuser sslcert=ssl/client-dn.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client-dn.key$$
2024-03-16 13:19:17.554 UTC [32553][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb_dn_re host=localhost port=51366
2024-03-16 13:19:17.586 UTC [32564][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51370
2024-03-16 13:19:17.598 UTC [32564][client backend] [[unknown]][13/1:0] LOG:  connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:10)
2024-03-16 13:19:17.598 UTC [32564][client backend] [[unknown]][13/1:0] LOG:  connection authorized: user=ssltestuser database=certdb_cn application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.611 UTC [32564][client backend] [001_ssltests.pl][13/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost dbname=certdb_cn user=ssltestuser sslcert=ssl/client-dn.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client-dn.key$$
2024-03-16 13:19:17.618 UTC [32564][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=certdb_cn host=localhost port=51370
2024-03-16 13:19:17.638 UTC [32571][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51372
2024-03-16 13:19:17.646 UTC [32571][client backend] [[unknown]][14/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:17.646 UTC [32571][client backend] [[unknown]][14/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.647 UTC [32571][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-16 13:19:17.655 UTC [32571][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=certdb host=localhost port=51372
2024-03-16 13:19:17.677 UTC [32577][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51376
2024-03-16 13:19:17.682 UTC [32577][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:19:17.708 UTC [32581][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51392
2024-03-16 13:19:17.720 UTC [32581][client backend] [[unknown]][15/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:17.720 UTC [32581][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-16 13:19:17.720 UTC [32581][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-03-16 13:19:17.720 UTC [32581][client backend] [[unknown]][15/1:0] DETAIL:  Connection matched file "/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf" line 7: "hostssl certdb          all             127.0.0.1/32            cert"
2024-03-16 13:19:17.757 UTC [32593][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51400
2024-03-16 13:19:17.764 UTC [32593][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:19:17.764 UTC [32593][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: certificate revoked.
	Failed certificate data (unverified): subject "/CN=ssltestuser", serial number 2315702411956921346, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:19:17.808 UTC [32603][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51404
2024-03-16 13:19:17.823 UTC [32603][client backend] [[unknown]][16/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:4)
2024-03-16 13:19:17.823 UTC [32603][client backend] [[unknown]][16/1:0] LOG:  connection authorized: user=ssltestuser database=verifydb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.842 UTC [32603][client backend] [001_ssltests.pl][16/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=verifydb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client.key$$
2024-03-16 13:19:17.848 UTC [32603][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.041 user=ssltestuser database=verifydb host=localhost port=51404
2024-03-16 13:19:17.865 UTC [32608][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51416
2024-03-16 13:19:17.873 UTC [32608][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-16 13:19:17.873 UTC [32608][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-03-16 13:19:17.873 UTC [32608][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-03-16 13:19:17.873 UTC [32608][client backend] [[unknown]][17/1:0] DETAIL:  Connection matched file "/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf" line 5: "hostssl verifydb        anotheruser     127.0.0.1/32            trust        clientcert=verify-full"
2024-03-16 13:19:17.905 UTC [32612][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51426
2024-03-16 13:19:17.914 UTC [32612][client backend] [[unknown]][18/1:0] LOG:  connection authenticated: user="yetanotheruser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:6)
2024-03-16 13:19:17.914 UTC [32612][client backend] [[unknown]][18/1:0] LOG:  connection authorized: user=yetanotheruser database=verifydb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:17.915 UTC [32612][client backend] [001_ssltests.pl][18/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=verifydb hostaddr=127.0.0.1 host=localhost user=yetanotheruser sslcert=ssl/client.crt  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client.key$$
2024-03-16 13:19:17.924 UTC [32612][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=yetanotheruser database=verifydb host=localhost port=51426
2024-03-16 13:19:17.944 UTC [32431][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:17.944 UTC [32431][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:17.952 UTC [32431][postmaster] LOG:  background worker "logical replication launcher" (PID 32441) exited with exit code 1
2024-03-16 13:19:17.956 UTC [32436][checkpointer] LOG:  shutting down
2024-03-16 13:19:17.956 UTC [32436][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:17.957 UTC [32436][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194DE0, redo lsn=0/4194DE0
2024-03-16 13:19:17.963 UTC [32431][postmaster] LOG:  database system is shut down
2024-03-16 13:19:18.137 UTC [32625][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:18.137 UTC [32625][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:18.138 UTC [32625][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:18.154 UTC [32638][startup] LOG:  database system was shut down at 2024-03-16 13:19:17 UTC
2024-03-16 13:19:18.163 UTC [32625][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:18.307 UTC [32657][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51434
2024-03-16 13:19:18.327 UTC [32657][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:19:18.327 UTC [32657][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:18.352 UTC [32657][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=certdb  sslkey=/tmp/cirrus-ci-build/src/test/ssl/tmp_check/tmp_test_ALcW/client.key sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 host=localhost sslmode=require sslcert=ssl/client+client_ca.crt$$
2024-03-16 13:19:18.359 UTC [32657][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.062 user=ssltestuser database=certdb host=localhost port=51434
2024-03-16 13:19:18.387 UTC [32667][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51440
2024-03-16 13:19:18.400 UTC [32667][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:19:18.400 UTC [32667][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: unable to get local issuer certificate.
	Failed certificate data (unverified): subject "/CN=ssltestuser", serial number 2315702411956921344, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:19:18.423 UTC [32676][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51444
2024-03-16 13:19:18.435 UTC [32676][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:19:18.435 UTC [32676][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: unable to get local issuer certificate.
	Failed certificate data (unverified): subject ".../CN=ssl-123456789012345678901234567890123456789012345678901234567890", serial number 2315702411956921348, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:19:18.457 UTC [32625][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:18.457 UTC [32625][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:18.469 UTC [32625][postmaster] LOG:  background worker "logical replication launcher" (PID 32641) exited with exit code 1
2024-03-16 13:19:18.469 UTC [32636][checkpointer] LOG:  shutting down
2024-03-16 13:19:18.469 UTC [32636][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:18.470 UTC [32636][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194E58, redo lsn=0/4194E58
2024-03-16 13:19:18.479 UTC [32625][postmaster] LOG:  database system is shut down
2024-03-16 13:19:18.619 UTC [32694][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:18.619 UTC [32694][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:18.620 UTC [32694][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:18.628 UTC [32713][startup] LOG:  database system was shut down at 2024-03-16 13:19:18 UTC
2024-03-16 13:19:18.638 UTC [32694][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:18.685 UTC [32726][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51452
2024-03-16 13:19:18.702 UTC [32726][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:19:18.702 UTC [32726][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 1: unable to get local issuer certificate.
	Failed certificate data (unverified): subject "/CN=Test CA for PostgreSQL SSL regression test client certs", serial number 2315702411956921089, issuer "/CN=Test root CA for PostgreSQL SSL regression test suite".
2024-03-16 13:19:18.713 UTC [32694][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:18.713 UTC [32694][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:18.725 UTC [32694][postmaster] LOG:  background worker "logical replication launcher" (PID 32718) exited with exit code 1
2024-03-16 13:19:18.726 UTC [32711][checkpointer] LOG:  shutting down
2024-03-16 13:19:18.726 UTC [32711][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:18.727 UTC [32711][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194ED0, redo lsn=0/4194ED0
2024-03-16 13:19:18.733 UTC [32694][postmaster] LOG:  database system is shut down
2024-03-16 13:19:18.867 UTC [32755][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:18.867 UTC [32755][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:18.868 UTC [32755][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:18.895 UTC [32763][startup] LOG:  database system was shut down at 2024-03-16 13:19:18 UTC
2024-03-16 13:19:18.903 UTC [32755][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:18.949 UTC [32773][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51468
2024-03-16 13:19:18.955 UTC [32773][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:19:18.955 UTC [32773][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: certificate revoked.
	Failed certificate data (unverified): subject "/CN=ssltestuser", serial number 2315702411956921346, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:19:18.978 UTC [32781][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51474
2024-03-16 13:19:18.994 UTC [32781][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:19:18.994 UTC [32781][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: certificate revoked.
	Failed certificate data (unverified): subject "/CN=\xce\x9f\xce\xb4\xcf\x85\xcf\x83\xcf\x83\xce\xad\xce\xb1\xcf\x82", serial number 2315702411956921349, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:19:19.002 UTC [32755][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:19.002 UTC [32755][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:19.008 UTC [32755][postmaster] LOG:  background worker "logical replication launcher" (PID 32766) exited with exit code 1
2024-03-16 13:19:19.008 UTC [32761][checkpointer] LOG:  shutting down
2024-03-16 13:19:19.008 UTC [32761][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:19.009 UTC [32761][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194F48, redo lsn=0/4194F48
2024-03-16 13:19:19.016 UTC [32755][postmaster] LOG:  database system is shut down
2024-03-16 13:19:19.154 UTC [32803][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:19.154 UTC [32803][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:19.154 UTC [32803][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:19.180 UTC [32816][startup] LOG:  database system was shut down at 2024-03-16 13:19:19 UTC
2024-03-16 13:19:19.196 UTC [32803][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:19.242 UTC [32828][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51490
2024-03-16 13:19:19.245 UTC [32828][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:19.245 UTC [32828][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:19.257 UTC [32828][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert internal error
2024-03-16 13:19:19.267 UTC [32836][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51496
2024-03-16 13:19:19.273 UTC [32836][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:19.274 UTC [32836][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:19.345 UTC [32836][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:19.352 UTC [32836][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.085 user=ssltestuser database=trustdb host=localhost port=51496
2024-03-16 13:19:19.368 UTC [32803][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:19.368 UTC [32803][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:19.380 UTC [32803][postmaster] LOG:  background worker "logical replication launcher" (PID 32822) exited with exit code 1
2024-03-16 13:19:19.386 UTC [32811][checkpointer] LOG:  shutting down
2024-03-16 13:19:19.387 UTC [32811][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:19.387 UTC [32811][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4194FC0, redo lsn=0/4194FC0
2024-03-16 13:19:19.393 UTC [32803][postmaster] LOG:  database system is shut down
2024-03-16 13:19:19.669 UTC [32879][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:19.669 UTC [32879][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:19.669 UTC [32879][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:19.714 UTC [32888][startup] LOG:  database system was shut down at 2024-03-16 13:19:19 UTC
2024-03-16 13:19:19.739 UTC [32879][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:19.848 UTC [32898][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51498
2024-03-16 13:19:19.855 UTC [32898][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:19.855 UTC [32898][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-16 13:19:19.957 UTC [32904][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51504
2024-03-16 13:19:19.978 UTC [32904][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:19.978 UTC [32904][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:20.016 UTC [32904][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:20.029 UTC [32904][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.072 user=ssltestuser database=trustdb host=localhost port=51504
2024-03-16 13:19:20.040 UTC [32879][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:20.040 UTC [32879][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:20.046 UTC [32879][postmaster] LOG:  background worker "logical replication launcher" (PID 32894) exited with exit code 1
2024-03-16 13:19:20.048 UTC [32886][checkpointer] LOG:  shutting down
2024-03-16 13:19:20.048 UTC [32886][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:20.048 UTC [32886][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4195038, redo lsn=0/4195038
2024-03-16 13:19:20.054 UTC [32879][postmaster] LOG:  database system is shut down
2024-03-16 13:19:20.158 UTC [32914][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:20.159 UTC [32914][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:20.159 UTC [32914][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:20.185 UTC [32925][startup] LOG:  database system was shut down at 2024-03-16 13:19:20 UTC
2024-03-16 13:19:20.194 UTC [32914][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:20.325 UTC [32942][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51516
2024-03-16 13:19:20.331 UTC [32942][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:20.332 UTC [32942][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-16 13:19:20.379 UTC [32945][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51524
2024-03-16 13:19:20.401 UTC [32945][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:20.401 UTC [32945][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:20.432 UTC [32945][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:20.437 UTC [32945][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.060 user=ssltestuser database=trustdb host=localhost port=51524
2024-03-16 13:19:20.453 UTC [32914][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:20.453 UTC [32914][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:20.460 UTC [32914][postmaster] LOG:  background worker "logical replication launcher" (PID 32929) exited with exit code 1
2024-03-16 13:19:20.460 UTC [32922][checkpointer] LOG:  shutting down
2024-03-16 13:19:20.460 UTC [32922][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:20.461 UTC [32922][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41950B0, redo lsn=0/41950B0
2024-03-16 13:19:20.467 UTC [32914][postmaster] LOG:  database system is shut down
2024-03-16 13:19:20.620 UTC [32959][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:20.620 UTC [32959][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:20.620 UTC [32959][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:20.650 UTC [32964][startup] LOG:  database system was shut down at 2024-03-16 13:19:20 UTC
2024-03-16 13:19:20.669 UTC [32959][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:20.814 UTC [32970][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51534
2024-03-16 13:19:20.820 UTC [32970][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:20.820 UTC [32970][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-16 13:19:20.874 UTC [32972][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51538
2024-03-16 13:19:20.880 UTC [32972][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:20.880 UTC [32972][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:20.905 UTC [32972][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:20.906 UTC [32972][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.044 user=ssltestuser database=trustdb host=localhost port=51538
2024-03-16 13:19:20.918 UTC [32959][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:20.918 UTC [32959][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:20.926 UTC [32959][postmaster] LOG:  background worker "logical replication launcher" (PID 32967) exited with exit code 1
2024-03-16 13:19:20.926 UTC [32962][checkpointer] LOG:  shutting down
2024-03-16 13:19:20.926 UTC [32962][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:20.927 UTC [32962][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4195128, redo lsn=0/4195128
2024-03-16 13:19:20.932 UTC [32959][postmaster] LOG:  database system is shut down
2024-03-16 13:19:21.068 UTC [32980][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:21.068 UTC [32980][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:21.068 UTC [32980][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:21.090 UTC [32985][startup] LOG:  database system was shut down at 2024-03-16 13:19:20 UTC
2024-03-16 13:19:21.098 UTC [32980][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:21.161 UTC [32993][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51540
2024-03-16 13:19:21.164 UTC [32993][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:21.170 UTC [32993][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:21.182 UTC [32993][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:19:21.219 UTC [32998][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51552
2024-03-16 13:19:21.234 UTC [32998][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:21.234 UTC [32998][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:21.252 UTC [32998][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:21.254 UTC [32998][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.037 user=ssltestuser database=trustdb host=localhost port=51552
2024-03-16 13:19:21.268 UTC [32980][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:21.268 UTC [32980][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:21.273 UTC [32980][postmaster] LOG:  background worker "logical replication launcher" (PID 32988) exited with exit code 1
2024-03-16 13:19:21.276 UTC [32983][checkpointer] LOG:  shutting down
2024-03-16 13:19:21.276 UTC [32983][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:21.277 UTC [32983][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/41951A0, redo lsn=0/41951A0
2024-03-16 13:19:21.283 UTC [32980][postmaster] LOG:  database system is shut down
2024-03-16 13:19:21.440 UTC [33011][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:21.440 UTC [33011][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:21.440 UTC [33011][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:21.472 UTC [33022][startup] LOG:  database system was shut down at 2024-03-16 13:19:21 UTC
2024-03-16 13:19:21.479 UTC [33011][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:21.614 UTC [33041][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51558
2024-03-16 13:19:21.617 UTC [33041][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:21.617 UTC [33041][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-16 13:19:21.668 UTC [33043][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51562
2024-03-16 13:19:21.691 UTC [33043][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:21.691 UTC [33043][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:21.709 UTC [33043][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:21.714 UTC [33043][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.053 user=ssltestuser database=trustdb host=localhost port=51562
2024-03-16 13:19:21.730 UTC [33011][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:21.730 UTC [33011][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:21.735 UTC [33011][postmaster] LOG:  background worker "logical replication launcher" (PID 33029) exited with exit code 1
2024-03-16 13:19:21.739 UTC [33020][checkpointer] LOG:  shutting down
2024-03-16 13:19:21.739 UTC [33020][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:21.740 UTC [33020][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4195218, redo lsn=0/4195218
2024-03-16 13:19:21.745 UTC [33011][postmaster] LOG:  database system is shut down
2024-03-16 13:19:21.877 UTC [33063][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:21.877 UTC [33063][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:21.878 UTC [33063][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:21.900 UTC [33071][startup] LOG:  database system was shut down at 2024-03-16 13:19:21 UTC
2024-03-16 13:19:21.908 UTC [33063][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:21.975 UTC [33083][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51570
2024-03-16 13:19:21.982 UTC [33083][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:21.982 UTC [33083][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-16 13:19:22.017 UTC [33091][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51584
2024-03-16 13:19:22.024 UTC [33091][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:22.024 UTC [33091][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:22.053 UTC [33091][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:22.059 UTC [33091][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.044 user=ssltestuser database=trustdb host=localhost port=51584
2024-03-16 13:19:22.076 UTC [33063][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:22.076 UTC [33063][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:22.083 UTC [33063][postmaster] LOG:  background worker "logical replication launcher" (PID 33076) exited with exit code 1
2024-03-16 13:19:22.084 UTC [33069][checkpointer] LOG:  shutting down
2024-03-16 13:19:22.084 UTC [33069][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:22.085 UTC [33069][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4195290, redo lsn=0/4195290
2024-03-16 13:19:22.091 UTC [33063][postmaster] LOG:  database system is shut down
2024-03-16 13:19:22.247 UTC [33123][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:22.247 UTC [33123][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:22.248 UTC [33123][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:22.271 UTC [33129][startup] LOG:  database system was shut down at 2024-03-16 13:19:22 UTC
2024-03-16 13:19:22.286 UTC [33123][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:22.401 UTC [33151][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51590
2024-03-16 13:19:22.409 UTC [33151][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:22.409 UTC [33151][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-16 13:19:22.446 UTC [33158][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51596
2024-03-16 13:19:22.455 UTC [33158][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:22.455 UTC [33158][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:22.477 UTC [33158][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:22.482 UTC [33158][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.045 user=ssltestuser database=trustdb host=localhost port=51596
2024-03-16 13:19:22.492 UTC [33123][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:22.492 UTC [33123][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:22.496 UTC [33123][postmaster] LOG:  background worker "logical replication launcher" (PID 33132) exited with exit code 1
2024-03-16 13:19:22.498 UTC [33126][checkpointer] LOG:  shutting down
2024-03-16 13:19:22.498 UTC [33126][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:22.499 UTC [33126][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4195308, redo lsn=0/4195308
2024-03-16 13:19:22.505 UTC [33123][postmaster] LOG:  database system is shut down
2024-03-16 13:19:22.637 UTC [33173][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-03-16 13:19:22.637 UTC [33173][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51829
2024-03-16 13:19:22.638 UTC [33173][postmaster] LOG:  listening on Unix socket "/tmp/aXxR29YrxK/.s.PGSQL.51829"
2024-03-16 13:19:22.648 UTC [33182][startup] LOG:  database system was shut down at 2024-03-16 13:19:22 UTC
2024-03-16 13:19:22.656 UTC [33173][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:19:22.738 UTC [33198][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51604
2024-03-16 13:19:22.740 UTC [33198][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:19:22.740 UTC [33198][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-16 13:19:22.772 UTC [33205][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=51608
2024-03-16 13:19:22.800 UTC [33205][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:19:22.800 UTC [33205][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:19:22.813 UTC [33205][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:19:22.816 UTC [33205][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.045 user=ssltestuser database=trustdb host=localhost port=51608
2024-03-16 13:19:22.835 UTC [33173][postmaster] LOG:  received fast shutdown request
2024-03-16 13:19:22.835 UTC [33173][postmaster] LOG:  aborting any active transactions
2024-03-16 13:19:22.840 UTC [33173][postmaster] LOG:  background worker "logical replication launcher" (PID 33186) exited with exit code 1
2024-03-16 13:19:22.847 UTC [33180][checkpointer] LOG:  shutting down
2024-03-16 13:19:22.847 UTC [33180][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:19:22.848 UTC [33180][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4195380, redo lsn=0/4195380
2024-03-16 13:19:22.854 UTC [33173][postmaster] LOG:  database system is shut down
2024-03-16 13:19:23.003 UTC [33221][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-03-16 13:19:23.003 UTC [33221][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:19:23.050](0.232s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"