[14:11:43.437](0.032s) # setting up data directory
# Checking port 58262
# Found port 58262
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=58262 host=/tmp/AvuYQVWY2c
Log file: /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log
[14:11:43.443](0.006s) # 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 35306
[14:11:43.737](0.294s) 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 35568
[14:11:44.919](1.181s) # 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-18 14:11:43.632 UTC [35306][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-18 14:11:43.632 UTC [35306][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:43.641 UTC [35312][startup] LOG:  database system was shut down at 2024-03-18 14:09:16 UTC
2024-03-18 14:11:43.663 UTC [35306][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:43.722 UTC [35334][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.723 UTC [35334][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-18 14:11:43.723 UTC [35334][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.735 UTC [35334][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-18 14:11:43.739 UTC [35334][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.751 UTC [35341][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.752 UTC [35341][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-18 14:11:43.752 UTC [35341][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.753 UTC [35341][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-18 14:11:43.755 UTC [35341][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.799 UTC [35358][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.800 UTC [35358][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-18 14:11:43.800 UTC [35358][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.806 UTC [35358][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-18 14:11:43.808 UTC [35358][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.848 UTC [35369][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.848 UTC [35369][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-18 14:11:43.848 UTC [35369][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.852 UTC [35369][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-18 14:11:43.852 UTC [35369][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.899 UTC [35386][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.900 UTC [35386][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-18 14:11:43.900 UTC [35386][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.904 UTC [35386][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-18 14:11:43.912 UTC [35386][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.937 UTC [35397][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.937 UTC [35397][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-18 14:11:43.937 UTC [35397][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.939 UTC [35397][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-18 14:11:43.984 UTC [35397][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.070 UTC [35437][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.071 UTC [35437][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-18 14:11:44.071 UTC [35437][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.074 UTC [35437][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-18 14:11:44.142 UTC [35437][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.073 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.193 UTC [35453][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.194 UTC [35453][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-18 14:11:44.194 UTC [35453][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.196 UTC [35453][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-18 14:11:44.245 UTC [35453][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.051 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.315 UTC [35484][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.316 UTC [35484][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-18 14:11:44.316 UTC [35484][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.317 UTC [35484][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-18 14:11:44.362 UTC [35484][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.450 UTC [35511][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.451 UTC [35511][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-18 14:11:44.451 UTC [35511][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.452 UTC [35511][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-18 14:11:44.509 UTC [35511][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.059 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.596 UTC [35536][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.597 UTC [35536][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-18 14:11:44.597 UTC [35536][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.599 UTC [35536][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-18 14:11:44.644 UTC [35536][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.714 UTC [35306][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:44.715 UTC [35306][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:44.719 UTC [35306][postmaster] LOG:  background worker "logical replication launcher" (PID 35321) exited with exit code 1
2024-03-18 14:11:44.723 UTC [35310][checkpointer] LOG:  shutting down
2024-03-18 14:11:44.723 UTC [35310][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:44.781 UTC [35310][checkpointer] LOG:  checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.058 s, sync=0.001 s, total=0.059 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-18 14:11:44.793 UTC [35306][postmaster] LOG:  database system is shut down
2024-03-18 14:11:44.849 UTC [35568][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-18 14:11:44.849 UTC [35568][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:44.849 UTC [35568][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:44.854 UTC [35577][startup] LOG:  database system was shut down at 2024-03-18 14:11:44 UTC
2024-03-18 14:11:44.860 UTC [35568][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:44.921 UTC [35568][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:44.921 UTC [35568][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:44.928 UTC [35568][postmaster] LOG:  background worker "logical replication launcher" (PID 35580) exited with exit code 1
2024-03-18 14:11:44.930 UTC [35575][checkpointer] LOG:  shutting down
2024-03-18 14:11:44.930 UTC [35575][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:44.931 UTC [35575][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/41946D8, redo lsn=0/41946D8
2024-03-18 14:11:44.935 UTC [35568][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.040 UTC [35597][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-18 14:11:45.040 UTC [35597][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[14:11:45.124](0.206s) 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 35610
[14:11:45.229](0.105s) 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-18 14:11:43.632 UTC [35306][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-18 14:11:43.632 UTC [35306][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:43.641 UTC [35312][startup] LOG:  database system was shut down at 2024-03-18 14:09:16 UTC
2024-03-18 14:11:43.663 UTC [35306][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:43.722 UTC [35334][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.723 UTC [35334][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-18 14:11:43.723 UTC [35334][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.735 UTC [35334][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-18 14:11:43.739 UTC [35334][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.751 UTC [35341][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.752 UTC [35341][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-18 14:11:43.752 UTC [35341][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.753 UTC [35341][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-18 14:11:43.755 UTC [35341][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.799 UTC [35358][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.800 UTC [35358][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-18 14:11:43.800 UTC [35358][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.806 UTC [35358][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-18 14:11:43.808 UTC [35358][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.848 UTC [35369][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.848 UTC [35369][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-18 14:11:43.848 UTC [35369][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.852 UTC [35369][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-18 14:11:43.852 UTC [35369][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.899 UTC [35386][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.900 UTC [35386][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-18 14:11:43.900 UTC [35386][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.904 UTC [35386][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-18 14:11:43.912 UTC [35386][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.937 UTC [35397][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.937 UTC [35397][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-18 14:11:43.937 UTC [35397][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.939 UTC [35397][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-18 14:11:43.984 UTC [35397][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.070 UTC [35437][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.071 UTC [35437][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-18 14:11:44.071 UTC [35437][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.074 UTC [35437][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-18 14:11:44.142 UTC [35437][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.073 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.193 UTC [35453][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.194 UTC [35453][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-18 14:11:44.194 UTC [35453][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.196 UTC [35453][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-18 14:11:44.245 UTC [35453][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.051 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.315 UTC [35484][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.316 UTC [35484][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-18 14:11:44.316 UTC [35484][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.317 UTC [35484][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-18 14:11:44.362 UTC [35484][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.450 UTC [35511][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.451 UTC [35511][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-18 14:11:44.451 UTC [35511][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.452 UTC [35511][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-18 14:11:44.509 UTC [35511][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.059 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.596 UTC [35536][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.597 UTC [35536][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-18 14:11:44.597 UTC [35536][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.599 UTC [35536][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-18 14:11:44.644 UTC [35536][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.714 UTC [35306][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:44.715 UTC [35306][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:44.719 UTC [35306][postmaster] LOG:  background worker "logical replication launcher" (PID 35321) exited with exit code 1
2024-03-18 14:11:44.723 UTC [35310][checkpointer] LOG:  shutting down
2024-03-18 14:11:44.723 UTC [35310][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:44.781 UTC [35310][checkpointer] LOG:  checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.058 s, sync=0.001 s, total=0.059 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-18 14:11:44.793 UTC [35306][postmaster] LOG:  database system is shut down
2024-03-18 14:11:44.849 UTC [35568][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-18 14:11:44.849 UTC [35568][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:44.849 UTC [35568][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:44.854 UTC [35577][startup] LOG:  database system was shut down at 2024-03-18 14:11:44 UTC
2024-03-18 14:11:44.860 UTC [35568][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:44.921 UTC [35568][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:44.921 UTC [35568][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:44.928 UTC [35568][postmaster] LOG:  background worker "logical replication launcher" (PID 35580) exited with exit code 1
2024-03-18 14:11:44.930 UTC [35575][checkpointer] LOG:  shutting down
2024-03-18 14:11:44.930 UTC [35575][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:44.931 UTC [35575][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/41946D8, redo lsn=0/41946D8
2024-03-18 14:11:44.935 UTC [35568][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.040 UTC [35597][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-18 14:11:45.040 UTC [35597][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.151 UTC [35610][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-18 14:11:45.151 UTC [35610][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:45.151 UTC [35610][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:45.155 UTC [35614][startup] LOG:  database system was shut down at 2024-03-18 14:11:44 UTC
2024-03-18 14:11:45.166 UTC [35610][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:45.233 UTC [35610][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:45.233 UTC [35610][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:45.237 UTC [35610][postmaster] LOG:  background worker "logical replication launcher" (PID 35619) exited with exit code 1
2024-03-18 14:11:45.248 UTC [35612][checkpointer] LOG:  shutting down
2024-03-18 14:11:45.248 UTC [35612][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:45.248 UTC [35612][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-18 14:11:45.253 UTC [35610][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.351 UTC [35632][postmaster] FATAL:  could not set SSL protocol version range
2024-03-18 14:11:45.351 UTC [35632][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-18 14:11:45.351 UTC [35632][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[14:11:45.435](0.205s) 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 35639
[14:11:45.544](0.109s) ok 5 - restart succeeds with correct SSL protocol bounds
[14:11:45.544](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 35679
[14:11:45.799](0.255s) ok 6 - server doesn't accept non-SSL connections
[14:11:45.800](0.000s) ok 7 - server doesn't accept non-SSL connections: matches
[14:11:45.831](0.031s) ok 8 - connect without server root cert sslmode=require
[14:11:45.831](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr
[14:11:45.851](0.020s) ok 10 - connect without server root cert sslmode=verify-ca
[14:11:45.851](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[14:11:45.871](0.020s) ok 12 - connect without server root cert sslmode=verify-full
[14:11:45.871](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches
[14:11:45.906](0.035s) ok 14 - connect with wrong server root cert sslmode=require
[14:11:45.906](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches
[14:11:45.925](0.019s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[14:11:45.925](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[14:11:45.948](0.022s) ok 18 - connect with wrong server root cert sslmode=verify-full
[14:11:45.948](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[14:11:45.982](0.034s) ok 20 - connect with server CA cert, without root CA
[14:11:45.982](0.000s) ok 21 - connect with server CA cert, without root CA: matches
[14:11:46.017](0.035s) ok 22 - connect with correct server CA cert file sslmode=require
[14:11:46.017](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[14:11:46.052](0.035s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[14:11:46.052](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[14:11:46.087](0.035s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[14:11:46.087](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[14:11:46.117](0.029s) ok 28 - cert root file that contains two certificates, order 1
[14:11:46.117](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[14:11:46.140](0.023s) ok 30 - cert root file that contains two certificates, order 2
[14:11:46.140](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[14:11:46.168](0.028s) ok 32 - connect with sslcertmode=disable
[14:11:46.168](0.000s) ok 33 - connect with sslcertmode=disable: no stderr
[14:11:46.213](0.045s) ok 34 - connect with sslcertmode=allow
[14:11:46.213](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[14:11:46.247](0.034s) ok 36 - connect with sslcertmode=require fails without a client certificate
[14:11:46.247](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[14:11:46.292](0.045s) ok 38 - sslcrl option with invalid file name
[14:11:46.293](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[14:11:46.321](0.029s) ok 40 - CRL belonging to a different CA
[14:11:46.321](0.000s) ok 41 - CRL belonging to a different CA: matches
[14:11:46.355](0.034s) ok 42 - directory CRL belonging to a different CA
[14:11:46.355](0.000s) ok 43 - directory CRL belonging to a different CA: matches
[14:11:46.393](0.037s) ok 44 - CRL with a non-revoked cert
[14:11:46.393](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[14:11:46.434](0.041s) ok 46 - directory CRL with a non-revoked cert
[14:11:46.435](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr
[14:11:46.464](0.030s) ok 48 - mismatch between host name and server certificate sslmode=require
[14:11:46.464](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[14:11:46.489](0.024s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[14:11:46.489](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[14:11:46.514](0.025s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[14:11:46.514](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 35882
[14:11:46.772](0.258s) ok 54 - IP address in the Common Name
[14:11:46.772](0.000s) ok 55 - IP address in the Common Name: no stderr
[14:11:46.800](0.028s) ok 56 - mismatch between host name and server certificate IP address
[14:11:46.801](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 35913
[14:11:47.043](0.242s) ok 58 - IP address in a dNSName
[14:11:47.043](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 35926
[14:11:47.280](0.237s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[14:11:47.280](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[14:11:47.301](0.021s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[14:11:47.301](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[14:11:47.328](0.027s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[14:11:47.328](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[14:11:47.350](0.022s) ok 66 - host name not matching with X.509 Subject Alternative Names
[14:11:47.350](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[14:11:47.371](0.021s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[14:11:47.372](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 35992
[14:11:47.618](0.247s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[14:11:47.619](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[14:11:47.649](0.031s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[14:11:47.650](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[14:11:47.672](0.022s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[14:11:47.672](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 36062
[14:11:47.920](0.248s) ok 76 - host matching an IPv4 address (Subject Alternative Name 1)
[14:11:47.921](0.000s) ok 77 - host matching an IPv4 address (Subject Alternative Name 1): no stderr
[14:11:47.947](0.027s) ok 78 - host matching an IPv4 address in alternate form (Subject Alternative Name 1)
[14:11:47.948](0.000s) ok 79 - host matching an IPv4 address in alternate form (Subject Alternative Name 1): no stderr
[14:11:47.966](0.019s) ok 80 - host not matching an IPv4 address (Subject Alternative Name 1)
[14:11:47.967](0.000s) ok 81 - host not matching an IPv4 address (Subject Alternative Name 1): matches
[14:11:47.992](0.025s) ok 82 - host matching an IPv6 address (Subject Alternative Name 2)
[14:11:47.992](0.000s) ok 83 - host matching an IPv6 address (Subject Alternative Name 2): no stderr
[14:11:48.013](0.021s) ok 84 - host matching an IPv6 address in alternate form (Subject Alternative Name 2)
[14:11:48.013](0.000s) ok 85 - host matching an IPv6 address in alternate form (Subject Alternative Name 2): no stderr
[14:11:48.033](0.020s) ok 86 - host matching an IPv6 address in mixed form (Subject Alternative Name 2)
[14:11:48.034](0.000s) ok 87 - host matching an IPv6 address in mixed form (Subject Alternative Name 2): no stderr
[14:11:48.059](0.026s) ok 88 - host not matching an IPv6 address (Subject Alternative Name 2)
[14:11:48.060](0.000s) ok 89 - host not matching an IPv6 address (Subject Alternative Name 2): matches
[14:11:48.078](0.018s) ok 90 - IPv6 host with CIDR mask does not match
[14:11:48.078](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 36136
[14:11:48.340](0.262s) ok 92 - certificate with both a CN and SANs 1
[14:11:48.340](0.000s) ok 93 - certificate with both a CN and SANs 1: no stderr
[14:11:48.361](0.021s) ok 94 - certificate with both a CN and SANs 2
[14:11:48.362](0.000s) ok 95 - certificate with both a CN and SANs 2: no stderr
[14:11:48.382](0.020s) ok 96 - certificate with both a CN and SANs ignores CN
[14:11:48.382](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 36235
[14:11:48.625](0.243s) ok 98 - certificate with both a CN and IP SANs matches CN
[14:11:48.625](0.000s) ok 99 - certificate with both a CN and IP SANs matches CN: no stderr
[14:11:48.661](0.036s) ok 100 - certificate with both a CN and IP SANs matches SAN 1
[14:11:48.661](0.000s) ok 101 - certificate with both a CN and IP SANs matches SAN 1: no stderr
[14:11:48.683](0.022s) ok 102 - certificate with both a CN and IP SANs matches SAN 2
[14:11:48.683](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 36314
[14:11:48.920](0.237s) ok 104 - certificate with both an IP CN and IP SANs 1
[14:11:48.920](0.000s) ok 105 - certificate with both an IP CN and IP SANs 1: no stderr
[14:11:48.955](0.035s) ok 106 - certificate with both an IP CN and IP SANs 2
[14:11:48.955](0.000s) ok 107 - certificate with both an IP CN and IP SANs 2: no stderr
[14:11:48.982](0.026s) ok 108 - certificate with both an IP CN and IP SANs ignores CN
[14:11:48.982](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 36391
[14:11:49.230](0.248s) ok 110 - certificate with both an IP CN and DNS SANs matches CN
[14:11:49.230](0.000s) ok 111 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[14:11:49.259](0.028s) ok 112 - certificate with both an IP CN and DNS SANs matches SAN 1
[14:11:49.259](0.000s) ok 113 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[14:11:49.291](0.033s) ok 114 - certificate with both an IP CN and DNS SANs matches SAN 2
[14:11:49.292](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 36471
[14:11:49.538](0.247s) ok 116 - server certificate without CN or SANs sslmode=verify-ca
[14:11:49.539](0.000s) ok 117 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[14:11:49.564](0.025s) ok 118 - server certificate without CN or SANs sslmode=verify-full
[14:11:49.564](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 36588
[14:11:49.795](0.231s) ok 120 - sslrootcert=system does not connect with private CA
[14:11:49.795](0.000s) ok 121 - sslrootcert=system does not connect with private CA: matches
[14:11:49.810](0.015s) ok 122 - sslrootcert=system only accepts sslmode=verify-full
[14:11:49.810](0.000s) ok 123 - sslrootcert=system only accepts sslmode=verify-full: matches
[14:11:49.844](0.034s) ok 124 - sslrootcert=system connects with overridden SSL_CERT_FILE
[14:11:49.844](0.000s) ok 125 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[14:11:49.870](0.026s) ok 126 - sslrootcert=system defaults to sslmode=verify-full
[14:11:49.870](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 36672
[14:11:50.121](0.251s) ok 128 - connects without client-side CRL
[14:11:50.121](0.000s) ok 129 - connects without client-side CRL: no stderr
[14:11:50.139](0.018s) ok 130 - does not connect with client-side CRL file
[14:11:50.139](0.000s) ok 131 - does not connect with client-side CRL file: matches
[14:11:50.165](0.025s) ok 132 - does not connect with client-side CRL directory
[14:11:50.165](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()
[14:11:50.200](0.035s) ok 134 - pg_stat_ssl view without client certificate: exit code 0
[14:11:50.200](0.000s) ok 135 - pg_stat_ssl view without client certificate: no stderr
[14:11:50.200](0.000s) ok 136 - pg_stat_ssl view without client certificate: matches
[14:11:50.232](0.032s) ok 137 - connection success with correct range of TLS protocol versions
[14:11:50.232](0.000s) ok 138 - connection success with correct range of TLS protocol versions: no stderr
[14:11:50.246](0.014s) ok 139 - connection failure with incorrect range of TLS protocol versions
[14:11:50.246](0.000s) ok 140 - connection failure with incorrect range of TLS protocol versions: matches
[14:11:50.256](0.009s) ok 141 - connection failure with an incorrect SSL protocol minimum bound
[14:11:50.256](0.000s) ok 142 - connection failure with an incorrect SSL protocol minimum bound: matches
[14:11:50.265](0.009s) ok 143 - connection failure with an incorrect SSL protocol maximum bound
[14:11:50.265](0.000s) ok 144 - connection failure with an incorrect SSL protocol maximum bound: matches
[14:11:50.265](0.000s) # running server tests
[14:11:50.290](0.025s) ok 145 - certificate authorization fails without client cert
[14:11:50.290](0.000s) ok 146 - certificate authorization fails without client cert: matches
[14:11:50.330](0.040s) ok 147 - certificate authorization succeeds with correct client cert in PEM format
[14:11:50.330](0.000s) ok 148 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[14:11:50.364](0.034s) ok 149 - certificate authorization succeeds with correct client cert in DER format
[14:11:50.365](0.000s) ok 150 - certificate authorization succeeds with correct client cert in DER format: no stderr
[14:11:50.390](0.025s) ok 151 - certificate authorization succeeds with correct client cert in encrypted PEM format
[14:11:50.390](0.000s) ok 152 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[14:11:50.418](0.028s) ok 153 - certificate authorization succeeds with correct client cert in encrypted DER format
[14:11:50.418](0.000s) ok 154 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[14:11:50.446](0.028s) ok 155 - certificate authorization succeeds with correct client cert and sslcertmode=require
[14:11:50.446](0.000s) ok 156 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[14:11:50.474](0.027s) ok 157 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[14:11:50.474](0.000s) ok 158 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[14:11:50.493](0.019s) ok 159 - certificate authorization fails with correct client cert and sslcertmode=disable
[14:11:50.494](0.000s) ok 160 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[14:11:50.511](0.017s) ok 161 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[14:11:50.511](0.000s) ok 162 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[14:11:50.546](0.034s) ok 163 - certificate authorization succeeds with DN mapping
[14:11:50.546](0.000s) ok 164 - certificate authorization succeeds with DN mapping: no stderr
[14:11:50.546](0.000s) ok 165 - certificate authorization succeeds with DN mapping: log matches
[14:11:50.580](0.034s) ok 166 - certificate authorization succeeds with DN regex mapping
[14:11:50.580](0.000s) ok 167 - certificate authorization succeeds with DN regex mapping: no stderr
[14:11:50.614](0.033s) ok 168 - certificate authorization succeeds with CN mapping
[14:11:50.614](0.000s) ok 169 - certificate authorization succeeds with CN mapping: no stderr
[14:11:50.614](0.000s) ok 170 - certificate authorization succeeds with CN mapping: log matches
[14:11:50.615](0.000s) not ok 171 # TODO & SKIP Need Pty support
[14:11:50.615](0.000s) not ok 172 # TODO & SKIP Need Pty support
[14:11:50.615](0.000s) not ok 173 # TODO & SKIP Need Pty support
[14:11:50.615](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_SnUb/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[14:11:50.641](0.026s) ok 175 - pg_stat_ssl with client certificate: exit code 0
[14:11:50.641](0.000s) ok 176 - pg_stat_ssl with client certificate: no stderr
[14:11:50.642](0.000s) ok 177 - pg_stat_ssl with client certificate: matches
[14:11:50.658](0.016s) ok 178 - certificate authorization fails because of file permissions
[14:11:50.658](0.000s) ok 179 - certificate authorization fails because of file permissions: matches
[14:11:50.687](0.029s) ok 180 - certificate authorization fails with client cert belonging to another user
[14:11:50.688](0.000s) ok 181 - certificate authorization fails with client cert belonging to another user: matches
[14:11:50.711](0.023s) ok 182 - certificate authorization fails with revoked client cert
[14:11:50.711](0.000s) ok 183 - certificate authorization fails with revoked client cert: matches
[14:11:50.711](0.000s) ok 184 - certificate authorization fails with revoked client cert: log does not match
[14:11:50.752](0.041s) ok 185 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[14:11:50.752](0.000s) ok 186 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[14:11:50.752](0.000s) ok 187 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[14:11:50.779](0.027s) ok 188 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[14:11:50.780](0.000s) ok 189 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[14:11:50.780](0.000s) ok 190 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[14:11:50.804](0.024s) ok 191 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[14:11:50.804](0.000s) ok 192 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[14:11:50.804](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 36901
[14:11:51.056](0.252s) ok 194 - intermediate client certificate is provided by client
[14:11:51.056](0.000s) ok 195 - intermediate client certificate is provided by client: no stderr
[14:11:51.090](0.034s) ok 196 - intermediate client certificate is missing
[14:11:51.090](0.000s) ok 197 - intermediate client certificate is missing: matches
[14:11:51.113](0.023s) ok 198 - logged client certificate Subjects are truncated if they're too long
[14:11:51.113](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 36978
[14:11:51.336](0.223s) ok 200 - intermediate client certificate is untrusted
[14:11:51.337](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 37029
[14:11:51.562](0.226s) ok 202 - certificate authorization fails with revoked client cert with server-side CRL directory
[14:11:51.563](0.000s) ok 203 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[14:11:51.592](0.029s) ok 204 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[14:11:51.592](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 37140
[14:11:51.857](0.264s) not ok 206 - connect with valid stapled ocsp response when sslocspstapling=1
[14:11:51.857](0.000s) 
[14:11:51.857](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at t/001_ssltests.pl line 923.
[14:11:51.857](0.000s) #          got: '2'
#     expected: '0'
[14:11:51.857](0.000s) not ok 207 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[14:11:51.857](0.000s) 
[14:11:51.857](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at t/001_ssltests.pl line 923.
[14:11:51.858](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 58262 failed: SSL error: ocsp callback failure'
#     expected: ''
[14:11:51.893](0.036s) ok 208 - connect without requesting ocsp response when sslocspstapling=0
[14:11:51.894](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 37221
[14:11:52.124](0.230s) ok 210 - failed with a revoked ocsp response when sslocspstapling=1
[14:11:52.160](0.036s) ok 211 - connect without requesting ocsp response when sslocspstapling=0
[14:11:52.160](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 37281
[14:11:52.405](0.246s) ok 213 - failed with a revoked ocsp response when sslocspstapling=1
[14:11:52.451](0.046s) ok 214 - connect without requesting ocsp response when sslocspstapling=0
[14:11:52.451](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 37345
[14:11:52.677](0.225s) ok 216 - failed with an expired ocsp response when sslocspstapling=1
[14:11:52.723](0.047s) ok 217 - connect without requesting ocsp response when sslocspstapling=0
[14:11:52.724](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 37399
[14:11:52.957](0.233s) not ok 219 - connect with valid stapled ocsp response when sslocspstapling=1
[14:11:52.957](0.000s) 
[14:11:52.957](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at t/001_ssltests.pl line 1001.
[14:11:52.957](0.000s) #          got: '2'
#     expected: '0'
[14:11:52.957](0.000s) not ok 220 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[14:11:52.958](0.000s) 
[14:11:52.958](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at t/001_ssltests.pl line 1001.
[14:11:52.958](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 58262 failed: server closed the connection unexpectedly
# 	This probably means the server terminated abnormally
# 	before or while processing the request.
# SSL SYSCALL error: Connection reset by peer'
#     expected: ''
[14:11:53.018](0.060s) ok 221 - connect without requesting ocsp response when sslocspstapling=0
[14:11:53.018](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 37483
[14:11:53.257](0.239s) ok 223 - failed with a revoked ocsp response when sslocspstapling=1
[14:11:53.295](0.038s) ok 224 - connect without requesting ocsp response when sslocspstapling=0
[14:11:53.295](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 37547
[14:11:53.525](0.230s) ok 226 - failed with a revoked ocsp response when sslocspstapling=1
[14:11:53.557](0.032s) ok 227 - connect without requesting ocsp response when sslocspstapling=0
[14:11:53.557](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 37606
[14:11:53.792](0.235s) ok 229 - failed with an expired ocsp response when sslocspstapling=1
[14:11:53.828](0.036s) ok 230 - connect without requesting ocsp response when sslocspstapling=0
[14:11:53.828](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 37664
[14:11:54.068](0.240s) ok 232 - failed with an expired ocsp response when sslocspstapling=1
[14:11:54.101](0.033s) ok 233 - connect without requesting ocsp response when sslocspstapling=0
[14:11:54.101](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-18 14:11:43.632 UTC [35306][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-18 14:11:43.632 UTC [35306][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:43.641 UTC [35312][startup] LOG:  database system was shut down at 2024-03-18 14:09:16 UTC
2024-03-18 14:11:43.663 UTC [35306][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:43.722 UTC [35334][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.723 UTC [35334][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-18 14:11:43.723 UTC [35334][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.735 UTC [35334][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-18 14:11:43.739 UTC [35334][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.751 UTC [35341][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.752 UTC [35341][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-18 14:11:43.752 UTC [35341][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.753 UTC [35341][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-18 14:11:43.755 UTC [35341][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.799 UTC [35358][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.800 UTC [35358][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-18 14:11:43.800 UTC [35358][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.806 UTC [35358][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-18 14:11:43.808 UTC [35358][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.848 UTC [35369][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.848 UTC [35369][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-18 14:11:43.848 UTC [35369][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.852 UTC [35369][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-18 14:11:43.852 UTC [35369][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.899 UTC [35386][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.900 UTC [35386][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-18 14:11:43.900 UTC [35386][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.904 UTC [35386][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-18 14:11:43.912 UTC [35386][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=postgres database=postgres host=[local]
2024-03-18 14:11:43.937 UTC [35397][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:43.937 UTC [35397][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-18 14:11:43.937 UTC [35397][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:43.939 UTC [35397][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-18 14:11:43.984 UTC [35397][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.070 UTC [35437][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.071 UTC [35437][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-18 14:11:44.071 UTC [35437][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.074 UTC [35437][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-18 14:11:44.142 UTC [35437][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.073 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.193 UTC [35453][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.194 UTC [35453][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-18 14:11:44.194 UTC [35453][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.196 UTC [35453][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-18 14:11:44.245 UTC [35453][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.051 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.315 UTC [35484][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.316 UTC [35484][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-18 14:11:44.316 UTC [35484][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.317 UTC [35484][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-18 14:11:44.362 UTC [35484][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.450 UTC [35511][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.451 UTC [35511][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-18 14:11:44.451 UTC [35511][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.452 UTC [35511][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-18 14:11:44.509 UTC [35511][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.059 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.596 UTC [35536][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:11:44.597 UTC [35536][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-18 14:11:44.597 UTC [35536][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=postgres database=postgres application_name=001_ssltests.pl
2024-03-18 14:11:44.599 UTC [35536][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-18 14:11:44.644 UTC [35536][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.047 user=postgres database=postgres host=[local]
2024-03-18 14:11:44.714 UTC [35306][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:44.715 UTC [35306][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:44.719 UTC [35306][postmaster] LOG:  background worker "logical replication launcher" (PID 35321) exited with exit code 1
2024-03-18 14:11:44.723 UTC [35310][checkpointer] LOG:  shutting down
2024-03-18 14:11:44.723 UTC [35310][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:44.781 UTC [35310][checkpointer] LOG:  checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.058 s, sync=0.001 s, total=0.059 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-18 14:11:44.793 UTC [35306][postmaster] LOG:  database system is shut down
2024-03-18 14:11:44.849 UTC [35568][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-18 14:11:44.849 UTC [35568][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:44.849 UTC [35568][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:44.854 UTC [35577][startup] LOG:  database system was shut down at 2024-03-18 14:11:44 UTC
2024-03-18 14:11:44.860 UTC [35568][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:44.921 UTC [35568][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:44.921 UTC [35568][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:44.928 UTC [35568][postmaster] LOG:  background worker "logical replication launcher" (PID 35580) exited with exit code 1
2024-03-18 14:11:44.930 UTC [35575][checkpointer] LOG:  shutting down
2024-03-18 14:11:44.930 UTC [35575][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:44.931 UTC [35575][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/41946D8, redo lsn=0/41946D8
2024-03-18 14:11:44.935 UTC [35568][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.040 UTC [35597][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-18 14:11:45.040 UTC [35597][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.151 UTC [35610][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-18 14:11:45.151 UTC [35610][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:45.151 UTC [35610][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:45.155 UTC [35614][startup] LOG:  database system was shut down at 2024-03-18 14:11:44 UTC
2024-03-18 14:11:45.166 UTC [35610][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:45.233 UTC [35610][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:45.233 UTC [35610][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:45.237 UTC [35610][postmaster] LOG:  background worker "logical replication launcher" (PID 35619) exited with exit code 1
2024-03-18 14:11:45.248 UTC [35612][checkpointer] LOG:  shutting down
2024-03-18 14:11:45.248 UTC [35612][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:45.248 UTC [35612][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-18 14:11:45.253 UTC [35610][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.351 UTC [35632][postmaster] FATAL:  could not set SSL protocol version range
2024-03-18 14:11:45.351 UTC [35632][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-18 14:11:45.351 UTC [35632][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.468 UTC [35639][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-18 14:11:45.468 UTC [35639][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:45.468 UTC [35639][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:45.485 UTC [35643][startup] LOG:  database system was shut down at 2024-03-18 14:11:45 UTC
2024-03-18 14:11:45.492 UTC [35639][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:45.563 UTC [35639][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:45.563 UTC [35639][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:45.572 UTC [35639][postmaster] LOG:  background worker "logical replication launcher" (PID 35646) exited with exit code 1
2024-03-18 14:11:45.575 UTC [35641][checkpointer] LOG:  shutting down
2024-03-18 14:11:45.575 UTC [35641][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:45.575 UTC [35641][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-18 14:11:45.581 UTC [35639][postmaster] LOG:  database system is shut down
2024-03-18 14:11:45.694 UTC [35679][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-18 14:11:45.694 UTC [35679][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:45.694 UTC [35679][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:45.703 UTC [35687][startup] LOG:  database system was shut down at 2024-03-18 14:11:45 UTC
2024-03-18 14:11:45.710 UTC [35679][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:45.796 UTC [35705][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42736
2024-03-18 14:11:45.797 UTC [35705][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-18 14:11:45.797 UTC [35705][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "localhost", forward lookup not checked.
2024-03-18 14:11:45.809 UTC [35707][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42742
2024-03-18 14:11:45.815 UTC [35707][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-18 14:11:45.815 UTC [35707][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-18 14:11:45.827 UTC [35707][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-18 14:11:45.832 UTC [35707][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=42742
2024-03-18 14:11:45.846 UTC [35718][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42754
2024-03-18 14:11:45.853 UTC [35718][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:11:45.867 UTC [35725][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42770
2024-03-18 14:11:45.871 UTC [35725][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:11:45.899 UTC [35730][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42776
2024-03-18 14:11:45.905 UTC [35730][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:11:45.918 UTC [35738][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42788
2024-03-18 14:11:45.923 UTC [35738][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:11:45.935 UTC [35743][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42790
2024-03-18 14:11:45.940 UTC [35743][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:11:45.969 UTC [35751][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42804
2024-03-18 14:11:45.977 UTC [35751][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:11:46.006 UTC [35761][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42812
2024-03-18 14:11:46.012 UTC [35761][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-18 14:11:46.012 UTC [35761][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-18 14:11:46.014 UTC [35761][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-18 14:11:46.016 UTC [35761][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=42812
2024-03-18 14:11:46.036 UTC [35769][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42814
2024-03-18 14:11:46.044 UTC [35769][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-18 14:11:46.044 UTC [35769][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-18 14:11:46.048 UTC [35769][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-18 14:11:46.053 UTC [35769][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.017 user=ssltestuser database=trustdb host=localhost port=42814
2024-03-18 14:11:46.072 UTC [35778][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42830
2024-03-18 14:11:46.082 UTC [35778][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-18 14:11:46.082 UTC [35778][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-18 14:11:46.083 UTC [35778][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-18 14:11:46.090 UTC [35778][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=42830
2024-03-18 14:11:46.105 UTC [35786][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42840
2024-03-18 14:11:46.111 UTC [35786][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-18 14:11:46.111 UTC [35786][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-18 14:11:46.113 UTC [35786][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-18 14:11:46.114 UTC [35786][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=42840
2024-03-18 14:11:46.128 UTC [35791][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42850
2024-03-18 14:11:46.134 UTC [35791][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-18 14:11:46.134 UTC [35791][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-18 14:11:46.136 UTC [35791][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-18 14:11:46.141 UTC [35791][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=ssltestuser database=trustdb host=localhost port=42850
2024-03-18 14:11:46.156 UTC [35796][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42866
2024-03-18 14:11:46.163 UTC [35796][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-18 14:11:46.163 UTC [35796][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-18 14:11:46.164 UTC [35796][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-18 14:11:46.169 UTC [35796][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=42866
2024-03-18 14:11:46.184 UTC [35802][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42872
2024-03-18 14:11:46.203 UTC [35802][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-18 14:11:46.203 UTC [35802][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-18 14:11:46.209 UTC [35802][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-18 14:11:46.214 UTC [35802][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=localhost port=42872
2024-03-18 14:11:46.234 UTC [35809][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42874
2024-03-18 14:11:46.243 UTC [35809][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-18 14:11:46.243 UTC [35809][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-18 14:11:46.244 UTC [35809][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=42874
2024-03-18 14:11:46.276 UTC [35815][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42882
2024-03-18 14:11:46.287 UTC [35815][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-18 14:11:46.287 UTC [35815][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-18 14:11:46.289 UTC [35815][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-18 14:11:46.289 UTC [35815][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.015 user=ssltestuser database=trustdb host=localhost port=42882
2024-03-18 14:11:46.314 UTC [35821][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42884
2024-03-18 14:11:46.324 UTC [35821][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:11:46.348 UTC [35827][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42900
2024-03-18 14:11:46.352 UTC [35827][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:11:46.378 UTC [35834][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42902
2024-03-18 14:11:46.384 UTC [35834][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-18 14:11:46.384 UTC [35834][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-18 14:11:46.389 UTC [35834][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-18 14:11:46.390 UTC [35834][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=42902
2024-03-18 14:11:46.419 UTC [35841][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42908
2024-03-18 14:11:46.429 UTC [35841][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-18 14:11:46.429 UTC [35841][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-18 14:11:46.430 UTC [35841][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-18 14:11:46.436 UTC [35841][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.017 user=ssltestuser database=trustdb host=localhost port=42908
2024-03-18 14:11:46.451 UTC [35847][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42920
2024-03-18 14:11:46.458 UTC [35847][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-18 14:11:46.458 UTC [35847][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-18 14:11:46.461 UTC [35847][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-18 14:11:46.462 UTC [35847][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=42920
2024-03-18 14:11:46.476 UTC [35853][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42936
2024-03-18 14:11:46.483 UTC [35853][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-18 14:11:46.483 UTC [35853][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-18 14:11:46.484 UTC [35853][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-18 14:11:46.488 UTC [35853][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=42936
2024-03-18 14:11:46.505 UTC [35860][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42944
2024-03-18 14:11:46.522 UTC [35679][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:46.522 UTC [35679][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:46.526 UTC [35679][postmaster] LOG:  background worker "logical replication launcher" (PID 35691) exited with exit code 1
2024-03-18 14:11:46.531 UTC [35685][checkpointer] LOG:  shutting down
2024-03-18 14:11:46.531 UTC [35685][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:46.532 UTC [35685][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-18 14:11:46.537 UTC [35679][postmaster] LOG:  database system is shut down
2024-03-18 14:11:46.652 UTC [35882][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-18 14:11:46.652 UTC [35882][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:46.652 UTC [35882][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:46.662 UTC [35892][startup] LOG:  database system was shut down at 2024-03-18 14:11:46 UTC
2024-03-18 14:11:46.670 UTC [35882][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:46.739 UTC [35901][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42960
2024-03-18 14:11:46.745 UTC [35901][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-18 14:11:46.745 UTC [35901][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-18 14:11:46.768 UTC [35901][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-18 14:11:46.773 UTC [35901][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=localhost port=42960
2024-03-18 14:11:46.791 UTC [35905][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42964
2024-03-18 14:11:46.804 UTC [35882][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:46.804 UTC [35882][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:46.808 UTC [35882][postmaster] LOG:  background worker "logical replication launcher" (PID 35895) exited with exit code 1
2024-03-18 14:11:46.808 UTC [35889][checkpointer] LOG:  shutting down
2024-03-18 14:11:46.808 UTC [35889][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:46.809 UTC [35889][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-18 14:11:46.814 UTC [35882][postmaster] LOG:  database system is shut down
2024-03-18 14:11:46.929 UTC [35913][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-18 14:11:46.929 UTC [35913][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:46.930 UTC [35913][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:46.934 UTC [35917][startup] LOG:  database system was shut down at 2024-03-18 14:11:46 UTC
2024-03-18 14:11:46.941 UTC [35913][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:47.015 UTC [35922][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42968
2024-03-18 14:11:47.021 UTC [35922][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-18 14:11:47.021 UTC [35922][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-18 14:11:47.033 UTC [35922][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-18 14:11:47.036 UTC [35922][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=localhost port=42968
2024-03-18 14:11:47.046 UTC [35913][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:47.046 UTC [35913][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:47.050 UTC [35913][postmaster] LOG:  background worker "logical replication launcher" (PID 35920) exited with exit code 1
2024-03-18 14:11:47.058 UTC [35915][checkpointer] LOG:  shutting down
2024-03-18 14:11:47.058 UTC [35915][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:47.058 UTC [35915][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-18 14:11:47.064 UTC [35913][postmaster] LOG:  database system is shut down
2024-03-18 14:11:47.169 UTC [35926][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-18 14:11:47.169 UTC [35926][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:47.169 UTC [35926][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:47.175 UTC [35933][startup] LOG:  database system was shut down at 2024-03-18 14:11:47 UTC
2024-03-18 14:11:47.182 UTC [35926][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:47.258 UTC [35943][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42980
2024-03-18 14:11:47.264 UTC [35943][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-18 14:11:47.264 UTC [35943][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-18 14:11:47.276 UTC [35943][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-18 14:11:47.278 UTC [35943][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=localhost port=42980
2024-03-18 14:11:47.290 UTC [35951][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42986
2024-03-18 14:11:47.296 UTC [35951][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-18 14:11:47.296 UTC [35951][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-18 14:11:47.297 UTC [35951][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-18 14:11:47.302 UTC [35951][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=42986
2024-03-18 14:11:47.317 UTC [35957][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=42990
2024-03-18 14:11:47.323 UTC [35957][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-18 14:11:47.323 UTC [35957][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-18 14:11:47.324 UTC [35957][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-18 14:11:47.325 UTC [35957][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=ssltestuser database=trustdb host=localhost port=42990
2024-03-18 14:11:47.340 UTC [35963][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43000
2024-03-18 14:11:47.363 UTC [35971][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43012
2024-03-18 14:11:47.375 UTC [35926][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:47.375 UTC [35926][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:47.385 UTC [35926][postmaster] LOG:  background worker "logical replication launcher" (PID 35936) exited with exit code 1
2024-03-18 14:11:47.388 UTC [35931][checkpointer] LOG:  shutting down
2024-03-18 14:11:47.388 UTC [35931][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:47.389 UTC [35931][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-18 14:11:47.393 UTC [35926][postmaster] LOG:  database system is shut down
2024-03-18 14:11:47.499 UTC [35992][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-18 14:11:47.499 UTC [35992][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:47.499 UTC [35992][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:47.504 UTC [35998][startup] LOG:  database system was shut down at 2024-03-18 14:11:47 UTC
2024-03-18 14:11:47.511 UTC [35992][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:47.596 UTC [36017][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43016
2024-03-18 14:11:47.602 UTC [36017][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-18 14:11:47.602 UTC [36017][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-18 14:11:47.614 UTC [36017][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-18 14:11:47.620 UTC [36017][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=43016
2024-03-18 14:11:47.636 UTC [36023][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43032
2024-03-18 14:11:47.660 UTC [36029][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43036
2024-03-18 14:11:47.679 UTC [35992][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:47.679 UTC [35992][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:47.684 UTC [35992][postmaster] LOG:  background worker "logical replication launcher" (PID 36003) exited with exit code 1
2024-03-18 14:11:47.685 UTC [35996][checkpointer] LOG:  shutting down
2024-03-18 14:11:47.685 UTC [35996][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:47.686 UTC [35996][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-18 14:11:47.691 UTC [35992][postmaster] LOG:  database system is shut down
2024-03-18 14:11:47.802 UTC [36062][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-18 14:11:47.802 UTC [36062][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:47.802 UTC [36062][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:47.808 UTC [36068][startup] LOG:  database system was shut down at 2024-03-18 14:11:47 UTC
2024-03-18 14:11:47.817 UTC [36062][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:47.894 UTC [36096][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43038
2024-03-18 14:11:47.904 UTC [36096][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-18 14:11:47.904 UTC [36096][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-18 14:11:47.916 UTC [36096][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-18 14:11:47.922 UTC [36096][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=localhost port=43038
2024-03-18 14:11:47.936 UTC [36105][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43052
2024-03-18 14:11:47.942 UTC [36105][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-18 14:11:47.942 UTC [36105][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-18 14:11:47.944 UTC [36105][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-18 14:11:47.944 UTC [36105][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=ssltestuser database=trustdb host=localhost port=43052
2024-03-18 14:11:47.957 UTC [36109][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43064
2024-03-18 14:11:47.976 UTC [36114][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43076
2024-03-18 14:11:47.987 UTC [36114][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-18 14:11:47.987 UTC [36114][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-18 14:11:47.988 UTC [36114][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-18 14:11:47.989 UTC [36114][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=43076
2024-03-18 14:11:48.002 UTC [36118][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43086
2024-03-18 14:11:48.008 UTC [36118][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-18 14:11:48.008 UTC [36118][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-18 14:11:48.009 UTC [36118][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-18 14:11:48.012 UTC [36118][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=43086
2024-03-18 14:11:48.022 UTC [36121][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43096
2024-03-18 14:11:48.028 UTC [36121][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-18 14:11:48.028 UTC [36121][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-18 14:11:48.030 UTC [36121][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-18 14:11:48.030 UTC [36121][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=ssltestuser database=trustdb host=localhost port=43096
2024-03-18 14:11:48.051 UTC [36123][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43110
2024-03-18 14:11:48.070 UTC [36127][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43126
2024-03-18 14:11:48.081 UTC [36062][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:48.081 UTC [36062][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:48.086 UTC [36062][postmaster] LOG:  background worker "logical replication launcher" (PID 36076) exited with exit code 1
2024-03-18 14:11:48.088 UTC [36066][checkpointer] LOG:  shutting down
2024-03-18 14:11:48.088 UTC [36066][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:48.089 UTC [36066][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-18 14:11:48.094 UTC [36062][postmaster] LOG:  database system is shut down
2024-03-18 14:11:48.212 UTC [36136][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-18 14:11:48.212 UTC [36136][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:48.212 UTC [36136][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:48.230 UTC [36139][startup] LOG:  database system was shut down at 2024-03-18 14:11:48 UTC
2024-03-18 14:11:48.238 UTC [36136][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:48.317 UTC [36161][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43134
2024-03-18 14:11:48.323 UTC [36161][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-18 14:11:48.323 UTC [36161][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-18 14:11:48.336 UTC [36161][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-18 14:11:48.337 UTC [36161][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=localhost port=43134
2024-03-18 14:11:48.350 UTC [36169][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43150
2024-03-18 14:11:48.356 UTC [36169][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-18 14:11:48.356 UTC [36169][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-18 14:11:48.358 UTC [36169][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-18 14:11:48.358 UTC [36169][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=ssltestuser database=trustdb host=localhost port=43150
2024-03-18 14:11:48.371 UTC [36176][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43156
2024-03-18 14:11:48.389 UTC [36136][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:48.389 UTC [36136][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:48.397 UTC [36136][postmaster] LOG:  background worker "logical replication launcher" (PID 36144) exited with exit code 1
2024-03-18 14:11:48.397 UTC [36137][checkpointer] LOG:  shutting down
2024-03-18 14:11:48.397 UTC [36137][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:48.398 UTC [36137][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-18 14:11:48.403 UTC [36136][postmaster] LOG:  database system is shut down
2024-03-18 14:11:48.515 UTC [36235][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-18 14:11:48.515 UTC [36235][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:48.515 UTC [36235][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:48.520 UTC [36245][startup] LOG:  database system was shut down at 2024-03-18 14:11:48 UTC
2024-03-18 14:11:48.527 UTC [36235][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:48.602 UTC [36277][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43166
2024-03-18 14:11:48.608 UTC [36277][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-18 14:11:48.608 UTC [36277][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-18 14:11:48.621 UTC [36277][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-18 14:11:48.626 UTC [36277][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=localhost port=43166
2024-03-18 14:11:48.648 UTC [36288][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43180
2024-03-18 14:11:48.655 UTC [36288][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-18 14:11:48.655 UTC [36288][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-18 14:11:48.656 UTC [36288][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-18 14:11:48.657 UTC [36288][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=43180
2024-03-18 14:11:48.671 UTC [36293][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43186
2024-03-18 14:11:48.677 UTC [36293][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-18 14:11:48.677 UTC [36293][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-18 14:11:48.679 UTC [36293][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-18 14:11:48.682 UTC [36293][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=43186
2024-03-18 14:11:48.686 UTC [36235][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:48.686 UTC [36235][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:48.695 UTC [36235][postmaster] LOG:  background worker "logical replication launcher" (PID 36251) exited with exit code 1
2024-03-18 14:11:48.695 UTC [36243][checkpointer] LOG:  shutting down
2024-03-18 14:11:48.695 UTC [36243][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:48.696 UTC [36243][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-18 14:11:48.702 UTC [36235][postmaster] LOG:  database system is shut down
2024-03-18 14:11:48.811 UTC [36314][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-18 14:11:48.811 UTC [36314][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:48.811 UTC [36314][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:48.817 UTC [36324][startup] LOG:  database system was shut down at 2024-03-18 14:11:48 UTC
2024-03-18 14:11:48.825 UTC [36314][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:48.898 UTC [36345][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43190
2024-03-18 14:11:48.904 UTC [36345][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-18 14:11:48.904 UTC [36345][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-18 14:11:48.917 UTC [36345][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-18 14:11:48.917 UTC [36345][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=localhost port=43190
2024-03-18 14:11:48.943 UTC [36354][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43206
2024-03-18 14:11:48.950 UTC [36354][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-18 14:11:48.950 UTC [36354][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-18 14:11:48.951 UTC [36354][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-18 14:11:48.954 UTC [36354][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=43206
2024-03-18 14:11:48.973 UTC [36362][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43222
2024-03-18 14:11:48.988 UTC [36314][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:48.988 UTC [36314][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:48.995 UTC [36314][postmaster] LOG:  background worker "logical replication launcher" (PID 36329) exited with exit code 1
2024-03-18 14:11:48.998 UTC [36322][checkpointer] LOG:  shutting down
2024-03-18 14:11:48.998 UTC [36322][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:48.999 UTC [36322][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-18 14:11:49.004 UTC [36314][postmaster] LOG:  database system is shut down
2024-03-18 14:11:49.118 UTC [36391][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-18 14:11:49.118 UTC [36391][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:49.118 UTC [36391][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:49.122 UTC [36396][startup] LOG:  database system was shut down at 2024-03-18 14:11:48 UTC
2024-03-18 14:11:49.129 UTC [36391][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:49.207 UTC [36420][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43226
2024-03-18 14:11:49.213 UTC [36420][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-18 14:11:49.213 UTC [36420][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-18 14:11:49.226 UTC [36420][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-18 14:11:49.232 UTC [36420][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=localhost port=43226
2024-03-18 14:11:49.247 UTC [36432][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43240
2024-03-18 14:11:49.253 UTC [36432][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-18 14:11:49.253 UTC [36432][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-18 14:11:49.255 UTC [36432][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-18 14:11:49.260 UTC [36432][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=43240
2024-03-18 14:11:49.279 UTC [36443][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43254
2024-03-18 14:11:49.286 UTC [36443][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-18 14:11:49.286 UTC [36443][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-18 14:11:49.287 UTC [36443][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-18 14:11:49.288 UTC [36443][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=43254
2024-03-18 14:11:49.294 UTC [36391][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:49.294 UTC [36391][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:49.302 UTC [36391][postmaster] LOG:  background worker "logical replication launcher" (PID 36401) exited with exit code 1
2024-03-18 14:11:49.302 UTC [36394][checkpointer] LOG:  shutting down
2024-03-18 14:11:49.302 UTC [36394][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:49.302 UTC [36394][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-18 14:11:49.311 UTC [36391][postmaster] LOG:  database system is shut down
2024-03-18 14:11:49.416 UTC [36471][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-18 14:11:49.417 UTC [36471][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:49.417 UTC [36471][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:49.421 UTC [36482][startup] LOG:  database system was shut down at 2024-03-18 14:11:49 UTC
2024-03-18 14:11:49.428 UTC [36471][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:49.515 UTC [36547][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43266
2024-03-18 14:11:49.521 UTC [36547][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-18 14:11:49.521 UTC [36547][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-18 14:11:49.534 UTC [36547][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-18 14:11:49.540 UTC [36547][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=localhost port=43266
2024-03-18 14:11:49.556 UTC [36557][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43270
2024-03-18 14:11:49.568 UTC [36471][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:49.568 UTC [36471][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:49.576 UTC [36471][postmaster] LOG:  background worker "logical replication launcher" (PID 36486) exited with exit code 1
2024-03-18 14:11:49.576 UTC [36480][checkpointer] LOG:  shutting down
2024-03-18 14:11:49.576 UTC [36480][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:49.577 UTC [36480][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-18 14:11:49.582 UTC [36471][postmaster] LOG:  database system is shut down
2024-03-18 14:11:49.693 UTC [36588][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-18 14:11:49.693 UTC [36588][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:49.693 UTC [36588][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:49.701 UTC [36600][startup] LOG:  database system was shut down at 2024-03-18 14:11:49 UTC
2024-03-18 14:11:49.709 UTC [36588][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:49.787 UTC [36626][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43276
2024-03-18 14:11:49.797 UTC [36626][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:11:49.822 UTC [36638][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43280
2024-03-18 14:11:49.828 UTC [36638][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-18 14:11:49.828 UTC [36638][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-18 14:11:49.840 UTC [36638][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-18 14:11:49.846 UTC [36638][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=localhost port=43280
2024-03-18 14:11:49.861 UTC [36648][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43290
2024-03-18 14:11:49.878 UTC [36588][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:49.878 UTC [36588][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:49.883 UTC [36588][postmaster] LOG:  background worker "logical replication launcher" (PID 36606) exited with exit code 1
2024-03-18 14:11:49.886 UTC [36597][checkpointer] LOG:  shutting down
2024-03-18 14:11:49.886 UTC [36597][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:49.887 UTC [36597][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-18 14:11:49.893 UTC [36588][postmaster] LOG:  database system is shut down
2024-03-18 14:11:50.011 UTC [36672][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-18 14:11:50.011 UTC [36672][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:50.011 UTC [36672][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:50.017 UTC [36683][startup] LOG:  database system was shut down at 2024-03-18 14:11:49 UTC
2024-03-18 14:11:50.027 UTC [36672][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:50.099 UTC [36706][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43300
2024-03-18 14:11:50.105 UTC [36706][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-18 14:11:50.105 UTC [36706][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-18 14:11:50.117 UTC [36706][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-18 14:11:50.117 UTC [36706][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=localhost port=43300
2024-03-18 14:11:50.131 UTC [36714][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43314
2024-03-18 14:11:50.138 UTC [36714][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-18 14:11:50.157 UTC [36722][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43320
2024-03-18 14:11:50.164 UTC [36722][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-18 14:11:50.182 UTC [36731][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43336
2024-03-18 14:11:50.193 UTC [36731][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-18 14:11:50.193 UTC [36731][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-18 14:11:50.195 UTC [36731][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-18 14:11:50.204 UTC [36731][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=43336
2024-03-18 14:11:50.221 UTC [36747][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43344
2024-03-18 14:11:50.226 UTC [36747][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-18 14:11:50.226 UTC [36747][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-18 14:11:50.228 UTC [36747][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-18 14:11:50.231 UTC [36747][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=43344
2024-03-18 14:11:50.275 UTC [36763][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43360
2024-03-18 14:11:50.282 UTC [36763][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-03-18 14:11:50.304 UTC [36771][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43364
2024-03-18 14:11:50.315 UTC [36771][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-18 14:11:50.315 UTC [36771][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-18 14:11:50.326 UTC [36771][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_SnUb/client.key$$
2024-03-18 14:11:50.332 UTC [36771][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb host=localhost port=43364
2024-03-18 14:11:50.347 UTC [36777][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43366
2024-03-18 14:11:50.354 UTC [36777][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-18 14:11:50.354 UTC [36777][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-18 14:11:50.356 UTC [36777][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_SnUb/client-der.key$$
2024-03-18 14:11:50.359 UTC [36777][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.012 user=ssltestuser database=certdb host=localhost port=43366
2024-03-18 14:11:50.375 UTC [36782][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43380
2024-03-18 14:11:50.384 UTC [36782][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-18 14:11:50.384 UTC [36782][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-18 14:11:50.385 UTC [36782][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_SnUb/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-03-18 14:11:50.389 UTC [36782][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.013 user=ssltestuser database=certdb host=localhost port=43380
2024-03-18 14:11:50.405 UTC [36787][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43392
2024-03-18 14:11:50.413 UTC [36787][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-18 14:11:50.413 UTC [36787][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-18 14:11:50.415 UTC [36787][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_SnUb/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-03-18 14:11:50.420 UTC [36787][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=ssltestuser database=certdb host=localhost port=43392
2024-03-18 14:11:50.434 UTC [36792][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43396
2024-03-18 14:11:50.441 UTC [36792][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-18 14:11:50.441 UTC [36792][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-18 14:11:50.443 UTC [36792][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_SnUb/client.key$$
2024-03-18 14:11:50.448 UTC [36792][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.014 user=ssltestuser database=certdb host=localhost port=43396
2024-03-18 14:11:50.461 UTC [36797][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43404
2024-03-18 14:11:50.469 UTC [36797][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-18 14:11:50.469 UTC [36797][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-18 14:11:50.470 UTC [36797][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_SnUb/client.key$$
2024-03-18 14:11:50.471 UTC [36797][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=ssltestuser database=certdb host=localhost port=43404
2024-03-18 14:11:50.484 UTC [36801][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43410
2024-03-18 14:11:50.490 UTC [36801][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-03-18 14:11:50.505 UTC [36806][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43414
2024-03-18 14:11:50.510 UTC [36806][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:11:50.523 UTC [36811][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43416
2024-03-18 14:11:50.531 UTC [36811][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-18 14:11:50.531 UTC [36811][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-18 14:11:50.542 UTC [36811][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_SnUb/client-dn.key$$
2024-03-18 14:11:50.542 UTC [36811][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=certdb_dn host=localhost port=43416
2024-03-18 14:11:50.557 UTC [36818][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43432
2024-03-18 14:11:50.565 UTC [36818][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-18 14:11:50.565 UTC [36818][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-18 14:11:50.576 UTC [36818][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_SnUb/client-dn.key$$
2024-03-18 14:11:50.581 UTC [36818][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb_dn_re host=localhost port=43432
2024-03-18 14:11:50.590 UTC [36825][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43436
2024-03-18 14:11:50.598 UTC [36825][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-18 14:11:50.598 UTC [36825][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-18 14:11:50.610 UTC [36825][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_SnUb/client-dn.key$$
2024-03-18 14:11:50.611 UTC [36825][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb_cn host=localhost port=43436
2024-03-18 14:11:50.627 UTC [36834][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43442
2024-03-18 14:11:50.635 UTC [36834][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-18 14:11:50.635 UTC [36834][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-18 14:11:50.636 UTC [36834][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-18 14:11:50.639 UTC [36834][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.011 user=ssltestuser database=certdb host=localhost port=43442
2024-03-18 14:11:50.652 UTC [36839][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43454
2024-03-18 14:11:50.654 UTC [36839][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:11:50.670 UTC [36846][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43466
2024-03-18 14:11:50.678 UTC [36846][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-18 14:11:50.678 UTC [36846][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-18 14:11:50.678 UTC [36846][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-03-18 14:11:50.678 UTC [36846][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-18 14:11:50.700 UTC [36854][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43476
2024-03-18 14:11:50.710 UTC [36854][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:11:50.710 UTC [36854][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-18 14:11:50.728 UTC [36861][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43490
2024-03-18 14:11:50.736 UTC [36861][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-18 14:11:50.736 UTC [36861][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-18 14:11:50.748 UTC [36861][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_SnUb/client.key$$
2024-03-18 14:11:50.754 UTC [36861][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=verifydb host=localhost port=43490
2024-03-18 14:11:50.767 UTC [36869][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43500
2024-03-18 14:11:50.776 UTC [36869][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-18 14:11:50.776 UTC [36869][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-03-18 14:11:50.776 UTC [36869][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-03-18 14:11:50.776 UTC [36869][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-18 14:11:50.790 UTC [36874][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43510
2024-03-18 14:11:50.798 UTC [36874][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-18 14:11:50.798 UTC [36874][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-18 14:11:50.799 UTC [36874][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_SnUb/client.key$$
2024-03-18 14:11:50.800 UTC [36874][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=yetanotheruser database=verifydb host=localhost port=43510
2024-03-18 14:11:50.807 UTC [36672][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:50.807 UTC [36672][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:50.812 UTC [36672][postmaster] LOG:  background worker "logical replication launcher" (PID 36690) exited with exit code 1
2024-03-18 14:11:50.816 UTC [36681][checkpointer] LOG:  shutting down
2024-03-18 14:11:50.816 UTC [36681][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:50.817 UTC [36681][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-18 14:11:50.824 UTC [36672][postmaster] LOG:  database system is shut down
2024-03-18 14:11:50.929 UTC [36901][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-18 14:11:50.929 UTC [36901][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:50.929 UTC [36901][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:50.933 UTC [36906][startup] LOG:  database system was shut down at 2024-03-18 14:11:50 UTC
2024-03-18 14:11:50.940 UTC [36901][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:51.029 UTC [36936][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43514
2024-03-18 14:11:51.036 UTC [36936][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-18 14:11:51.036 UTC [36936][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-18 14:11:51.052 UTC [36936][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_SnUb/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-18 14:11:51.057 UTC [36936][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb host=localhost port=43514
2024-03-18 14:11:51.075 UTC [36950][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43522
2024-03-18 14:11:51.082 UTC [36950][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:11:51.082 UTC [36950][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-18 14:11:51.101 UTC [36957][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43530
2024-03-18 14:11:51.108 UTC [36957][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:11:51.108 UTC [36957][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-18 14:11:51.116 UTC [36901][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:51.116 UTC [36901][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:51.121 UTC [36901][postmaster] LOG:  background worker "logical replication launcher" (PID 36910) exited with exit code 1
2024-03-18 14:11:51.122 UTC [36904][checkpointer] LOG:  shutting down
2024-03-18 14:11:51.122 UTC [36904][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:51.122 UTC [36904][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-18 14:11:51.129 UTC [36901][postmaster] LOG:  database system is shut down
2024-03-18 14:11:51.239 UTC [36978][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-18 14:11:51.239 UTC [36978][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:51.239 UTC [36978][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:51.246 UTC [36985][startup] LOG:  database system was shut down at 2024-03-18 14:11:51 UTC
2024-03-18 14:11:51.254 UTC [36978][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:51.327 UTC [37004][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43536
2024-03-18 14:11:51.333 UTC [37004][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:11:51.333 UTC [37004][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-18 14:11:51.339 UTC [36978][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:51.339 UTC [36978][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:51.343 UTC [36978][postmaster] LOG:  background worker "logical replication launcher" (PID 36990) exited with exit code 1
2024-03-18 14:11:51.347 UTC [36983][checkpointer] LOG:  shutting down
2024-03-18 14:11:51.347 UTC [36983][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:51.347 UTC [36983][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-18 14:11:51.352 UTC [36978][postmaster] LOG:  database system is shut down
2024-03-18 14:11:51.470 UTC [37029][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-18 14:11:51.470 UTC [37029][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:51.470 UTC [37029][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:51.474 UTC [37037][startup] LOG:  database system was shut down at 2024-03-18 14:11:51 UTC
2024-03-18 14:11:51.481 UTC [37029][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:51.552 UTC [37056][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43544
2024-03-18 14:11:51.562 UTC [37056][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:11:51.562 UTC [37056][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-18 14:11:51.577 UTC [37070][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43556
2024-03-18 14:11:51.584 UTC [37070][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:11:51.584 UTC [37070][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-18 14:11:51.601 UTC [37029][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:51.601 UTC [37029][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:51.608 UTC [37029][postmaster] LOG:  background worker "logical replication launcher" (PID 37041) exited with exit code 1
2024-03-18 14:11:51.608 UTC [37035][checkpointer] LOG:  shutting down
2024-03-18 14:11:51.608 UTC [37035][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:51.609 UTC [37035][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-18 14:11:51.614 UTC [37029][postmaster] LOG:  database system is shut down
2024-03-18 14:11:51.730 UTC [37140][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-18 14:11:51.730 UTC [37140][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:51.730 UTC [37140][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:51.734 UTC [37148][startup] LOG:  database system was shut down at 2024-03-18 14:11:51 UTC
2024-03-18 14:11:51.741 UTC [37140][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:51.848 UTC [37180][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43570
2024-03-18 14:11:51.850 UTC [37180][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:51.851 UTC [37180][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:51.859 UTC [37180][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert internal error
2024-03-18 14:11:51.872 UTC [37192][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43580
2024-03-18 14:11:51.878 UTC [37192][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-18 14:11:51.878 UTC [37192][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-18 14:11:51.890 UTC [37192][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-18 14:11:51.894 UTC [37192][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=localhost port=43580
2024-03-18 14:11:51.900 UTC [37140][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:51.900 UTC [37140][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:51.904 UTC [37140][postmaster] LOG:  background worker "logical replication launcher" (PID 37152) exited with exit code 1
2024-03-18 14:11:51.909 UTC [37146][checkpointer] LOG:  shutting down
2024-03-18 14:11:51.909 UTC [37146][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:51.910 UTC [37146][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-18 14:11:51.915 UTC [37140][postmaster] LOG:  database system is shut down
2024-03-18 14:11:52.037 UTC [37221][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-18 14:11:52.037 UTC [37221][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:52.037 UTC [37221][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:52.053 UTC [37231][startup] LOG:  database system was shut down at 2024-03-18 14:11:51 UTC
2024-03-18 14:11:52.060 UTC [37221][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:52.116 UTC [37247][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43586
2024-03-18 14:11:52.118 UTC [37247][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:52.118 UTC [37247][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:52.121 UTC [37247][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert internal error
2024-03-18 14:11:52.135 UTC [37252][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43598
2024-03-18 14:11:52.142 UTC [37252][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-18 14:11:52.142 UTC [37252][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-18 14:11:52.156 UTC [37252][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-18 14:11:52.162 UTC [37252][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=localhost port=43598
2024-03-18 14:11:52.170 UTC [37221][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:52.170 UTC [37221][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:52.176 UTC [37221][postmaster] LOG:  background worker "logical replication launcher" (PID 37238) exited with exit code 1
2024-03-18 14:11:52.179 UTC [37229][checkpointer] LOG:  shutting down
2024-03-18 14:11:52.179 UTC [37229][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:52.180 UTC [37229][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-18 14:11:52.185 UTC [37221][postmaster] LOG:  database system is shut down
2024-03-18 14:11:52.298 UTC [37281][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-18 14:11:52.298 UTC [37281][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:52.298 UTC [37281][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:52.301 UTC [37285][startup] LOG:  database system was shut down at 2024-03-18 14:11:52 UTC
2024-03-18 14:11:52.308 UTC [37281][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:52.395 UTC [37309][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43608
2024-03-18 14:11:52.397 UTC [37309][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:52.397 UTC [37309][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-18 14:11:52.429 UTC [37319][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43622
2024-03-18 14:11:52.435 UTC [37319][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-18 14:11:52.435 UTC [37319][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-18 14:11:52.447 UTC [37319][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-18 14:11:52.448 UTC [37319][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=localhost port=43622
2024-03-18 14:11:52.456 UTC [37281][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:52.456 UTC [37281][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:52.460 UTC [37281][postmaster] LOG:  background worker "logical replication launcher" (PID 37289) exited with exit code 1
2024-03-18 14:11:52.465 UTC [37283][checkpointer] LOG:  shutting down
2024-03-18 14:11:52.465 UTC [37283][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:52.465 UTC [37283][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-18 14:11:52.471 UTC [37281][postmaster] LOG:  database system is shut down
2024-03-18 14:11:52.577 UTC [37345][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-18 14:11:52.577 UTC [37345][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:52.577 UTC [37345][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:52.581 UTC [37350][startup] LOG:  database system was shut down at 2024-03-18 14:11:52 UTC
2024-03-18 14:11:52.588 UTC [37345][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:52.666 UTC [37368][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43628
2024-03-18 14:11:52.669 UTC [37368][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:52.669 UTC [37368][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-18 14:11:52.699 UTC [37371][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=43634
2024-03-18 14:11:52.705 UTC [37371][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-18 14:11:52.705 UTC [37371][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-18 14:11:52.717 UTC [37371][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-18 14:11:52.720 UTC [37371][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=localhost port=43634
2024-03-18 14:11:52.730 UTC [37345][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:52.730 UTC [37345][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:52.736 UTC [37345][postmaster] LOG:  background worker "logical replication launcher" (PID 37354) exited with exit code 1
2024-03-18 14:11:52.736 UTC [37348][checkpointer] LOG:  shutting down
2024-03-18 14:11:52.736 UTC [37348][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:52.737 UTC [37348][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-18 14:11:52.742 UTC [37345][postmaster] LOG:  database system is shut down
2024-03-18 14:11:52.853 UTC [37399][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-18 14:11:52.853 UTC [37399][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:52.853 UTC [37399][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:52.858 UTC [37408][startup] LOG:  database system was shut down at 2024-03-18 14:11:52 UTC
2024-03-18 14:11:52.865 UTC [37399][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:52.945 UTC [37434][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52916
2024-03-18 14:11:52.948 UTC [37434][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:52.948 UTC [37434][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-18 14:11:52.993 UTC [37445][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52932
2024-03-18 14:11:53.002 UTC [37445][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-18 14:11:53.002 UTC [37445][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-18 14:11:53.014 UTC [37445][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-18 14:11:53.017 UTC [37445][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=localhost port=52932
2024-03-18 14:11:53.032 UTC [37399][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:53.032 UTC [37399][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:53.041 UTC [37399][postmaster] LOG:  background worker "logical replication launcher" (PID 37413) exited with exit code 1
2024-03-18 14:11:53.042 UTC [37406][checkpointer] LOG:  shutting down
2024-03-18 14:11:53.042 UTC [37406][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:53.042 UTC [37406][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-18 14:11:53.048 UTC [37399][postmaster] LOG:  database system is shut down
2024-03-18 14:11:53.158 UTC [37483][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-18 14:11:53.158 UTC [37483][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:53.158 UTC [37483][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:53.165 UTC [37492][startup] LOG:  database system was shut down at 2024-03-18 14:11:53 UTC
2024-03-18 14:11:53.174 UTC [37483][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:53.249 UTC [37519][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52938
2024-03-18 14:11:53.251 UTC [37519][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:53.252 UTC [37519][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:53.253 UTC [37519][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-18 14:11:53.271 UTC [37525][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52950
2024-03-18 14:11:53.278 UTC [37525][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-18 14:11:53.278 UTC [37525][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-18 14:11:53.290 UTC [37525][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-18 14:11:53.291 UTC [37525][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=localhost port=52950
2024-03-18 14:11:53.298 UTC [37483][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:53.298 UTC [37483][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:53.305 UTC [37483][postmaster] LOG:  background worker "logical replication launcher" (PID 37497) exited with exit code 1
2024-03-18 14:11:53.309 UTC [37490][checkpointer] LOG:  shutting down
2024-03-18 14:11:53.309 UTC [37490][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:53.310 UTC [37490][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-18 14:11:53.316 UTC [37483][postmaster] LOG:  database system is shut down
2024-03-18 14:11:53.431 UTC [37547][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-18 14:11:53.431 UTC [37547][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:53.432 UTC [37547][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:53.437 UTC [37558][startup] LOG:  database system was shut down at 2024-03-18 14:11:53 UTC
2024-03-18 14:11:53.446 UTC [37547][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:53.517 UTC [37581][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52964
2024-03-18 14:11:53.519 UTC [37581][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:53.520 UTC [37581][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:53.525 UTC [37581][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:11:53.535 UTC [37585][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52966
2024-03-18 14:11:53.541 UTC [37585][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-18 14:11:53.541 UTC [37585][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-18 14:11:53.554 UTC [37585][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-18 14:11:53.557 UTC [37585][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=localhost port=52966
2024-03-18 14:11:53.563 UTC [37547][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:53.563 UTC [37547][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:53.574 UTC [37547][postmaster] LOG:  background worker "logical replication launcher" (PID 37564) exited with exit code 1
2024-03-18 14:11:53.575 UTC [37554][checkpointer] LOG:  shutting down
2024-03-18 14:11:53.575 UTC [37554][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:53.575 UTC [37554][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-18 14:11:53.581 UTC [37547][postmaster] LOG:  database system is shut down
2024-03-18 14:11:53.701 UTC [37606][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-18 14:11:53.701 UTC [37606][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:53.701 UTC [37606][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:53.713 UTC [37615][startup] LOG:  database system was shut down at 2024-03-18 14:11:53 UTC
2024-03-18 14:11:53.728 UTC [37606][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:53.782 UTC [37638][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52978
2024-03-18 14:11:53.785 UTC [37638][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:53.785 UTC [37638][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: Resource temporarily unavailable
2024-03-18 14:11:53.806 UTC [37644][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52982
2024-03-18 14:11:53.812 UTC [37644][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-18 14:11:53.812 UTC [37644][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-18 14:11:53.824 UTC [37644][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-18 14:11:53.829 UTC [37644][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=localhost port=52982
2024-03-18 14:11:53.838 UTC [37606][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:53.838 UTC [37606][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:53.843 UTC [37606][postmaster] LOG:  background worker "logical replication launcher" (PID 37623) exited with exit code 1
2024-03-18 14:11:53.851 UTC [37613][checkpointer] LOG:  shutting down
2024-03-18 14:11:53.851 UTC [37613][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:53.852 UTC [37613][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-18 14:11:53.858 UTC [37606][postmaster] LOG:  database system is shut down
2024-03-18 14:11:53.962 UTC [37664][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-18 14:11:53.962 UTC [37664][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 58262
2024-03-18 14:11:53.962 UTC [37664][postmaster] LOG:  listening on Unix socket "/tmp/AvuYQVWY2c/.s.PGSQL.58262"
2024-03-18 14:11:53.972 UTC [37673][startup] LOG:  database system was shut down at 2024-03-18 14:11:53 UTC
2024-03-18 14:11:53.982 UTC [37664][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:11:54.060 UTC [37695][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=52998
2024-03-18 14:11:54.062 UTC [37695][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:54.063 UTC [37695][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:11:54.067 UTC [37695][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert internal error
2024-03-18 14:11:54.078 UTC [37699][not initialized] [[unknown]][:0] LOG:  connection received: host=localhost port=53002
2024-03-18 14:11:54.083 UTC [37699][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-18 14:11:54.084 UTC [37699][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-18 14:11:54.097 UTC [37699][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-18 14:11:54.102 UTC [37699][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=localhost port=53002
2024-03-18 14:11:54.110 UTC [37664][postmaster] LOG:  received fast shutdown request
2024-03-18 14:11:54.110 UTC [37664][postmaster] LOG:  aborting any active transactions
2024-03-18 14:11:54.120 UTC [37664][postmaster] LOG:  background worker "logical replication launcher" (PID 37679) exited with exit code 1
2024-03-18 14:11:54.121 UTC [37671][checkpointer] LOG:  shutting down
2024-03-18 14:11:54.121 UTC [37671][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:11:54.121 UTC [37671][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-18 14:11:54.126 UTC [37664][postmaster] LOG:  database system is shut down
2024-03-18 14:11:54.258 UTC [37722][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-03-18 14:11:54.258 UTC [37722][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[14:11:54.323](0.221s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"