[05:08:01.515](0.118s) # setting up data directory # Checking port 51651 # Found port 51651 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=51651 host=/tmp/yUpAfjW5Sw Log file: /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log [05:08:01.526](0.012s) # 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 30146 [05:08:01.941](0.415s) 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 30480 [05:08:03.150](1.209s) # 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-28 05:08:01.753 UTC [30146][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-28 05:08:01.753 UTC [30146][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:01.787 UTC [30174][startup] LOG: database system was shut down at 2024-03-28 05:06:24 UTC 2024-03-28 05:08:01.793 UTC [30146][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:01.910 UTC [30212][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:01.911 UTC [30212][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-28 05:08:01.911 UTC [30212][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:01.939 UTC [30212][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-28 05:08:01.942 UTC [30212][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=postgres database=postgres host=[local] 2024-03-28 05:08:01.959 UTC [30225][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:01.960 UTC [30225][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-28 05:08:01.960 UTC [30225][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:01.962 UTC [30225][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-28 05:08:01.963 UTC [30225][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.005 UTC [30238][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.006 UTC [30238][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-28 05:08:02.006 UTC [30238][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.012 UTC [30238][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-28 05:08:02.012 UTC [30238][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.059 UTC [30253][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.060 UTC [30253][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-28 05:08:02.060 UTC [30253][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.061 UTC [30253][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-28 05:08:02.063 UTC [30253][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.118 UTC [30262][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.119 UTC [30262][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-28 05:08:02.119 UTC [30262][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.127 UTC [30262][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-28 05:08:02.128 UTC [30262][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.166 UTC [30283][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.167 UTC [30283][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-28 05:08:02.167 UTC [30283][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.169 UTC [30283][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-28 05:08:02.206 UTC [30283][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.039 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.302 UTC [30318][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.303 UTC [30318][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-28 05:08:02.303 UTC [30318][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.305 UTC [30318][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-28 05:08:02.353 UTC [30318][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.051 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.444 UTC [30356][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.445 UTC [30356][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-28 05:08:02.445 UTC [30356][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.447 UTC [30356][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-28 05:08:02.481 UTC [30356][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.042 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.560 UTC [30386][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.561 UTC [30386][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-28 05:08:02.561 UTC [30386][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.570 UTC [30386][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-28 05:08:02.629 UTC [30386][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.070 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.703 UTC [30404][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.704 UTC [30404][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-28 05:08:02.704 UTC [30404][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.710 UTC [30404][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-28 05:08:02.771 UTC [30404][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.069 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.829 UTC [30439][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.829 UTC [30439][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-28 05:08:02.829 UTC [30439][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.831 UTC [30439][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-28 05:08:02.892 UTC [30439][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.063 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.948 UTC [30146][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:02.948 UTC [30146][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:02.952 UTC [30146][postmaster] LOG: background worker "logical replication launcher" (PID 30182) exited with exit code 1 2024-03-28 05:08:02.959 UTC [30170][checkpointer] LOG: shutting down 2024-03-28 05:08:02.959 UTC [30170][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.036 UTC [30170][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.077 s, sync=0.001 s, total=0.077 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414C3F8, redo lsn=0/414C3F8 2024-03-28 05:08:03.047 UTC [30146][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.071 UTC [30480][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-28 05:08:03.071 UTC [30480][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:03.071 UTC [30480][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:03.075 UTC [30483][startup] LOG: database system was shut down at 2024-03-28 05:08:03 UTC 2024-03-28 05:08:03.081 UTC [30480][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:03.169 UTC [30480][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:03.169 UTC [30480][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:03.173 UTC [30480][postmaster] LOG: background worker "logical replication launcher" (PID 30486) exited with exit code 1 2024-03-28 05:08:03.178 UTC [30481][checkpointer] LOG: shutting down 2024-03-28 05:08:03.178 UTC [30481][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.178 UTC [30481][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/414C470, redo lsn=0/414C470 2024-03-28 05:08:03.183 UTC [30480][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.354 UTC [30521][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-28 05:08:03.354 UTC [30521][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:08:03.371](0.221s) 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 30539 [05:08:03.476](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-28 05:08:01.753 UTC [30146][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-28 05:08:01.753 UTC [30146][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:01.787 UTC [30174][startup] LOG: database system was shut down at 2024-03-28 05:06:24 UTC 2024-03-28 05:08:01.793 UTC [30146][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:01.910 UTC [30212][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:01.911 UTC [30212][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-28 05:08:01.911 UTC [30212][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:01.939 UTC [30212][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-28 05:08:01.942 UTC [30212][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=postgres database=postgres host=[local] 2024-03-28 05:08:01.959 UTC [30225][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:01.960 UTC [30225][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-28 05:08:01.960 UTC [30225][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:01.962 UTC [30225][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-28 05:08:01.963 UTC [30225][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.005 UTC [30238][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.006 UTC [30238][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-28 05:08:02.006 UTC [30238][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.012 UTC [30238][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-28 05:08:02.012 UTC [30238][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.059 UTC [30253][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.060 UTC [30253][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-28 05:08:02.060 UTC [30253][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.061 UTC [30253][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-28 05:08:02.063 UTC [30253][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.118 UTC [30262][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.119 UTC [30262][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-28 05:08:02.119 UTC [30262][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.127 UTC [30262][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-28 05:08:02.128 UTC [30262][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.166 UTC [30283][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.167 UTC [30283][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-28 05:08:02.167 UTC [30283][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.169 UTC [30283][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-28 05:08:02.206 UTC [30283][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.039 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.302 UTC [30318][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.303 UTC [30318][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-28 05:08:02.303 UTC [30318][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.305 UTC [30318][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-28 05:08:02.353 UTC [30318][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.051 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.444 UTC [30356][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.445 UTC [30356][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-28 05:08:02.445 UTC [30356][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.447 UTC [30356][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-28 05:08:02.481 UTC [30356][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.042 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.560 UTC [30386][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.561 UTC [30386][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-28 05:08:02.561 UTC [30386][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.570 UTC [30386][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-28 05:08:02.629 UTC [30386][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.070 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.703 UTC [30404][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.704 UTC [30404][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-28 05:08:02.704 UTC [30404][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.710 UTC [30404][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-28 05:08:02.771 UTC [30404][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.069 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.829 UTC [30439][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.829 UTC [30439][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-28 05:08:02.829 UTC [30439][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.831 UTC [30439][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-28 05:08:02.892 UTC [30439][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.063 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.948 UTC [30146][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:02.948 UTC [30146][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:02.952 UTC [30146][postmaster] LOG: background worker "logical replication launcher" (PID 30182) exited with exit code 1 2024-03-28 05:08:02.959 UTC [30170][checkpointer] LOG: shutting down 2024-03-28 05:08:02.959 UTC [30170][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.036 UTC [30170][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.077 s, sync=0.001 s, total=0.077 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414C3F8, redo lsn=0/414C3F8 2024-03-28 05:08:03.047 UTC [30146][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.071 UTC [30480][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-28 05:08:03.071 UTC [30480][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:03.071 UTC [30480][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:03.075 UTC [30483][startup] LOG: database system was shut down at 2024-03-28 05:08:03 UTC 2024-03-28 05:08:03.081 UTC [30480][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:03.169 UTC [30480][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:03.169 UTC [30480][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:03.173 UTC [30480][postmaster] LOG: background worker "logical replication launcher" (PID 30486) exited with exit code 1 2024-03-28 05:08:03.178 UTC [30481][checkpointer] LOG: shutting down 2024-03-28 05:08:03.178 UTC [30481][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.178 UTC [30481][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/414C470, redo lsn=0/414C470 2024-03-28 05:08:03.183 UTC [30480][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.354 UTC [30521][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-28 05:08:03.354 UTC [30521][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.432 UTC [30539][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-28 05:08:03.432 UTC [30539][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:03.432 UTC [30539][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:03.436 UTC [30547][startup] LOG: database system was shut down at 2024-03-28 05:08:03 UTC 2024-03-28 05:08:03.444 UTC [30539][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:03.484 UTC [30539][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:03.484 UTC [30539][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:03.489 UTC [30539][postmaster] LOG: background worker "logical replication launcher" (PID 30550) exited with exit code 1 2024-03-28 05:08:03.500 UTC [30545][checkpointer] LOG: shutting down 2024-03-28 05:08:03.500 UTC [30545][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.500 UTC [30545][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/414C4E8, redo lsn=0/414C4E8 2024-03-28 05:08:03.505 UTC [30539][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.645 UTC [30568][postmaster] FATAL: could not set SSL protocol version range 2024-03-28 05:08:03.645 UTC [30568][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-28 05:08:03.645 UTC [30568][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:08:03.688](0.211s) 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 30590 [05:08:03.807](0.119s) ok 5 - restart succeeds with correct SSL protocol bounds [05:08:03.807](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 30623 [05:08:04.046](0.239s) ok 6 - server doesn't accept non-SSL connections [05:08:04.046](0.000s) ok 7 - server doesn't accept non-SSL connections: matches [05:08:04.080](0.033s) ok 8 - connect without server root cert sslmode=require [05:08:04.080](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr [05:08:04.104](0.024s) ok 10 - connect without server root cert sslmode=verify-ca [05:08:04.104](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches [05:08:04.129](0.025s) ok 12 - connect without server root cert sslmode=verify-full [05:08:04.129](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches [05:08:04.200](0.071s) ok 14 - connect with wrong server root cert sslmode=require [05:08:04.200](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches [05:08:04.219](0.019s) ok 16 - connect with wrong server root cert sslmode=verify-ca [05:08:04.219](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [05:08:04.260](0.041s) ok 18 - connect with wrong server root cert sslmode=verify-full [05:08:04.260](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [05:08:04.291](0.030s) ok 20 - connect with server CA cert, without root CA [05:08:04.291](0.000s) ok 21 - connect with server CA cert, without root CA: matches [05:08:04.314](0.023s) ok 22 - connect with correct server CA cert file sslmode=require [05:08:04.314](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [05:08:04.341](0.026s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [05:08:04.341](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [05:08:04.366](0.025s) ok 26 - connect with correct server CA cert file sslmode=verify-full [05:08:04.366](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [05:08:04.404](0.037s) ok 28 - cert root file that contains two certificates, order 1 [05:08:04.404](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr [05:08:04.436](0.032s) ok 30 - cert root file that contains two certificates, order 2 [05:08:04.436](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr [05:08:04.461](0.025s) ok 32 - connect with sslcertmode=disable [05:08:04.461](0.000s) ok 33 - connect with sslcertmode=disable: no stderr [05:08:04.517](0.055s) ok 34 - connect with sslcertmode=allow [05:08:04.517](0.000s) ok 35 - connect with sslcertmode=allow: no stderr [05:08:04.556](0.039s) ok 36 - connect with sslcertmode=require fails without a client certificate [05:08:04.556](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [05:08:04.577](0.021s) ok 38 - sslcrl option with invalid file name [05:08:04.577](0.000s) ok 39 - sslcrl option with invalid file name: no stderr [05:08:04.600](0.023s) ok 40 - CRL belonging to a different CA [05:08:04.600](0.000s) ok 41 - CRL belonging to a different CA: matches [05:08:04.622](0.023s) ok 42 - directory CRL belonging to a different CA [05:08:04.623](0.000s) ok 43 - directory CRL belonging to a different CA: matches [05:08:04.667](0.044s) ok 44 - CRL with a non-revoked cert [05:08:04.667](0.000s) ok 45 - CRL with a non-revoked cert: no stderr [05:08:04.691](0.024s) ok 46 - directory CRL with a non-revoked cert [05:08:04.691](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr [05:08:04.742](0.051s) ok 48 - mismatch between host name and server certificate sslmode=require [05:08:04.742](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [05:08:04.800](0.058s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [05:08:04.800](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [05:08:05.339](0.539s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [05:08:05.339](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 30931 [05:08:05.605](0.266s) ok 54 - IP address in the Common Name [05:08:05.605](0.000s) ok 55 - IP address in the Common Name: no stderr [05:08:05.638](0.032s) ok 56 - mismatch between host name and server certificate IP address [05:08:05.638](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 31010 [05:08:05.888](0.250s) ok 58 - IP address in a dNSName [05:08:05.888](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 31099 [05:08:06.254](0.366s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [05:08:06.254](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [05:08:06.290](0.036s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [05:08:06.290](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [05:08:06.323](0.033s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [05:08:06.323](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [05:08:06.372](0.049s) ok 66 - host name not matching with X.509 Subject Alternative Names [05:08:06.372](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [05:08:06.419](0.046s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [05:08:06.419](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 31220 [05:08:06.688](0.268s) ok 70 - host name matching with a single X.509 Subject Alternative Name [05:08:06.688](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [05:08:06.752](0.064s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [05:08:06.752](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [05:08:06.809](0.057s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [05:08:06.809](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 31319 [05:08:07.144](0.335s) ok 76 - host matching an IPv4 address (Subject Alternative Name 1) [05:08:07.144](0.000s) ok 77 - host matching an IPv4 address (Subject Alternative Name 1): no stderr [05:08:07.189](0.045s) ok 78 - host matching an IPv4 address in alternate form (Subject Alternative Name 1) [05:08:07.189](0.000s) ok 79 - host matching an IPv4 address in alternate form (Subject Alternative Name 1): no stderr [05:08:07.234](0.044s) ok 80 - host not matching an IPv4 address (Subject Alternative Name 1) [05:08:07.234](0.000s) ok 81 - host not matching an IPv4 address (Subject Alternative Name 1): matches [05:08:07.277](0.043s) ok 82 - host matching an IPv6 address (Subject Alternative Name 2) [05:08:07.277](0.000s) ok 83 - host matching an IPv6 address (Subject Alternative Name 2): no stderr [05:08:07.325](0.048s) ok 84 - host matching an IPv6 address in alternate form (Subject Alternative Name 2) [05:08:07.325](0.000s) ok 85 - host matching an IPv6 address in alternate form (Subject Alternative Name 2): no stderr [05:08:07.387](0.062s) ok 86 - host matching an IPv6 address in mixed form (Subject Alternative Name 2) [05:08:07.387](0.000s) ok 87 - host matching an IPv6 address in mixed form (Subject Alternative Name 2): no stderr [05:08:07.448](0.061s) ok 88 - host not matching an IPv6 address (Subject Alternative Name 2) [05:08:07.449](0.000s) ok 89 - host not matching an IPv6 address (Subject Alternative Name 2): matches [05:08:07.480](0.031s) ok 90 - IPv6 host with CIDR mask does not match [05:08:07.480](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 31424 [05:08:07.757](0.277s) ok 92 - certificate with both a CN and SANs 1 [05:08:07.757](0.000s) ok 93 - certificate with both a CN and SANs 1: no stderr [05:08:07.803](0.046s) ok 94 - certificate with both a CN and SANs 2 [05:08:07.803](0.000s) ok 95 - certificate with both a CN and SANs 2: no stderr [05:08:07.838](0.035s) ok 96 - certificate with both a CN and SANs ignores CN [05:08:07.838](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 31479 [05:08:08.152](0.313s) ok 98 - certificate with both a CN and IP SANs matches CN [05:08:08.152](0.000s) ok 99 - certificate with both a CN and IP SANs matches CN: no stderr [05:08:08.201](0.049s) ok 100 - certificate with both a CN and IP SANs matches SAN 1 [05:08:08.202](0.000s) ok 101 - certificate with both a CN and IP SANs matches SAN 1: no stderr [05:08:08.239](0.037s) ok 102 - certificate with both a CN and IP SANs matches SAN 2 [05:08:08.239](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 31588 [05:08:08.535](0.296s) ok 104 - certificate with both an IP CN and IP SANs 1 [05:08:08.535](0.000s) ok 105 - certificate with both an IP CN and IP SANs 1: no stderr [05:08:08.584](0.049s) ok 106 - certificate with both an IP CN and IP SANs 2 [05:08:08.584](0.000s) ok 107 - certificate with both an IP CN and IP SANs 2: no stderr [05:08:08.634](0.049s) ok 108 - certificate with both an IP CN and IP SANs ignores CN [05:08:08.634](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 31669 [05:08:08.927](0.293s) ok 110 - certificate with both an IP CN and DNS SANs matches CN [05:08:08.927](0.000s) ok 111 - certificate with both an IP CN and DNS SANs matches CN: no stderr [05:08:08.971](0.044s) ok 112 - certificate with both an IP CN and DNS SANs matches SAN 1 [05:08:08.971](0.000s) ok 113 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [05:08:09.010](0.039s) ok 114 - certificate with both an IP CN and DNS SANs matches SAN 2 [05:08:09.010](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 31744 [05:08:09.287](0.277s) ok 116 - server certificate without CN or SANs sslmode=verify-ca [05:08:09.287](0.000s) ok 117 - server certificate without CN or SANs sslmode=verify-ca: no stderr [05:08:09.329](0.041s) ok 118 - server certificate without CN or SANs sslmode=verify-full [05:08:09.329](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 31814 [05:08:09.572](0.243s) ok 120 - sslrootcert=system does not connect with private CA [05:08:09.572](0.000s) ok 121 - sslrootcert=system does not connect with private CA: matches [05:08:09.592](0.020s) ok 122 - sslrootcert=system only accepts sslmode=verify-full [05:08:09.592](0.000s) ok 123 - sslrootcert=system only accepts sslmode=verify-full: matches [05:08:09.675](0.083s) ok 124 - sslrootcert=system connects with overridden SSL_CERT_FILE [05:08:09.675](0.000s) ok 125 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [05:08:09.715](0.040s) ok 126 - sslrootcert=system defaults to sslmode=verify-full [05:08:09.716](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 31903 [05:08:10.016](0.300s) ok 128 - connects without client-side CRL [05:08:10.016](0.000s) ok 129 - connects without client-side CRL: no stderr [05:08:10.040](0.024s) ok 130 - does not connect with client-side CRL file [05:08:10.040](0.000s) ok 131 - does not connect with client-side CRL file: matches [05:08:10.076](0.036s) ok 132 - does not connect with client-side CRL directory [05:08:10.076](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() [05:08:10.110](0.034s) ok 134 - pg_stat_ssl view without client certificate: exit code 0 [05:08:10.111](0.000s) ok 135 - pg_stat_ssl view without client certificate: no stderr [05:08:10.111](0.000s) ok 136 - pg_stat_ssl view without client certificate: matches [05:08:10.163](0.052s) ok 137 - connection success with correct range of TLS protocol versions [05:08:10.163](0.000s) ok 138 - connection success with correct range of TLS protocol versions: no stderr [05:08:10.173](0.010s) ok 139 - connection failure with incorrect range of TLS protocol versions [05:08:10.173](0.000s) ok 140 - connection failure with incorrect range of TLS protocol versions: matches [05:08:10.201](0.028s) ok 141 - connection failure with an incorrect SSL protocol minimum bound [05:08:10.201](0.000s) ok 142 - connection failure with an incorrect SSL protocol minimum bound: matches [05:08:10.211](0.010s) ok 143 - connection failure with an incorrect SSL protocol maximum bound [05:08:10.212](0.000s) ok 144 - connection failure with an incorrect SSL protocol maximum bound: matches [05:08:10.212](0.000s) # running server tests [05:08:10.255](0.043s) ok 145 - certificate authorization fails without client cert [05:08:10.255](0.000s) ok 146 - certificate authorization fails without client cert: matches [05:08:10.296](0.041s) ok 147 - certificate authorization succeeds with correct client cert in PEM format [05:08:10.296](0.000s) ok 148 - certificate authorization succeeds with correct client cert in PEM format: no stderr [05:08:10.344](0.048s) ok 149 - certificate authorization succeeds with correct client cert in DER format [05:08:10.345](0.000s) ok 150 - certificate authorization succeeds with correct client cert in DER format: no stderr [05:08:10.410](0.066s) ok 151 - certificate authorization succeeds with correct client cert in encrypted PEM format [05:08:10.411](0.000s) ok 152 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [05:08:10.446](0.036s) ok 153 - certificate authorization succeeds with correct client cert in encrypted DER format [05:08:10.447](0.000s) ok 154 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [05:08:10.480](0.034s) ok 155 - certificate authorization succeeds with correct client cert and sslcertmode=require [05:08:10.481](0.000s) ok 156 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [05:08:10.518](0.038s) ok 157 - certificate authorization succeeds with correct client cert and sslcertmode=allow [05:08:10.519](0.000s) ok 158 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [05:08:10.559](0.040s) ok 159 - certificate authorization fails with correct client cert and sslcertmode=disable [05:08:10.559](0.000s) ok 160 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [05:08:10.600](0.041s) ok 161 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [05:08:10.600](0.000s) ok 162 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [05:08:10.669](0.069s) ok 163 - certificate authorization succeeds with DN mapping [05:08:10.669](0.000s) ok 164 - certificate authorization succeeds with DN mapping: no stderr [05:08:10.670](0.000s) ok 165 - certificate authorization succeeds with DN mapping: log matches [05:08:10.712](0.042s) ok 166 - certificate authorization succeeds with DN regex mapping [05:08:10.712](0.000s) ok 167 - certificate authorization succeeds with DN regex mapping: no stderr [05:08:10.758](0.046s) ok 168 - certificate authorization succeeds with CN mapping [05:08:10.758](0.000s) ok 169 - certificate authorization succeeds with CN mapping: no stderr [05:08:10.758](0.000s) ok 170 - certificate authorization succeeds with CN mapping: log matches [05:08:10.759](0.000s) not ok 171 # TODO & SKIP Need Pty support [05:08:10.759](0.000s) not ok 172 # TODO & SKIP Need Pty support [05:08:10.759](0.000s) not ok 173 # TODO & SKIP Need Pty support [05:08:10.759](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__Kri/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [05:08:10.801](0.042s) ok 175 - pg_stat_ssl with client certificate: exit code 0 [05:08:10.801](0.000s) ok 176 - pg_stat_ssl with client certificate: no stderr [05:08:10.801](0.000s) ok 177 - pg_stat_ssl with client certificate: matches [05:08:10.828](0.027s) ok 178 - certificate authorization fails because of file permissions [05:08:10.829](0.000s) ok 179 - certificate authorization fails because of file permissions: matches [05:08:10.862](0.033s) ok 180 - certificate authorization fails with client cert belonging to another user [05:08:10.862](0.000s) ok 181 - certificate authorization fails with client cert belonging to another user: matches [05:08:10.904](0.042s) ok 182 - certificate authorization fails with revoked client cert [05:08:10.904](0.000s) ok 183 - certificate authorization fails with revoked client cert: matches [05:08:10.904](0.000s) ok 184 - certificate authorization fails with revoked client cert: log does not match [05:08:10.945](0.041s) ok 185 - auth_option clientcert=verify-full succeeds with matching username and Common Name [05:08:10.946](0.000s) ok 186 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [05:08:10.946](0.000s) ok 187 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [05:08:11.008](0.062s) ok 188 - auth_option clientcert=verify-full fails with mismatching username and Common Name [05:08:11.008](0.000s) ok 189 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [05:08:11.009](0.000s) ok 190 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [05:08:11.056](0.047s) ok 191 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [05:08:11.056](0.000s) ok 192 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [05:08:11.057](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 32199 [05:08:11.342](0.285s) ok 194 - intermediate client certificate is provided by client [05:08:11.342](0.000s) ok 195 - intermediate client certificate is provided by client: no stderr [05:08:11.382](0.040s) ok 196 - intermediate client certificate is missing [05:08:11.382](0.000s) ok 197 - intermediate client certificate is missing: matches [05:08:11.413](0.031s) ok 198 - logged client certificate Subjects are truncated if they're too long [05:08:11.413](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 32282 [05:08:11.659](0.246s) ok 200 - intermediate client certificate is untrusted [05:08:11.659](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 32332 [05:08:11.928](0.269s) ok 202 - certificate authorization fails with revoked client cert with server-side CRL directory [05:08:11.928](0.000s) ok 203 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [05:08:12.073](0.145s) ok 204 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [05:08:12.074](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 32438 [05:08:12.447](0.373s) not ok 206 - connect with valid stapled ocsp response when sslocspstapling=1 [05:08:12.447](0.000s) [05:08:12.447](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at t/001_ssltests.pl line 923. [05:08:12.447](0.000s) # got: '2' # expected: '0' [05:08:12.447](0.000s) not ok 207 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [05:08:12.447](0.000s) [05:08:12.447](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at t/001_ssltests.pl line 923. [05:08:12.447](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 51651 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: '' [05:08:12.516](0.068s) ok 208 - connect without requesting ocsp response when sslocspstapling=0 [05:08:12.516](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 32512 [05:08:12.789](0.273s) ok 210 - failed with a revoked ocsp response when sslocspstapling=1 [05:08:12.868](0.079s) ok 211 - connect without requesting ocsp response when sslocspstapling=0 [05:08:12.868](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 32563 [05:08:13.139](0.271s) ok 213 - failed with a revoked ocsp response when sslocspstapling=1 [05:08:13.224](0.085s) ok 214 - connect without requesting ocsp response when sslocspstapling=0 [05:08:13.225](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 32641 [05:08:13.461](0.236s) ok 216 - failed with an expired ocsp response when sslocspstapling=1 [05:08:13.520](0.059s) ok 217 - connect without requesting ocsp response when sslocspstapling=0 [05:08:13.520](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 32775 [05:08:13.992](0.472s) not ok 219 - connect with valid stapled ocsp response when sslocspstapling=1 [05:08:13.993](0.000s) [05:08:13.993](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at t/001_ssltests.pl line 1001. [05:08:13.993](0.000s) # got: '2' # expected: '0' [05:08:13.993](0.000s) not ok 220 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [05:08:13.993](0.000s) [05:08:13.993](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at t/001_ssltests.pl line 1001. [05:08:13.993](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 51651 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: '' [05:08:14.091](0.098s) ok 221 - connect without requesting ocsp response when sslocspstapling=0 [05:08:14.092](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 32830 [05:08:14.283](0.192s) ok 223 - failed with a revoked ocsp response when sslocspstapling=1 [05:08:14.349](0.066s) ok 224 - connect without requesting ocsp response when sslocspstapling=0 [05:08:14.349](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 32857 [05:08:14.722](0.372s) ok 226 - failed with a revoked ocsp response when sslocspstapling=1 [05:08:14.827](0.105s) ok 227 - connect without requesting ocsp response when sslocspstapling=0 [05:08:14.827](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 32906 [05:08:15.111](0.284s) ok 229 - failed with an expired ocsp response when sslocspstapling=1 [05:08:15.178](0.067s) ok 230 - connect without requesting ocsp response when sslocspstapling=0 [05:08:15.178](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 32965 [05:08:15.435](0.256s) ok 232 - failed with an expired ocsp response when sslocspstapling=1 [05:08:15.511](0.077s) ok 233 - connect without requesting ocsp response when sslocspstapling=0 [05:08:15.511](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-28 05:08:01.753 UTC [30146][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-28 05:08:01.753 UTC [30146][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:01.787 UTC [30174][startup] LOG: database system was shut down at 2024-03-28 05:06:24 UTC 2024-03-28 05:08:01.793 UTC [30146][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:01.910 UTC [30212][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:01.911 UTC [30212][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-28 05:08:01.911 UTC [30212][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:01.939 UTC [30212][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-28 05:08:01.942 UTC [30212][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=postgres database=postgres host=[local] 2024-03-28 05:08:01.959 UTC [30225][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:01.960 UTC [30225][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-28 05:08:01.960 UTC [30225][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:01.962 UTC [30225][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-28 05:08:01.963 UTC [30225][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.005 UTC [30238][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.006 UTC [30238][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-28 05:08:02.006 UTC [30238][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.012 UTC [30238][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-28 05:08:02.012 UTC [30238][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.059 UTC [30253][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.060 UTC [30253][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-28 05:08:02.060 UTC [30253][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.061 UTC [30253][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-28 05:08:02.063 UTC [30253][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.118 UTC [30262][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.119 UTC [30262][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-28 05:08:02.119 UTC [30262][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.127 UTC [30262][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-28 05:08:02.128 UTC [30262][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.166 UTC [30283][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.167 UTC [30283][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-28 05:08:02.167 UTC [30283][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.169 UTC [30283][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-28 05:08:02.206 UTC [30283][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.039 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.302 UTC [30318][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.303 UTC [30318][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-28 05:08:02.303 UTC [30318][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.305 UTC [30318][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-28 05:08:02.353 UTC [30318][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.051 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.444 UTC [30356][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.445 UTC [30356][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-28 05:08:02.445 UTC [30356][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.447 UTC [30356][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-28 05:08:02.481 UTC [30356][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.042 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.560 UTC [30386][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.561 UTC [30386][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-28 05:08:02.561 UTC [30386][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.570 UTC [30386][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-28 05:08:02.629 UTC [30386][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.070 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.703 UTC [30404][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.704 UTC [30404][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-28 05:08:02.704 UTC [30404][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.710 UTC [30404][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-28 05:08:02.771 UTC [30404][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.069 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.829 UTC [30439][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:08:02.829 UTC [30439][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-28 05:08:02.829 UTC [30439][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-28 05:08:02.831 UTC [30439][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-28 05:08:02.892 UTC [30439][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.063 user=postgres database=postgres host=[local] 2024-03-28 05:08:02.948 UTC [30146][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:02.948 UTC [30146][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:02.952 UTC [30146][postmaster] LOG: background worker "logical replication launcher" (PID 30182) exited with exit code 1 2024-03-28 05:08:02.959 UTC [30170][checkpointer] LOG: shutting down 2024-03-28 05:08:02.959 UTC [30170][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.036 UTC [30170][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.077 s, sync=0.001 s, total=0.077 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414C3F8, redo lsn=0/414C3F8 2024-03-28 05:08:03.047 UTC [30146][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.071 UTC [30480][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-28 05:08:03.071 UTC [30480][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:03.071 UTC [30480][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:03.075 UTC [30483][startup] LOG: database system was shut down at 2024-03-28 05:08:03 UTC 2024-03-28 05:08:03.081 UTC [30480][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:03.169 UTC [30480][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:03.169 UTC [30480][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:03.173 UTC [30480][postmaster] LOG: background worker "logical replication launcher" (PID 30486) exited with exit code 1 2024-03-28 05:08:03.178 UTC [30481][checkpointer] LOG: shutting down 2024-03-28 05:08:03.178 UTC [30481][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.178 UTC [30481][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/414C470, redo lsn=0/414C470 2024-03-28 05:08:03.183 UTC [30480][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.354 UTC [30521][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-28 05:08:03.354 UTC [30521][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.432 UTC [30539][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-28 05:08:03.432 UTC [30539][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:03.432 UTC [30539][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:03.436 UTC [30547][startup] LOG: database system was shut down at 2024-03-28 05:08:03 UTC 2024-03-28 05:08:03.444 UTC [30539][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:03.484 UTC [30539][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:03.484 UTC [30539][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:03.489 UTC [30539][postmaster] LOG: background worker "logical replication launcher" (PID 30550) exited with exit code 1 2024-03-28 05:08:03.500 UTC [30545][checkpointer] LOG: shutting down 2024-03-28 05:08:03.500 UTC [30545][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.500 UTC [30545][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/414C4E8, redo lsn=0/414C4E8 2024-03-28 05:08:03.505 UTC [30539][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.645 UTC [30568][postmaster] FATAL: could not set SSL protocol version range 2024-03-28 05:08:03.645 UTC [30568][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-28 05:08:03.645 UTC [30568][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.774 UTC [30590][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-28 05:08:03.774 UTC [30590][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:03.774 UTC [30590][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:03.795 UTC [30605][startup] LOG: database system was shut down at 2024-03-28 05:08:03 UTC 2024-03-28 05:08:03.803 UTC [30590][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:03.812 UTC [30590][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:03.812 UTC [30590][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:03.820 UTC [30590][postmaster] LOG: background worker "logical replication launcher" (PID 30612) exited with exit code 1 2024-03-28 05:08:03.835 UTC [30603][checkpointer] LOG: shutting down 2024-03-28 05:08:03.836 UTC [30603][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:03.838 UTC [30603][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/414C560, redo lsn=0/414C560 2024-03-28 05:08:03.844 UTC [30590][postmaster] LOG: database system is shut down 2024-03-28 05:08:03.946 UTC [30623][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-28 05:08:03.946 UTC [30623][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:03.946 UTC [30623][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:04.003 UTC [30642][startup] LOG: database system was shut down at 2024-03-28 05:08:03 UTC 2024-03-28 05:08:04.010 UTC [30623][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:04.043 UTC [30657][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60112 2024-03-28 05:08:04.044 UTC [30657][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-28 05:08:04.044 UTC [30657][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "localhost", forward lookup not checked. 2024-03-28 05:08:04.057 UTC [30666][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60120 2024-03-28 05:08:04.064 UTC [30666][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-28 05:08:04.064 UTC [30666][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-28 05:08:04.076 UTC [30666][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-28 05:08:04.081 UTC [30666][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=localhost port=60120 2024-03-28 05:08:04.099 UTC [30672][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60134 2024-03-28 05:08:04.105 UTC [30672][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:08:04.124 UTC [30682][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60148 2024-03-28 05:08:04.131 UTC [30682][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:08:04.143 UTC [30686][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60160 2024-03-28 05:08:04.196 UTC [30686][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:08:04.211 UTC [30690][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60166 2024-03-28 05:08:04.218 UTC [30690][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:08:04.241 UTC [30699][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60172 2024-03-28 05:08:04.251 UTC [30699][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:08:04.283 UTC [30705][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60180 2024-03-28 05:08:04.290 UTC [30705][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:08:04.303 UTC [30710][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60182 2024-03-28 05:08:04.309 UTC [30710][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-28 05:08:04.309 UTC [30710][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-28 05:08:04.311 UTC [30710][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-28 05:08:04.313 UTC [30710][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=60182 2024-03-28 05:08:04.326 UTC [30712][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60186 2024-03-28 05:08:04.336 UTC [30712][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-28 05:08:04.336 UTC [30712][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-28 05:08:04.337 UTC [30712][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-28 05:08:04.340 UTC [30712][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=trustdb host=localhost port=60186 2024-03-28 05:08:04.354 UTC [30716][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60192 2024-03-28 05:08:04.361 UTC [30716][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-28 05:08:04.361 UTC [30716][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-28 05:08:04.363 UTC [30716][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-28 05:08:04.366 UTC [30716][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=60192 2024-03-28 05:08:04.386 UTC [30722][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60196 2024-03-28 05:08:04.396 UTC [30722][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-28 05:08:04.396 UTC [30722][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-28 05:08:04.397 UTC [30722][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-28 05:08:04.398 UTC [30722][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=60196 2024-03-28 05:08:04.423 UTC [30730][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60204 2024-03-28 05:08:04.431 UTC [30730][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-28 05:08:04.431 UTC [30730][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-28 05:08:04.432 UTC [30730][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-28 05:08:04.436 UTC [30730][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=ssltestuser database=trustdb host=localhost port=60204 2024-03-28 05:08:04.446 UTC [30741][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60210 2024-03-28 05:08:04.456 UTC [30741][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-28 05:08:04.456 UTC [30741][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-28 05:08:04.457 UTC [30741][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-28 05:08:04.461 UTC [30741][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.015 user=ssltestuser database=trustdb host=localhost port=60210 2024-03-28 05:08:04.501 UTC [30750][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60224 2024-03-28 05:08:04.511 UTC [30750][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-28 05:08:04.512 UTC [30750][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-28 05:08:04.513 UTC [30750][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-28 05:08:04.514 UTC [30750][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=trustdb host=localhost port=60224 2024-03-28 05:08:04.538 UTC [30760][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60226 2024-03-28 05:08:04.549 UTC [30760][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-28 05:08:04.549 UTC [30760][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-28 05:08:04.553 UTC [30760][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.015 user=ssltestuser database=trustdb host=localhost port=60226 2024-03-28 05:08:04.566 UTC [30772][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60232 2024-03-28 05:08:04.572 UTC [30772][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-28 05:08:04.572 UTC [30772][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-28 05:08:04.573 UTC [30772][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-28 05:08:04.574 UTC [30772][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=ssltestuser database=trustdb host=localhost port=60232 2024-03-28 05:08:04.586 UTC [30775][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60234 2024-03-28 05:08:04.599 UTC [30775][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:08:04.614 UTC [30780][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60250 2024-03-28 05:08:04.622 UTC [30780][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:08:04.648 UTC [30783][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60252 2024-03-28 05:08:04.657 UTC [30783][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-28 05:08:04.657 UTC [30783][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-28 05:08:04.658 UTC [30783][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-28 05:08:04.661 UTC [30783][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=60252 2024-03-28 05:08:04.677 UTC [30787][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60264 2024-03-28 05:08:04.685 UTC [30787][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-28 05:08:04.685 UTC [30787][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-28 05:08:04.687 UTC [30787][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-28 05:08:04.690 UTC [30787][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=60264 2024-03-28 05:08:04.717 UTC [30794][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60278 2024-03-28 05:08:04.727 UTC [30794][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-28 05:08:04.727 UTC [30794][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-28 05:08:04.738 UTC [30794][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-28 05:08:04.744 UTC [30794][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=localhost port=60278 2024-03-28 05:08:04.777 UTC [30804][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60290 2024-03-28 05:08:04.790 UTC [30804][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-28 05:08:04.790 UTC [30804][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-28 05:08:04.792 UTC [30804][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-28 05:08:04.793 UTC [30804][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=60290 2024-03-28 05:08:04.823 UTC [30817][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60302 2024-03-28 05:08:05.349 UTC [30623][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:05.349 UTC [30623][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:05.354 UTC [30623][postmaster] LOG: background worker "logical replication launcher" (PID 30648) exited with exit code 1 2024-03-28 05:08:05.363 UTC [30639][checkpointer] LOG: shutting down 2024-03-28 05:08:05.363 UTC [30639][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:05.363 UTC [30639][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/414C5D8, redo lsn=0/414C5D8 2024-03-28 05:08:05.379 UTC [30623][postmaster] LOG: database system is shut down 2024-03-28 05:08:05.474 UTC [30931][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-28 05:08:05.474 UTC [30931][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:05.475 UTC [30931][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:05.480 UTC [30937][startup] LOG: database system was shut down at 2024-03-28 05:08:05 UTC 2024-03-28 05:08:05.487 UTC [30931][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:05.569 UTC [30956][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60308 2024-03-28 05:08:05.585 UTC [30956][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-28 05:08:05.585 UTC [30956][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-28 05:08:05.601 UTC [30956][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-28 05:08:05.603 UTC [30956][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=localhost port=60308 2024-03-28 05:08:05.629 UTC [30974][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60314 2024-03-28 05:08:05.645 UTC [30931][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:05.645 UTC [30931][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:05.652 UTC [30931][postmaster] LOG: background worker "logical replication launcher" (PID 30940) exited with exit code 1 2024-03-28 05:08:05.653 UTC [30934][checkpointer] LOG: shutting down 2024-03-28 05:08:05.653 UTC [30934][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:05.654 UTC [30934][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/414C650, redo lsn=0/414C650 2024-03-28 05:08:05.659 UTC [30931][postmaster] LOG: database system is shut down 2024-03-28 05:08:05.804 UTC [31010][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-28 05:08:05.804 UTC [31010][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:05.805 UTC [31010][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:05.819 UTC [31032][startup] LOG: database system was shut down at 2024-03-28 05:08:05 UTC 2024-03-28 05:08:05.829 UTC [31010][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:05.866 UTC [31055][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60316 2024-03-28 05:08:05.873 UTC [31055][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-28 05:08:05.873 UTC [31055][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-28 05:08:05.884 UTC [31055][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-28 05:08:05.889 UTC [31055][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=60316 2024-03-28 05:08:05.896 UTC [31010][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:05.897 UTC [31010][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:05.900 UTC [31010][postmaster] LOG: background worker "logical replication launcher" (PID 31042) exited with exit code 1 2024-03-28 05:08:05.908 UTC [31026][checkpointer] LOG: shutting down 2024-03-28 05:08:05.908 UTC [31026][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:05.908 UTC [31026][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/414C6C8, redo lsn=0/414C6C8 2024-03-28 05:08:05.914 UTC [31010][postmaster] LOG: database system is shut down 2024-03-28 05:08:06.071 UTC [31099][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-28 05:08:06.071 UTC [31099][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:06.071 UTC [31099][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:06.094 UTC [31119][startup] LOG: database system was shut down at 2024-03-28 05:08:05 UTC 2024-03-28 05:08:06.104 UTC [31099][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:06.228 UTC [31141][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60324 2024-03-28 05:08:06.233 UTC [31141][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-28 05:08:06.233 UTC [31141][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-28 05:08:06.250 UTC [31141][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-28 05:08:06.256 UTC [31141][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=localhost port=60324 2024-03-28 05:08:06.275 UTC [31149][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60336 2024-03-28 05:08:06.282 UTC [31149][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-28 05:08:06.282 UTC [31149][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-28 05:08:06.284 UTC [31149][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-28 05:08:06.287 UTC [31149][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=60336 2024-03-28 05:08:06.312 UTC [31158][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60344 2024-03-28 05:08:06.318 UTC [31158][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-28 05:08:06.318 UTC [31158][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-28 05:08:06.320 UTC [31158][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-28 05:08:06.322 UTC [31158][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=60344 2024-03-28 05:08:06.360 UTC [31162][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60352 2024-03-28 05:08:06.403 UTC [31172][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60358 2024-03-28 05:08:06.429 UTC [31099][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:06.429 UTC [31099][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:06.433 UTC [31099][postmaster] LOG: background worker "logical replication launcher" (PID 31125) exited with exit code 1 2024-03-28 05:08:06.440 UTC [31113][checkpointer] LOG: shutting down 2024-03-28 05:08:06.440 UTC [31113][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:06.441 UTC [31113][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/414C740, redo lsn=0/414C740 2024-03-28 05:08:06.446 UTC [31099][postmaster] LOG: database system is shut down 2024-03-28 05:08:06.597 UTC [31220][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-28 05:08:06.597 UTC [31220][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:06.597 UTC [31220][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:06.611 UTC [31235][startup] LOG: database system was shut down at 2024-03-28 05:08:06 UTC 2024-03-28 05:08:06.623 UTC [31220][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:06.656 UTC [31248][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60360 2024-03-28 05:08:06.666 UTC [31248][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-28 05:08:06.666 UTC [31248][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-28 05:08:06.683 UTC [31248][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-28 05:08:06.687 UTC [31248][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=localhost port=60360 2024-03-28 05:08:06.740 UTC [31274][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60376 2024-03-28 05:08:06.793 UTC [31289][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60386 2024-03-28 05:08:06.842 UTC [31220][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:06.842 UTC [31220][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:06.846 UTC [31220][postmaster] LOG: background worker "logical replication launcher" (PID 31240) exited with exit code 1 2024-03-28 05:08:06.850 UTC [31233][checkpointer] LOG: shutting down 2024-03-28 05:08:06.850 UTC [31233][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:06.850 UTC [31233][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/414C7B8, redo lsn=0/414C7B8 2024-03-28 05:08:06.855 UTC [31220][postmaster] LOG: database system is shut down 2024-03-28 05:08:06.992 UTC [31319][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-28 05:08:06.992 UTC [31319][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:06.992 UTC [31319][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:07.010 UTC [31323][startup] LOG: database system was shut down at 2024-03-28 05:08:06 UTC 2024-03-28 05:08:07.032 UTC [31319][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:07.079 UTC [31336][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60390 2024-03-28 05:08:07.106 UTC [31336][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-28 05:08:07.106 UTC [31336][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-28 05:08:07.140 UTC [31336][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-28 05:08:07.146 UTC [31336][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.067 user=ssltestuser database=trustdb host=localhost port=60390 2024-03-28 05:08:07.178 UTC [31345][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60406 2024-03-28 05:08:07.184 UTC [31345][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-28 05:08:07.184 UTC [31345][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-28 05:08:07.185 UTC [31345][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-28 05:08:07.190 UTC [31345][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.015 user=ssltestuser database=trustdb host=localhost port=60406 2024-03-28 05:08:07.216 UTC [31351][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60412 2024-03-28 05:08:07.265 UTC [31359][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60422 2024-03-28 05:08:07.272 UTC [31359][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-28 05:08:07.272 UTC [31359][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-28 05:08:07.273 UTC [31359][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-28 05:08:07.276 UTC [31359][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=60422 2024-03-28 05:08:07.312 UTC [31371][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60434 2024-03-28 05:08:07.320 UTC [31371][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-28 05:08:07.320 UTC [31371][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-28 05:08:07.321 UTC [31371][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-28 05:08:07.324 UTC [31371][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=60434 2024-03-28 05:08:07.353 UTC [31376][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60444 2024-03-28 05:08:07.368 UTC [31376][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-28 05:08:07.368 UTC [31376][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-28 05:08:07.383 UTC [31376][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-28 05:08:07.388 UTC [31376][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.037 user=ssltestuser database=trustdb host=localhost port=60444 2024-03-28 05:08:07.436 UTC [31391][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60452 2024-03-28 05:08:07.467 UTC [31396][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60460 2024-03-28 05:08:07.483 UTC [31319][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:07.483 UTC [31319][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:07.494 UTC [31319][postmaster] LOG: background worker "logical replication launcher" (PID 31329) exited with exit code 1 2024-03-28 05:08:07.494 UTC [31321][checkpointer] LOG: shutting down 2024-03-28 05:08:07.494 UTC [31321][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:07.495 UTC [31321][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/414C830, redo lsn=0/414C830 2024-03-28 05:08:07.499 UTC [31319][postmaster] LOG: database system is shut down 2024-03-28 05:08:07.634 UTC [31424][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-28 05:08:07.634 UTC [31424][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:07.635 UTC [31424][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:07.652 UTC [31437][startup] LOG: database system was shut down at 2024-03-28 05:08:07 UTC 2024-03-28 05:08:07.659 UTC [31424][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:07.736 UTC [31456][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60462 2024-03-28 05:08:07.741 UTC [31456][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-28 05:08:07.742 UTC [31456][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-28 05:08:07.753 UTC [31456][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-28 05:08:07.758 UTC [31456][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=localhost port=60462 2024-03-28 05:08:07.791 UTC [31465][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60468 2024-03-28 05:08:07.798 UTC [31465][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-28 05:08:07.798 UTC [31465][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-28 05:08:07.799 UTC [31465][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-28 05:08:07.805 UTC [31465][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=60468 2024-03-28 05:08:07.830 UTC [31470][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60484 2024-03-28 05:08:07.862 UTC [31424][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:07.862 UTC [31424][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:07.870 UTC [31424][postmaster] LOG: background worker "logical replication launcher" (PID 31442) exited with exit code 1 2024-03-28 05:08:07.870 UTC [31434][checkpointer] LOG: shutting down 2024-03-28 05:08:07.870 UTC [31434][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:07.871 UTC [31434][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/414C8A8, redo lsn=0/414C8A8 2024-03-28 05:08:07.876 UTC [31424][postmaster] LOG: database system is shut down 2024-03-28 05:08:07.933 UTC [31479][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-28 05:08:07.933 UTC [31479][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:07.933 UTC [31479][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:07.967 UTC [31494][startup] LOG: database system was shut down at 2024-03-28 05:08:07 UTC 2024-03-28 05:08:07.993 UTC [31479][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:08.118 UTC [31531][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60490 2024-03-28 05:08:08.124 UTC [31531][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-28 05:08:08.124 UTC [31531][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-28 05:08:08.147 UTC [31531][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-28 05:08:08.153 UTC [31531][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.042 user=ssltestuser database=trustdb host=localhost port=60490 2024-03-28 05:08:08.182 UTC [31554][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60506 2024-03-28 05:08:08.196 UTC [31554][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-28 05:08:08.196 UTC [31554][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-28 05:08:08.197 UTC [31554][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-28 05:08:08.200 UTC [31554][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=60506 2024-03-28 05:08:08.222 UTC [31567][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60512 2024-03-28 05:08:08.232 UTC [31567][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-28 05:08:08.232 UTC [31567][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-28 05:08:08.235 UTC [31567][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-28 05:08:08.238 UTC [31567][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.017 user=ssltestuser database=trustdb host=localhost port=60512 2024-03-28 05:08:08.244 UTC [31479][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:08.244 UTC [31479][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:08.250 UTC [31479][postmaster] LOG: background worker "logical replication launcher" (PID 31509) exited with exit code 1 2024-03-28 05:08:08.253 UTC [31491][checkpointer] LOG: shutting down 2024-03-28 05:08:08.253 UTC [31491][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:08.254 UTC [31491][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/414C920, redo lsn=0/414C920 2024-03-28 05:08:08.259 UTC [31479][postmaster] LOG: database system is shut down 2024-03-28 05:08:08.389 UTC [31588][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-28 05:08:08.389 UTC [31588][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:08.389 UTC [31588][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:08.397 UTC [31597][startup] LOG: database system was shut down at 2024-03-28 05:08:08 UTC 2024-03-28 05:08:08.419 UTC [31588][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:08.482 UTC [31616][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60518 2024-03-28 05:08:08.496 UTC [31616][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-28 05:08:08.496 UTC [31616][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-28 05:08:08.531 UTC [31616][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-28 05:08:08.538 UTC [31616][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.058 user=ssltestuser database=trustdb host=localhost port=60518 2024-03-28 05:08:08.567 UTC [31630][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60522 2024-03-28 05:08:08.579 UTC [31630][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-28 05:08:08.579 UTC [31630][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-28 05:08:08.580 UTC [31630][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-28 05:08:08.581 UTC [31630][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=localhost port=60522 2024-03-28 05:08:08.611 UTC [31642][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60536 2024-03-28 05:08:08.643 UTC [31588][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:08.643 UTC [31588][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:08.651 UTC [31588][postmaster] LOG: background worker "logical replication launcher" (PID 31604) exited with exit code 1 2024-03-28 05:08:08.651 UTC [31595][checkpointer] LOG: shutting down 2024-03-28 05:08:08.651 UTC [31595][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:08.652 UTC [31595][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/414C998, redo lsn=0/414C998 2024-03-28 05:08:08.657 UTC [31588][postmaster] LOG: database system is shut down 2024-03-28 05:08:08.806 UTC [31669][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-28 05:08:08.806 UTC [31669][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:08.807 UTC [31669][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:08.823 UTC [31676][startup] LOG: database system was shut down at 2024-03-28 05:08:08 UTC 2024-03-28 05:08:08.831 UTC [31669][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:08.898 UTC [31700][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60550 2024-03-28 05:08:08.905 UTC [31700][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-28 05:08:08.905 UTC [31700][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-28 05:08:08.923 UTC [31700][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-28 05:08:08.929 UTC [31700][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=localhost port=60550 2024-03-28 05:08:08.954 UTC [31716][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60562 2024-03-28 05:08:08.966 UTC [31716][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-28 05:08:08.966 UTC [31716][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-28 05:08:08.968 UTC [31716][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-28 05:08:08.973 UTC [31716][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=60562 2024-03-28 05:08:08.999 UTC [31723][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60570 2024-03-28 05:08:09.005 UTC [31723][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-28 05:08:09.005 UTC [31723][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-28 05:08:09.006 UTC [31723][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-28 05:08:09.009 UTC [31723][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=60570 2024-03-28 05:08:09.024 UTC [31669][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:09.024 UTC [31669][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:09.029 UTC [31669][postmaster] LOG: background worker "logical replication launcher" (PID 31681) exited with exit code 1 2024-03-28 05:08:09.029 UTC [31674][checkpointer] LOG: shutting down 2024-03-28 05:08:09.030 UTC [31674][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:09.030 UTC [31674][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/414CA10, redo lsn=0/414CA10 2024-03-28 05:08:09.035 UTC [31669][postmaster] LOG: database system is shut down 2024-03-28 05:08:09.152 UTC [31744][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-28 05:08:09.152 UTC [31744][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:09.152 UTC [31744][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:09.161 UTC [31755][startup] LOG: database system was shut down at 2024-03-28 05:08:09 UTC 2024-03-28 05:08:09.168 UTC [31744][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:09.255 UTC [31771][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60578 2024-03-28 05:08:09.262 UTC [31771][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-28 05:08:09.262 UTC [31771][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-28 05:08:09.283 UTC [31771][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-28 05:08:09.289 UTC [31771][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.037 user=ssltestuser database=trustdb host=localhost port=60578 2024-03-28 05:08:09.319 UTC [31792][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60588 2024-03-28 05:08:09.338 UTC [31744][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:09.338 UTC [31744][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:09.342 UTC [31744][postmaster] LOG: background worker "logical replication launcher" (PID 31762) exited with exit code 1 2024-03-28 05:08:09.345 UTC [31752][checkpointer] LOG: shutting down 2024-03-28 05:08:09.345 UTC [31752][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:09.346 UTC [31752][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/414CA88, redo lsn=0/414CA88 2024-03-28 05:08:09.351 UTC [31744][postmaster] LOG: database system is shut down 2024-03-28 05:08:09.487 UTC [31814][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-28 05:08:09.487 UTC [31814][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:09.487 UTC [31814][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:09.499 UTC [31824][startup] LOG: database system was shut down at 2024-03-28 05:08:09 UTC 2024-03-28 05:08:09.515 UTC [31814][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:09.563 UTC [31842][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60596 2024-03-28 05:08:09.571 UTC [31842][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:08:09.620 UTC [31853][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60598 2024-03-28 05:08:09.638 UTC [31853][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-28 05:08:09.638 UTC [31853][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-28 05:08:09.671 UTC [31853][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-28 05:08:09.678 UTC [31853][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.059 user=ssltestuser database=trustdb host=localhost port=60598 2024-03-28 05:08:09.703 UTC [31874][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60614 2024-03-28 05:08:09.733 UTC [31814][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:09.733 UTC [31814][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:09.740 UTC [31814][postmaster] LOG: background worker "logical replication launcher" (PID 31831) exited with exit code 1 2024-03-28 05:08:09.742 UTC [31822][checkpointer] LOG: shutting down 2024-03-28 05:08:09.742 UTC [31822][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:09.743 UTC [31822][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/414CB00, redo lsn=0/414CB00 2024-03-28 05:08:09.748 UTC [31814][postmaster] LOG: database system is shut down 2024-03-28 05:08:09.889 UTC [31903][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-28 05:08:09.889 UTC [31903][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:09.889 UTC [31903][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:09.900 UTC [31915][startup] LOG: database system was shut down at 2024-03-28 05:08:09 UTC 2024-03-28 05:08:09.909 UTC [31903][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:09.967 UTC [31936][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60616 2024-03-28 05:08:09.975 UTC [31936][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-28 05:08:09.975 UTC [31936][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-28 05:08:10.012 UTC [31936][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-28 05:08:10.018 UTC [31936][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.052 user=ssltestuser database=trustdb host=localhost port=60616 2024-03-28 05:08:10.030 UTC [31953][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60624 2024-03-28 05:08:10.042 UTC [31953][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-28 05:08:10.058 UTC [31960][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60638 2024-03-28 05:08:10.073 UTC [31960][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-28 05:08:10.098 UTC [31970][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60652 2024-03-28 05:08:10.104 UTC [31970][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-28 05:08:10.104 UTC [31970][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-28 05:08:10.105 UTC [31970][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-28 05:08:10.115 UTC [31970][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=60652 2024-03-28 05:08:10.140 UTC [31980][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60658 2024-03-28 05:08:10.158 UTC [31980][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-28 05:08:10.158 UTC [31980][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-28 05:08:10.159 UTC [31980][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-28 05:08:10.162 UTC [31980][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=60658 2024-03-28 05:08:10.236 UTC [32014][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60666 2024-03-28 05:08:10.247 UTC [32014][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-28 05:08:10.265 UTC [32030][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60668 2024-03-28 05:08:10.273 UTC [32030][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-28 05:08:10.273 UTC [32030][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-28 05:08:10.292 UTC [32030][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__Kri/client.key$$ 2024-03-28 05:08:10.298 UTC [32030][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=certdb host=localhost port=60668 2024-03-28 05:08:10.316 UTC [32042][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60682 2024-03-28 05:08:10.335 UTC [32042][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-28 05:08:10.335 UTC [32042][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-28 05:08:10.336 UTC [32042][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__Kri/client-der.key$$ 2024-03-28 05:08:10.337 UTC [32042][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=localhost port=60682 2024-03-28 05:08:10.375 UTC [32058][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60686 2024-03-28 05:08:10.393 UTC [32058][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-28 05:08:10.393 UTC [32058][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-28 05:08:10.395 UTC [32058][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__Kri/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-28 05:08:10.395 UTC [32058][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=ssltestuser database=certdb host=localhost port=60686 2024-03-28 05:08:10.431 UTC [32073][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60700 2024-03-28 05:08:10.440 UTC [32073][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-28 05:08:10.440 UTC [32073][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-28 05:08:10.441 UTC [32073][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__Kri/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-28 05:08:10.446 UTC [32073][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=ssltestuser database=certdb host=localhost port=60700 2024-03-28 05:08:10.462 UTC [32080][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60704 2024-03-28 05:08:10.470 UTC [32080][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-28 05:08:10.470 UTC [32080][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-28 05:08:10.472 UTC [32080][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__Kri/client.key$$ 2024-03-28 05:08:10.475 UTC [32080][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=certdb host=localhost port=60704 2024-03-28 05:08:10.505 UTC [32093][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60708 2024-03-28 05:08:10.513 UTC [32093][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-28 05:08:10.513 UTC [32093][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-28 05:08:10.515 UTC [32093][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__Kri/client.key$$ 2024-03-28 05:08:10.523 UTC [32093][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=certdb host=localhost port=60708 2024-03-28 05:08:10.546 UTC [32101][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60712 2024-03-28 05:08:10.556 UTC [32101][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-28 05:08:10.593 UTC [32111][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60714 2024-03-28 05:08:10.597 UTC [32111][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:08:10.641 UTC [32120][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60726 2024-03-28 05:08:10.654 UTC [32120][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-28 05:08:10.654 UTC [32120][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-28 05:08:10.665 UTC [32120][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__Kri/client-dn.key$$ 2024-03-28 05:08:10.671 UTC [32120][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb_dn host=localhost port=60726 2024-03-28 05:08:10.686 UTC [32128][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60734 2024-03-28 05:08:10.696 UTC [32128][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-28 05:08:10.696 UTC [32128][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-28 05:08:10.708 UTC [32128][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__Kri/client-dn.key$$ 2024-03-28 05:08:10.713 UTC [32128][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=ssltestuser database=certdb_dn_re host=localhost port=60734 2024-03-28 05:08:10.729 UTC [32131][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60742 2024-03-28 05:08:10.737 UTC [32131][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-28 05:08:10.737 UTC [32131][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-28 05:08:10.754 UTC [32131][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__Kri/client-dn.key$$ 2024-03-28 05:08:10.760 UTC [32131][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb_cn host=localhost port=60742 2024-03-28 05:08:10.786 UTC [32138][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60752 2024-03-28 05:08:10.794 UTC [32138][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-28 05:08:10.794 UTC [32138][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-28 05:08:10.796 UTC [32138][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-28 05:08:10.803 UTC [32138][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.017 user=ssltestuser database=certdb host=localhost port=60752 2024-03-28 05:08:10.823 UTC [32144][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60768 2024-03-28 05:08:10.830 UTC [32144][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:08:10.848 UTC [32149][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60782 2024-03-28 05:08:10.856 UTC [32149][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-28 05:08:10.856 UTC [32149][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-28 05:08:10.856 UTC [32149][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-28 05:08:10.856 UTC [32149][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-28 05:08:10.889 UTC [32156][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60786 2024-03-28 05:08:10.896 UTC [32156][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:08:10.896 UTC [32156][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-28 05:08:10.923 UTC [32160][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60798 2024-03-28 05:08:10.930 UTC [32160][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-28 05:08:10.930 UTC [32160][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-28 05:08:10.942 UTC [32160][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__Kri/client.key$$ 2024-03-28 05:08:10.947 UTC [32160][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=ssltestuser database=verifydb host=localhost port=60798 2024-03-28 05:08:10.987 UTC [32173][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60804 2024-03-28 05:08:10.996 UTC [32173][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-28 05:08:10.996 UTC [32173][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-28 05:08:10.996 UTC [32173][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-28 05:08:10.996 UTC [32173][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-28 05:08:11.039 UTC [32178][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60818 2024-03-28 05:08:11.047 UTC [32178][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-28 05:08:11.047 UTC [32178][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-28 05:08:11.052 UTC [32178][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__Kri/client.key$$ 2024-03-28 05:08:11.053 UTC [32178][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.017 user=yetanotheruser database=verifydb host=localhost port=60818 2024-03-28 05:08:11.068 UTC [31903][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:11.068 UTC [31903][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:11.078 UTC [31903][postmaster] LOG: background worker "logical replication launcher" (PID 31921) exited with exit code 1 2024-03-28 05:08:11.078 UTC [31913][checkpointer] LOG: shutting down 2024-03-28 05:08:11.078 UTC [31913][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:11.079 UTC [31913][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/414CB78, redo lsn=0/414CB78 2024-03-28 05:08:11.084 UTC [31903][postmaster] LOG: database system is shut down 2024-03-28 05:08:11.250 UTC [32199][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-28 05:08:11.250 UTC [32199][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:11.250 UTC [32199][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:11.264 UTC [32207][startup] LOG: database system was shut down at 2024-03-28 05:08:11 UTC 2024-03-28 05:08:11.272 UTC [32199][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:11.300 UTC [32221][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60826 2024-03-28 05:08:11.316 UTC [32221][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-28 05:08:11.316 UTC [32221][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-28 05:08:11.337 UTC [32221][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__Kri/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-28 05:08:11.341 UTC [32221][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.041 user=ssltestuser database=certdb host=localhost port=60826 2024-03-28 05:08:11.363 UTC [32242][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60832 2024-03-28 05:08:11.383 UTC [32242][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:08:11.383 UTC [32242][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-28 05:08:11.403 UTC [32261][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60834 2024-03-28 05:08:11.412 UTC [32261][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:08:11.412 UTC [32261][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-28 05:08:11.420 UTC [32199][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:11.420 UTC [32199][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:11.425 UTC [32199][postmaster] LOG: background worker "logical replication launcher" (PID 32215) exited with exit code 1 2024-03-28 05:08:11.428 UTC [32205][checkpointer] LOG: shutting down 2024-03-28 05:08:11.428 UTC [32205][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:11.429 UTC [32205][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/414CBF0, redo lsn=0/414CBF0 2024-03-28 05:08:11.434 UTC [32199][postmaster] LOG: database system is shut down 2024-03-28 05:08:11.584 UTC [32282][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-28 05:08:11.584 UTC [32282][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:11.584 UTC [32282][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:11.589 UTC [32291][startup] LOG: database system was shut down at 2024-03-28 05:08:11 UTC 2024-03-28 05:08:11.596 UTC [32282][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:11.645 UTC [32309][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60836 2024-03-28 05:08:11.652 UTC [32309][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:08:11.652 UTC [32309][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-28 05:08:11.665 UTC [32282][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:11.665 UTC [32282][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:11.671 UTC [32282][postmaster] LOG: background worker "logical replication launcher" (PID 32295) exited with exit code 1 2024-03-28 05:08:11.672 UTC [32289][checkpointer] LOG: shutting down 2024-03-28 05:08:11.672 UTC [32289][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:11.672 UTC [32289][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/414CC68, redo lsn=0/414CC68 2024-03-28 05:08:11.677 UTC [32282][postmaster] LOG: database system is shut down 2024-03-28 05:08:11.818 UTC [32332][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-28 05:08:11.818 UTC [32332][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:11.818 UTC [32332][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:11.840 UTC [32346][startup] LOG: database system was shut down at 2024-03-28 05:08:11 UTC 2024-03-28 05:08:11.847 UTC [32332][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:11.893 UTC [32357][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60842 2024-03-28 05:08:11.904 UTC [32357][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:08:11.904 UTC [32357][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-28 05:08:11.998 UTC [32405][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60858 2024-03-28 05:08:12.041 UTC [32405][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:08:12.041 UTC [32405][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-28 05:08:12.087 UTC [32332][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:12.087 UTC [32332][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:12.091 UTC [32332][postmaster] LOG: background worker "logical replication launcher" (PID 32350) exited with exit code 1 2024-03-28 05:08:12.096 UTC [32344][checkpointer] LOG: shutting down 2024-03-28 05:08:12.096 UTC [32344][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:12.097 UTC [32344][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/414CCE0, redo lsn=0/414CCE0 2024-03-28 05:08:12.102 UTC [32332][postmaster] LOG: database system is shut down 2024-03-28 05:08:12.291 UTC [32438][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-28 05:08:12.291 UTC [32438][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:12.291 UTC [32438][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:12.313 UTC [32457][startup] LOG: database system was shut down at 2024-03-28 05:08:12 UTC 2024-03-28 05:08:12.321 UTC [32438][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:12.431 UTC [32470][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39232 2024-03-28 05:08:12.439 UTC [32470][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:12.439 UTC [32470][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-28 05:08:12.475 UTC [32476][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39234 2024-03-28 05:08:12.484 UTC [32476][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-28 05:08:12.484 UTC [32476][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-28 05:08:12.512 UTC [32476][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-28 05:08:12.518 UTC [32476][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.043 user=ssltestuser database=trustdb host=localhost port=39234 2024-03-28 05:08:12.527 UTC [32438][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:12.527 UTC [32438][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:12.532 UTC [32438][postmaster] LOG: background worker "logical replication launcher" (PID 32461) exited with exit code 1 2024-03-28 05:08:12.539 UTC [32455][checkpointer] LOG: shutting down 2024-03-28 05:08:12.539 UTC [32455][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:12.540 UTC [32455][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/414CD58, redo lsn=0/414CD58 2024-03-28 05:08:12.546 UTC [32438][postmaster] LOG: database system is shut down 2024-03-28 05:08:12.684 UTC [32512][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-28 05:08:12.684 UTC [32512][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:12.684 UTC [32512][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:12.723 UTC [32523][startup] LOG: database system was shut down at 2024-03-28 05:08:12 UTC 2024-03-28 05:08:12.730 UTC [32512][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:12.767 UTC [32531][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39244 2024-03-28 05:08:12.781 UTC [32531][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:12.781 UTC [32531][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-28 05:08:12.819 UTC [32538][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39248 2024-03-28 05:08:12.831 UTC [32538][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-28 05:08:12.831 UTC [32538][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-28 05:08:12.864 UTC [32538][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-28 05:08:12.867 UTC [32538][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.052 user=ssltestuser database=trustdb host=localhost port=39248 2024-03-28 05:08:12.871 UTC [32512][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:12.871 UTC [32512][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:12.879 UTC [32512][postmaster] LOG: background worker "logical replication launcher" (PID 32527) exited with exit code 1 2024-03-28 05:08:12.888 UTC [32520][checkpointer] LOG: shutting down 2024-03-28 05:08:12.888 UTC [32520][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:12.889 UTC [32520][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/414CDD0, redo lsn=0/414CDD0 2024-03-28 05:08:12.895 UTC [32512][postmaster] LOG: database system is shut down 2024-03-28 05:08:13.043 UTC [32563][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-28 05:08:13.043 UTC [32563][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:13.043 UTC [32563][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:13.054 UTC [32572][startup] LOG: database system was shut down at 2024-03-28 05:08:12 UTC 2024-03-28 05:08:13.062 UTC [32563][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:13.128 UTC [32589][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39250 2024-03-28 05:08:13.132 UTC [32589][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:13.132 UTC [32589][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-28 05:08:13.168 UTC [32601][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39264 2024-03-28 05:08:13.179 UTC [32601][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-28 05:08:13.179 UTC [32601][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-28 05:08:13.220 UTC [32601][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-28 05:08:13.226 UTC [32601][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.057 user=ssltestuser database=trustdb host=localhost port=39264 2024-03-28 05:08:13.228 UTC [32563][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:13.228 UTC [32563][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:13.232 UTC [32563][postmaster] LOG: background worker "logical replication launcher" (PID 32577) exited with exit code 1 2024-03-28 05:08:13.240 UTC [32569][checkpointer] LOG: shutting down 2024-03-28 05:08:13.240 UTC [32569][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:13.241 UTC [32569][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/414CE48, redo lsn=0/414CE48 2024-03-28 05:08:13.249 UTC [32563][postmaster] LOG: database system is shut down 2024-03-28 05:08:13.359 UTC [32641][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-28 05:08:13.359 UTC [32641][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:13.359 UTC [32641][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:13.383 UTC [32649][startup] LOG: database system was shut down at 2024-03-28 05:08:13 UTC 2024-03-28 05:08:13.392 UTC [32641][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:13.452 UTC [32672][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39276 2024-03-28 05:08:13.455 UTC [32672][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:13.455 UTC [32672][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:13.460 UTC [32672][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert internal error 2024-03-28 05:08:13.481 UTC [32688][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39288 2024-03-28 05:08:13.499 UTC [32688][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-28 05:08:13.499 UTC [32688][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-28 05:08:13.516 UTC [32688][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-28 05:08:13.521 UTC [32688][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.040 user=ssltestuser database=trustdb host=localhost port=39288 2024-03-28 05:08:13.529 UTC [32641][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:13.529 UTC [32641][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:13.538 UTC [32641][postmaster] LOG: background worker "logical replication launcher" (PID 32659) exited with exit code 1 2024-03-28 05:08:13.539 UTC [32647][checkpointer] LOG: shutting down 2024-03-28 05:08:13.539 UTC [32647][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:13.540 UTC [32647][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/414CEC0, redo lsn=0/414CEC0 2024-03-28 05:08:13.545 UTC [32641][postmaster] LOG: database system is shut down 2024-03-28 05:08:13.792 UTC [32775][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-28 05:08:13.793 UTC [32775][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:13.793 UTC [32775][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:13.887 UTC [32803][startup] LOG: database system was shut down at 2024-03-28 05:08:13 UTC 2024-03-28 05:08:13.912 UTC [32775][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:13.956 UTC [32809][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39304 2024-03-28 05:08:13.976 UTC [32809][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:13.976 UTC [32809][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-28 05:08:14.041 UTC [32819][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39308 2024-03-28 05:08:14.051 UTC [32819][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-28 05:08:14.051 UTC [32819][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-28 05:08:14.088 UTC [32819][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-28 05:08:14.099 UTC [32819][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.059 user=ssltestuser database=trustdb host=localhost port=39308 2024-03-28 05:08:14.106 UTC [32775][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:14.106 UTC [32775][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:14.114 UTC [32775][postmaster] LOG: background worker "logical replication launcher" (PID 32806) exited with exit code 1 2024-03-28 05:08:14.115 UTC [32799][checkpointer] LOG: shutting down 2024-03-28 05:08:14.115 UTC [32799][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:14.116 UTC [32799][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/414CF38, redo lsn=0/414CF38 2024-03-28 05:08:14.122 UTC [32775][postmaster] LOG: database system is shut down 2024-03-28 05:08:14.203 UTC [32830][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-28 05:08:14.203 UTC [32830][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:14.203 UTC [32830][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:14.218 UTC [32835][startup] LOG: database system was shut down at 2024-03-28 05:08:14 UTC 2024-03-28 05:08:14.225 UTC [32830][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:14.275 UTC [32840][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39324 2024-03-28 05:08:14.277 UTC [32840][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:14.278 UTC [32840][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:14.289 UTC [32840][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:08:14.311 UTC [32843][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39336 2024-03-28 05:08:14.319 UTC [32843][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-28 05:08:14.319 UTC [32843][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-28 05:08:14.345 UTC [32843][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-28 05:08:14.350 UTC [32843][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.040 user=ssltestuser database=trustdb host=localhost port=39336 2024-03-28 05:08:14.362 UTC [32830][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:14.362 UTC [32830][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:14.367 UTC [32830][postmaster] LOG: background worker "logical replication launcher" (PID 32838) exited with exit code 1 2024-03-28 05:08:14.370 UTC [32833][checkpointer] LOG: shutting down 2024-03-28 05:08:14.370 UTC [32833][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:14.371 UTC [32833][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/414CFB0, redo lsn=0/414CFB0 2024-03-28 05:08:14.376 UTC [32830][postmaster] LOG: database system is shut down 2024-03-28 05:08:14.541 UTC [32857][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-28 05:08:14.541 UTC [32857][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:14.542 UTC [32857][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:14.571 UTC [32867][startup] LOG: database system was shut down at 2024-03-28 05:08:14 UTC 2024-03-28 05:08:14.579 UTC [32857][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:14.704 UTC [32879][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39338 2024-03-28 05:08:14.715 UTC [32879][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:14.716 UTC [32879][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:14.721 UTC [32879][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:08:14.760 UTC [32889][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39350 2024-03-28 05:08:14.771 UTC [32889][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-28 05:08:14.771 UTC [32889][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-28 05:08:14.823 UTC [32889][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-28 05:08:14.828 UTC [32889][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.069 user=ssltestuser database=trustdb host=localhost port=39350 2024-03-28 05:08:14.835 UTC [32857][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:14.836 UTC [32857][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:14.846 UTC [32857][postmaster] LOG: background worker "logical replication launcher" (PID 32871) exited with exit code 1 2024-03-28 05:08:14.846 UTC [32865][checkpointer] LOG: shutting down 2024-03-28 05:08:14.846 UTC [32865][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:14.847 UTC [32865][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/414D028, redo lsn=0/414D028 2024-03-28 05:08:14.852 UTC [32857][postmaster] LOG: database system is shut down 2024-03-28 05:08:14.985 UTC [32906][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-28 05:08:14.985 UTC [32906][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:14.985 UTC [32906][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:15.015 UTC [32921][startup] LOG: database system was shut down at 2024-03-28 05:08:14 UTC 2024-03-28 05:08:15.023 UTC [32906][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:15.095 UTC [32934][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39364 2024-03-28 05:08:15.105 UTC [32934][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:15.105 UTC [32934][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:15.110 UTC [32934][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:08:15.156 UTC [32942][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39366 2024-03-28 05:08:15.163 UTC [32942][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-28 05:08:15.163 UTC [32942][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-28 05:08:15.175 UTC [32942][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-28 05:08:15.179 UTC [32942][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=localhost port=39366 2024-03-28 05:08:15.187 UTC [32906][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:15.187 UTC [32906][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:15.191 UTC [32906][postmaster] LOG: background worker "logical replication launcher" (PID 32925) exited with exit code 1 2024-03-28 05:08:15.193 UTC [32919][checkpointer] LOG: shutting down 2024-03-28 05:08:15.193 UTC [32919][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:15.194 UTC [32919][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/414D0A0, redo lsn=0/414D0A0 2024-03-28 05:08:15.199 UTC [32906][postmaster] LOG: database system is shut down 2024-03-28 05:08:15.341 UTC [32965][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-28 05:08:15.341 UTC [32965][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51651 2024-03-28 05:08:15.341 UTC [32965][postmaster] LOG: listening on Unix socket "/tmp/yUpAfjW5Sw/.s.PGSQL.51651" 2024-03-28 05:08:15.364 UTC [32975][startup] LOG: database system was shut down at 2024-03-28 05:08:15 UTC 2024-03-28 05:08:15.371 UTC [32965][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:08:15.424 UTC [32989][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39370 2024-03-28 05:08:15.427 UTC [32989][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:08:15.427 UTC [32989][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-28 05:08:15.464 UTC [32995][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=39378 2024-03-28 05:08:15.476 UTC [32995][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-28 05:08:15.476 UTC [32995][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-28 05:08:15.507 UTC [32995][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-28 05:08:15.510 UTC [32995][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.047 user=ssltestuser database=trustdb host=localhost port=39378 2024-03-28 05:08:15.522 UTC [32965][postmaster] LOG: received fast shutdown request 2024-03-28 05:08:15.522 UTC [32965][postmaster] LOG: aborting any active transactions 2024-03-28 05:08:15.528 UTC [32965][postmaster] LOG: background worker "logical replication launcher" (PID 32978) exited with exit code 1 2024-03-28 05:08:15.531 UTC [32973][checkpointer] LOG: shutting down 2024-03-28 05:08:15.531 UTC [32973][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:08:15.531 UTC [32973][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/414D118, redo lsn=0/414D118 2024-03-28 05:08:15.536 UTC [32965][postmaster] LOG: database system is shut down 2024-03-28 05:08:15.712 UTC [33073][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-28 05:08:15.712 UTC [33073][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:08:15.824](0.313s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"