[00:36:47.150](0.026s) # setting up data directory # Checking port 61742 # Found port 61742 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=61742 host=/tmp/lwpVoisUKW Log file: /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log [00:36:47.156](0.006s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/tmp_install/initdb-template /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata # Running: /tmp/cirrus-ci-build/src/test/ssl/../../../src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata ### Starting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/src/test/ssl/tmp_check/log/001_ssltests_primary.log -o --cluster-name=primary start waiting for server to start.... done server started # Postmaster PID for node "primary" is 28211 [00:36:47.465](0.309s) 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 28475 [00:36:48.907](1.443s) # 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-06 00:36:47.384 UTC [28211][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-06 00:36:47.384 UTC [28211][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:47.391 UTC [28225][startup] LOG: database system was shut down at 2024-03-06 00:35:15 UTC 2024-03-06 00:36:47.410 UTC [28211][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:47.435 UTC [28234][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.436 UTC [28234][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-06 00:36:47.436 UTC [28234][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.462 UTC [28234][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-06 00:36:47.464 UTC [28234][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.493 UTC [28243][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.495 UTC [28243][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-06 00:36:47.495 UTC [28243][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.506 UTC [28243][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-06 00:36:47.509 UTC [28243][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.017 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.541 UTC [28256][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.542 UTC [28256][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-06 00:36:47.542 UTC [28256][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.544 UTC [28256][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-06 00:36:47.544 UTC [28256][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.003 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.579 UTC [28270][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.580 UTC [28270][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-06 00:36:47.580 UTC [28270][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.581 UTC [28270][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-06 00:36:47.583 UTC [28270][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.627 UTC [28283][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.628 UTC [28283][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-06 00:36:47.628 UTC [28283][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.636 UTC [28283][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-06 00:36:47.641 UTC [28283][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.674 UTC [28296][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.675 UTC [28296][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-06 00:36:47.675 UTC [28296][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.677 UTC [28296][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-06 00:36:47.766 UTC [28296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.091 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.805 UTC [28314][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.806 UTC [28314][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-06 00:36:47.806 UTC [28314][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.807 UTC [28314][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-06 00:36:47.860 UTC [28314][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.055 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.928 UTC [28345][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.929 UTC [28345][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-06 00:36:47.929 UTC [28345][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.930 UTC [28345][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-06 00:36:47.968 UTC [28345][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.040 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.080 UTC [28373][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.081 UTC [28373][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-06 00:36:48.081 UTC [28373][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.083 UTC [28373][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-06 00:36:48.190 UTC [28373][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.115 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.350 UTC [28430][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.351 UTC [28430][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-06 00:36:48.351 UTC [28430][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.353 UTC [28430][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-06 00:36:48.406 UTC [28430][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.056 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.491 UTC [28442][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.492 UTC [28442][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-06 00:36:48.492 UTC [28442][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.494 UTC [28442][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-06 00:36:48.559 UTC [28442][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.067 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.605 UTC [28211][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:48.605 UTC [28211][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:48.617 UTC [28211][postmaster] LOG: background worker "logical replication launcher" (PID 28231) exited with exit code 1 2024-03-06 00:36:48.618 UTC [28223][checkpointer] LOG: shutting down 2024-03-06 00:36:48.618 UTC [28223][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:48.736 UTC [28223][checkpointer] LOG: checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.118 s, sync=0.001 s, total=0.119 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45479 kB, estimate=45479 kB; lsn=0/4196518, redo lsn=0/4196518 2024-03-06 00:36:48.759 UTC [28211][postmaster] LOG: database system is shut down 2024-03-06 00:36:48.836 UTC [28475][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-06 00:36:48.836 UTC [28475][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:48.836 UTC [28475][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:48.855 UTC [28489][startup] LOG: database system was shut down at 2024-03-06 00:36:48 UTC 2024-03-06 00:36:48.863 UTC [28475][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:48.917 UTC [28475][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:48.917 UTC [28475][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:48.922 UTC [28475][postmaster] LOG: background worker "logical replication launcher" (PID 28497) exited with exit code 1 2024-03-06 00:36:48.926 UTC [28487][checkpointer] LOG: shutting down 2024-03-06 00:36:48.926 UTC [28487][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:48.927 UTC [28487][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/4196590, redo lsn=0/4196590 2024-03-06 00:36:48.933 UTC [28475][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.072 UTC [28543][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-06 00:36:49.072 UTC [28543][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [00:36:49.124](0.217s) 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 28560 [00:36:49.240](0.116s) 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-06 00:36:47.384 UTC [28211][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-06 00:36:47.384 UTC [28211][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:47.391 UTC [28225][startup] LOG: database system was shut down at 2024-03-06 00:35:15 UTC 2024-03-06 00:36:47.410 UTC [28211][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:47.435 UTC [28234][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.436 UTC [28234][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-06 00:36:47.436 UTC [28234][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.462 UTC [28234][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-06 00:36:47.464 UTC [28234][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.493 UTC [28243][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.495 UTC [28243][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-06 00:36:47.495 UTC [28243][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.506 UTC [28243][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-06 00:36:47.509 UTC [28243][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.017 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.541 UTC [28256][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.542 UTC [28256][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-06 00:36:47.542 UTC [28256][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.544 UTC [28256][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-06 00:36:47.544 UTC [28256][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.003 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.579 UTC [28270][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.580 UTC [28270][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-06 00:36:47.580 UTC [28270][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.581 UTC [28270][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-06 00:36:47.583 UTC [28270][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.627 UTC [28283][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.628 UTC [28283][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-06 00:36:47.628 UTC [28283][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.636 UTC [28283][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-06 00:36:47.641 UTC [28283][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.674 UTC [28296][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.675 UTC [28296][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-06 00:36:47.675 UTC [28296][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.677 UTC [28296][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-06 00:36:47.766 UTC [28296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.091 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.805 UTC [28314][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.806 UTC [28314][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-06 00:36:47.806 UTC [28314][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.807 UTC [28314][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-06 00:36:47.860 UTC [28314][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.055 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.928 UTC [28345][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.929 UTC [28345][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-06 00:36:47.929 UTC [28345][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.930 UTC [28345][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-06 00:36:47.968 UTC [28345][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.040 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.080 UTC [28373][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.081 UTC [28373][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-06 00:36:48.081 UTC [28373][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.083 UTC [28373][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-06 00:36:48.190 UTC [28373][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.115 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.350 UTC [28430][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.351 UTC [28430][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-06 00:36:48.351 UTC [28430][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.353 UTC [28430][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-06 00:36:48.406 UTC [28430][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.056 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.491 UTC [28442][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.492 UTC [28442][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-06 00:36:48.492 UTC [28442][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.494 UTC [28442][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-06 00:36:48.559 UTC [28442][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.067 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.605 UTC [28211][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:48.605 UTC [28211][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:48.617 UTC [28211][postmaster] LOG: background worker "logical replication launcher" (PID 28231) exited with exit code 1 2024-03-06 00:36:48.618 UTC [28223][checkpointer] LOG: shutting down 2024-03-06 00:36:48.618 UTC [28223][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:48.736 UTC [28223][checkpointer] LOG: checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.118 s, sync=0.001 s, total=0.119 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45479 kB, estimate=45479 kB; lsn=0/4196518, redo lsn=0/4196518 2024-03-06 00:36:48.759 UTC [28211][postmaster] LOG: database system is shut down 2024-03-06 00:36:48.836 UTC [28475][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-06 00:36:48.836 UTC [28475][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:48.836 UTC [28475][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:48.855 UTC [28489][startup] LOG: database system was shut down at 2024-03-06 00:36:48 UTC 2024-03-06 00:36:48.863 UTC [28475][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:48.917 UTC [28475][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:48.917 UTC [28475][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:48.922 UTC [28475][postmaster] LOG: background worker "logical replication launcher" (PID 28497) exited with exit code 1 2024-03-06 00:36:48.926 UTC [28487][checkpointer] LOG: shutting down 2024-03-06 00:36:48.926 UTC [28487][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:48.927 UTC [28487][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/4196590, redo lsn=0/4196590 2024-03-06 00:36:48.933 UTC [28475][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.072 UTC [28543][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-06 00:36:49.072 UTC [28543][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.186 UTC [28560][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-06 00:36:49.186 UTC [28560][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:49.186 UTC [28560][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:49.197 UTC [28565][startup] LOG: database system was shut down at 2024-03-06 00:36:48 UTC 2024-03-06 00:36:49.219 UTC [28560][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:49.243 UTC [28560][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:49.243 UTC [28560][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:49.248 UTC [28560][postmaster] LOG: background worker "logical replication launcher" (PID 28569) exited with exit code 1 2024-03-06 00:36:49.253 UTC [28563][checkpointer] LOG: shutting down 2024-03-06 00:36:49.253 UTC [28563][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:49.254 UTC [28563][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/4196608, redo lsn=0/4196608 2024-03-06 00:36:49.261 UTC [28560][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.383 UTC [28596][postmaster] FATAL: could not set SSL protocol version range 2024-03-06 00:36:49.383 UTC [28596][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-06 00:36:49.383 UTC [28596][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [00:36:49.452](0.212s) 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 28619 [00:36:49.562](0.111s) ok 5 - restart succeeds with correct SSL protocol bounds [00:36:49.563](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 28681 [00:36:49.797](0.234s) ok 6 - server doesn't accept non-SSL connections [00:36:49.797](0.000s) ok 7 - server doesn't accept non-SSL connections: matches [00:36:49.880](0.083s) ok 8 - connect without server root cert sslmode=require [00:36:49.881](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr [00:36:49.903](0.022s) ok 10 - connect without server root cert sslmode=verify-ca [00:36:49.903](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches [00:36:49.941](0.038s) ok 12 - connect without server root cert sslmode=verify-full [00:36:49.941](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches [00:36:49.980](0.039s) ok 14 - connect with wrong server root cert sslmode=require [00:36:49.980](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches [00:36:50.020](0.040s) ok 16 - connect with wrong server root cert sslmode=verify-ca [00:36:50.020](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [00:36:50.046](0.026s) ok 18 - connect with wrong server root cert sslmode=verify-full [00:36:50.046](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [00:36:50.076](0.029s) ok 20 - connect with server CA cert, without root CA [00:36:50.076](0.000s) ok 21 - connect with server CA cert, without root CA: matches [00:36:50.142](0.066s) ok 22 - connect with correct server CA cert file sslmode=require [00:36:50.142](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [00:36:50.189](0.047s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [00:36:50.189](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [00:36:50.220](0.031s) ok 26 - connect with correct server CA cert file sslmode=verify-full [00:36:50.221](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [00:36:50.260](0.040s) ok 28 - cert root file that contains two certificates, order 1 [00:36:50.261](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr [00:36:50.326](0.065s) ok 30 - cert root file that contains two certificates, order 2 [00:36:50.326](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr [00:36:50.366](0.040s) ok 32 - connect with sslcertmode=disable [00:36:50.366](0.000s) ok 33 - connect with sslcertmode=disable: no stderr [00:36:50.394](0.027s) ok 34 - connect with sslcertmode=allow [00:36:50.394](0.000s) ok 35 - connect with sslcertmode=allow: no stderr [00:36:50.439](0.045s) ok 36 - connect with sslcertmode=require fails without a client certificate [00:36:50.440](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [00:36:50.479](0.039s) ok 38 - sslcrl option with invalid file name [00:36:50.479](0.000s) ok 39 - sslcrl option with invalid file name: no stderr [00:36:50.509](0.030s) ok 40 - CRL belonging to a different CA [00:36:50.509](0.000s) ok 41 - CRL belonging to a different CA: matches [00:36:50.548](0.038s) ok 42 - directory CRL belonging to a different CA [00:36:50.548](0.000s) ok 43 - directory CRL belonging to a different CA: matches [00:36:50.601](0.053s) ok 44 - CRL with a non-revoked cert [00:36:50.601](0.000s) ok 45 - CRL with a non-revoked cert: no stderr [00:36:50.647](0.046s) ok 46 - directory CRL with a non-revoked cert [00:36:50.648](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr [00:36:50.681](0.033s) ok 48 - mismatch between host name and server certificate sslmode=require [00:36:50.681](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [00:36:50.708](0.027s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [00:36:50.708](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [00:36:50.728](0.020s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [00:36:50.729](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 28978 [00:36:51.010](0.281s) ok 54 - IP address in the Common Name [00:36:51.010](0.000s) ok 55 - IP address in the Common Name: no stderr [00:36:51.059](0.049s) ok 56 - mismatch between host name and server certificate IP address [00:36:51.059](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 29047 [00:36:51.315](0.256s) ok 58 - IP address in a dNSName [00:36:51.315](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 29118 [00:36:51.593](0.278s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [00:36:51.594](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [00:36:51.632](0.038s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [00:36:51.632](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [00:36:51.663](0.031s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [00:36:51.663](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [00:36:51.687](0.024s) ok 66 - host name not matching with X.509 Subject Alternative Names [00:36:51.687](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [00:36:51.707](0.020s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [00:36:51.708](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 29218 [00:36:51.988](0.280s) ok 70 - host name matching with a single X.509 Subject Alternative Name [00:36:51.988](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [00:36:52.026](0.038s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [00:36:52.026](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [00:36:52.070](0.044s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [00:36:52.070](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 29270 [00:36:52.357](0.287s) ok 76 - host matching an IPv4 address (Subject Alternative Name 1) [00:36:52.358](0.000s) ok 77 - host matching an IPv4 address (Subject Alternative Name 1): no stderr [00:36:52.405](0.048s) ok 78 - host matching an IPv4 address in alternate form (Subject Alternative Name 1) [00:36:52.405](0.000s) ok 79 - host matching an IPv4 address in alternate form (Subject Alternative Name 1): no stderr [00:36:52.470](0.064s) ok 80 - host not matching an IPv4 address (Subject Alternative Name 1) [00:36:52.470](0.000s) ok 81 - host not matching an IPv4 address (Subject Alternative Name 1): matches [00:36:52.511](0.041s) ok 82 - host matching an IPv6 address (Subject Alternative Name 2) [00:36:52.511](0.000s) ok 83 - host matching an IPv6 address (Subject Alternative Name 2): no stderr [00:36:52.564](0.052s) ok 84 - host matching an IPv6 address in alternate form (Subject Alternative Name 2) [00:36:52.564](0.000s) ok 85 - host matching an IPv6 address in alternate form (Subject Alternative Name 2): no stderr [00:36:52.607](0.043s) ok 86 - host matching an IPv6 address in mixed form (Subject Alternative Name 2) [00:36:52.608](0.000s) ok 87 - host matching an IPv6 address in mixed form (Subject Alternative Name 2): no stderr [00:36:52.657](0.050s) ok 88 - host not matching an IPv6 address (Subject Alternative Name 2) [00:36:52.658](0.000s) ok 89 - host not matching an IPv6 address (Subject Alternative Name 2): matches [00:36:52.700](0.042s) ok 90 - IPv6 host with CIDR mask does not match [00:36:52.700](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 29361 [00:36:52.893](0.192s) ok 92 - certificate with both a CN and SANs 1 [00:36:52.893](0.000s) ok 93 - certificate with both a CN and SANs 1: no stderr [00:36:52.932](0.039s) ok 94 - certificate with both a CN and SANs 2 [00:36:52.932](0.000s) ok 95 - certificate with both a CN and SANs 2: no stderr [00:36:52.965](0.033s) ok 96 - certificate with both a CN and SANs ignores CN [00:36:52.966](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 29406 [00:36:53.258](0.293s) ok 98 - certificate with both a CN and IP SANs matches CN [00:36:53.259](0.000s) ok 99 - certificate with both a CN and IP SANs matches CN: no stderr [00:36:53.303](0.044s) ok 100 - certificate with both a CN and IP SANs matches SAN 1 [00:36:53.303](0.000s) ok 101 - certificate with both a CN and IP SANs matches SAN 1: no stderr [00:36:53.356](0.053s) ok 102 - certificate with both a CN and IP SANs matches SAN 2 [00:36:53.357](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 29467 [00:36:53.659](0.302s) ok 104 - certificate with both an IP CN and IP SANs 1 [00:36:53.659](0.000s) ok 105 - certificate with both an IP CN and IP SANs 1: no stderr [00:36:53.696](0.037s) ok 106 - certificate with both an IP CN and IP SANs 2 [00:36:53.697](0.000s) ok 107 - certificate with both an IP CN and IP SANs 2: no stderr [00:36:53.723](0.026s) ok 108 - certificate with both an IP CN and IP SANs ignores CN [00:36:53.723](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 29512 [00:36:54.041](0.318s) ok 110 - certificate with both an IP CN and DNS SANs matches CN [00:36:54.042](0.000s) ok 111 - certificate with both an IP CN and DNS SANs matches CN: no stderr [00:36:54.091](0.049s) ok 112 - certificate with both an IP CN and DNS SANs matches SAN 1 [00:36:54.091](0.000s) ok 113 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [00:36:54.156](0.065s) ok 114 - certificate with both an IP CN and DNS SANs matches SAN 2 [00:36:54.156](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 29583 [00:36:54.413](0.257s) ok 116 - server certificate without CN or SANs sslmode=verify-ca [00:36:54.414](0.000s) ok 117 - server certificate without CN or SANs sslmode=verify-ca: no stderr [00:36:54.473](0.059s) ok 118 - server certificate without CN or SANs sslmode=verify-full [00:36:54.473](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 29665 [00:36:54.727](0.254s) ok 120 - sslrootcert=system does not connect with private CA [00:36:54.727](0.000s) ok 121 - sslrootcert=system does not connect with private CA: matches [00:36:54.753](0.025s) ok 122 - sslrootcert=system only accepts sslmode=verify-full [00:36:54.753](0.000s) ok 123 - sslrootcert=system only accepts sslmode=verify-full: matches [00:36:54.823](0.070s) ok 124 - sslrootcert=system connects with overridden SSL_CERT_FILE [00:36:54.823](0.000s) ok 125 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [00:36:54.864](0.041s) ok 126 - sslrootcert=system defaults to sslmode=verify-full [00:36:54.864](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 29719 [00:36:55.167](0.303s) ok 128 - connects without client-side CRL [00:36:55.168](0.000s) ok 129 - connects without client-side CRL: no stderr [00:36:55.226](0.059s) ok 130 - does not connect with client-side CRL file [00:36:55.226](0.000s) ok 131 - does not connect with client-side CRL file: matches [00:36:55.263](0.037s) ok 132 - does not connect with client-side CRL directory [00:36:55.263](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() [00:36:55.303](0.039s) ok 134 - pg_stat_ssl view without client certificate: exit code 0 [00:36:55.303](0.000s) ok 135 - pg_stat_ssl view without client certificate: no stderr [00:36:55.303](0.000s) ok 136 - pg_stat_ssl view without client certificate: matches [00:36:55.360](0.057s) ok 137 - connection success with correct range of TLS protocol versions [00:36:55.360](0.000s) ok 138 - connection success with correct range of TLS protocol versions: no stderr [00:36:55.393](0.033s) ok 139 - connection failure with incorrect range of TLS protocol versions [00:36:55.394](0.000s) ok 140 - connection failure with incorrect range of TLS protocol versions: matches [00:36:55.415](0.021s) ok 141 - connection failure with an incorrect SSL protocol minimum bound [00:36:55.415](0.000s) ok 142 - connection failure with an incorrect SSL protocol minimum bound: matches [00:36:55.427](0.012s) ok 143 - connection failure with an incorrect SSL protocol maximum bound [00:36:55.428](0.000s) ok 144 - connection failure with an incorrect SSL protocol maximum bound: matches [00:36:55.428](0.000s) # running server tests [00:36:55.469](0.042s) ok 145 - certificate authorization fails without client cert [00:36:55.470](0.000s) ok 146 - certificate authorization fails without client cert: matches [00:36:55.535](0.065s) ok 147 - certificate authorization succeeds with correct client cert in PEM format [00:36:55.535](0.000s) ok 148 - certificate authorization succeeds with correct client cert in PEM format: no stderr [00:36:55.573](0.038s) ok 149 - certificate authorization succeeds with correct client cert in DER format [00:36:55.574](0.000s) ok 150 - certificate authorization succeeds with correct client cert in DER format: no stderr [00:36:55.622](0.049s) ok 151 - certificate authorization succeeds with correct client cert in encrypted PEM format [00:36:55.623](0.000s) ok 152 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [00:36:55.671](0.048s) ok 153 - certificate authorization succeeds with correct client cert in encrypted DER format [00:36:55.671](0.000s) ok 154 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [00:36:55.722](0.051s) ok 155 - certificate authorization succeeds with correct client cert and sslcertmode=require [00:36:55.722](0.000s) ok 156 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [00:36:55.754](0.032s) ok 157 - certificate authorization succeeds with correct client cert and sslcertmode=allow [00:36:55.754](0.000s) ok 158 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [00:36:55.812](0.058s) ok 159 - certificate authorization fails with correct client cert and sslcertmode=disable [00:36:55.812](0.000s) ok 160 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [00:36:55.876](0.063s) ok 161 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [00:36:55.876](0.000s) ok 162 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [00:36:55.947](0.071s) ok 163 - certificate authorization succeeds with DN mapping [00:36:55.947](0.000s) ok 164 - certificate authorization succeeds with DN mapping: no stderr [00:36:55.947](0.000s) ok 165 - certificate authorization succeeds with DN mapping: log matches [00:36:56.015](0.068s) ok 166 - certificate authorization succeeds with DN regex mapping [00:36:56.015](0.000s) ok 167 - certificate authorization succeeds with DN regex mapping: no stderr [00:36:56.078](0.062s) ok 168 - certificate authorization succeeds with CN mapping [00:36:56.078](0.000s) ok 169 - certificate authorization succeeds with CN mapping: no stderr [00:36:56.078](0.000s) ok 170 - certificate authorization succeeds with CN mapping: log matches [00:36:56.078](0.000s) not ok 171 # TODO & SKIP Need Pty support [00:36:56.079](0.000s) not ok 172 # TODO & SKIP Need Pty support [00:36:56.079](0.000s) not ok 173 # TODO & SKIP Need Pty support [00:36:56.079](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_twAx/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [00:36:56.146](0.067s) ok 175 - pg_stat_ssl with client certificate: exit code 0 [00:36:56.146](0.000s) ok 176 - pg_stat_ssl with client certificate: no stderr [00:36:56.147](0.000s) ok 177 - pg_stat_ssl with client certificate: matches [00:36:56.185](0.038s) ok 178 - certificate authorization fails because of file permissions [00:36:56.185](0.000s) ok 179 - certificate authorization fails because of file permissions: matches [00:36:56.235](0.050s) ok 180 - certificate authorization fails with client cert belonging to another user [00:36:56.235](0.000s) ok 181 - certificate authorization fails with client cert belonging to another user: matches [00:36:56.280](0.045s) ok 182 - certificate authorization fails with revoked client cert [00:36:56.280](0.000s) ok 183 - certificate authorization fails with revoked client cert: matches [00:36:56.281](0.000s) ok 184 - certificate authorization fails with revoked client cert: log does not match [00:36:56.335](0.054s) ok 185 - auth_option clientcert=verify-full succeeds with matching username and Common Name [00:36:56.335](0.000s) ok 186 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [00:36:56.335](0.000s) ok 187 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [00:36:56.377](0.041s) ok 188 - auth_option clientcert=verify-full fails with mismatching username and Common Name [00:36:56.377](0.000s) ok 189 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [00:36:56.377](0.000s) ok 190 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [00:36:56.414](0.037s) ok 191 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [00:36:56.415](0.000s) ok 192 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [00:36:56.415](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 30030 [00:36:56.639](0.224s) ok 194 - intermediate client certificate is provided by client [00:36:56.639](0.000s) ok 195 - intermediate client certificate is provided by client: no stderr [00:36:56.698](0.059s) ok 196 - intermediate client certificate is missing [00:36:56.698](0.000s) ok 197 - intermediate client certificate is missing: matches [00:36:56.723](0.025s) ok 198 - logged client certificate Subjects are truncated if they're too long [00:36:56.723](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 30088 [00:36:56.900](0.177s) ok 200 - intermediate client certificate is untrusted [00:36:56.901](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 30171 [00:36:57.162](0.262s) ok 202 - certificate authorization fails with revoked client cert with server-side CRL directory [00:36:57.163](0.000s) ok 203 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [00:36:57.228](0.065s) ok 204 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [00:36:57.228](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 30260 [00:36:57.580](0.352s) not ok 206 - connect with valid stapled ocsp response when sslocspstapling=1 [00:36:57.580](0.000s) [00:36:57.580](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at t/001_ssltests.pl line 923. [00:36:57.580](0.000s) # got: '2' # expected: '0' [00:36:57.581](0.000s) not ok 207 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [00:36:57.581](0.000s) [00:36:57.581](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at t/001_ssltests.pl line 923. [00:36:57.581](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 61742 failed: SSL error: ocsp callback failure' # expected: '' [00:36:57.641](0.060s) ok 208 - connect without requesting ocsp response when sslocspstapling=0 [00:36:57.641](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 30326 [00:36:57.907](0.266s) ok 210 - failed with a revoked ocsp response when sslocspstapling=1 [00:36:57.963](0.056s) ok 211 - connect without requesting ocsp response when sslocspstapling=0 [00:36:57.963](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 30365 [00:36:58.219](0.255s) ok 213 - failed with a revoked ocsp response when sslocspstapling=1 [00:36:58.279](0.061s) ok 214 - connect without requesting ocsp response when sslocspstapling=0 [00:36:58.279](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 30420 [00:36:58.532](0.253s) ok 216 - failed with an expired ocsp response when sslocspstapling=1 [00:36:58.581](0.049s) ok 217 - connect without requesting ocsp response when sslocspstapling=0 [00:36:58.582](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 30477 [00:36:58.854](0.272s) not ok 219 - connect with valid stapled ocsp response when sslocspstapling=1 [00:36:58.854](0.000s) [00:36:58.854](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at t/001_ssltests.pl line 1001. [00:36:58.854](0.000s) # got: '2' # expected: '0' [00:36:58.854](0.000s) not ok 220 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [00:36:58.854](0.000s) [00:36:58.854](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at t/001_ssltests.pl line 1001. [00:36:58.855](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 61742 failed: SSL error: ocsp callback failure' # expected: '' [00:36:58.916](0.061s) ok 221 - connect without requesting ocsp response when sslocspstapling=0 [00:36:58.916](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 30545 [00:36:59.194](0.278s) ok 223 - failed with a revoked ocsp response when sslocspstapling=1 [00:36:59.259](0.064s) ok 224 - connect without requesting ocsp response when sslocspstapling=0 [00:36:59.259](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 30599 [00:36:59.522](0.263s) ok 226 - failed with a revoked ocsp response when sslocspstapling=1 [00:36:59.589](0.067s) ok 227 - connect without requesting ocsp response when sslocspstapling=0 [00:36:59.589](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 30652 [00:36:59.848](0.259s) ok 229 - failed with an expired ocsp response when sslocspstapling=1 [00:36:59.903](0.055s) ok 230 - connect without requesting ocsp response when sslocspstapling=0 [00:36:59.903](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 30703 [00:37:00.077](0.174s) ok 232 - failed with an expired ocsp response when sslocspstapling=1 [00:37:00.146](0.069s) ok 233 - connect without requesting ocsp response when sslocspstapling=0 [00:37:00.146](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-06 00:36:47.384 UTC [28211][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-06 00:36:47.384 UTC [28211][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:47.391 UTC [28225][startup] LOG: database system was shut down at 2024-03-06 00:35:15 UTC 2024-03-06 00:36:47.410 UTC [28211][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:47.435 UTC [28234][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.436 UTC [28234][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-06 00:36:47.436 UTC [28234][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.462 UTC [28234][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-06 00:36:47.464 UTC [28234][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.493 UTC [28243][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.495 UTC [28243][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-06 00:36:47.495 UTC [28243][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.506 UTC [28243][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-06 00:36:47.509 UTC [28243][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.017 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.541 UTC [28256][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.542 UTC [28256][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-06 00:36:47.542 UTC [28256][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.544 UTC [28256][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-06 00:36:47.544 UTC [28256][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.003 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.579 UTC [28270][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.580 UTC [28270][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-06 00:36:47.580 UTC [28270][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.581 UTC [28270][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-06 00:36:47.583 UTC [28270][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.627 UTC [28283][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.628 UTC [28283][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-06 00:36:47.628 UTC [28283][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.636 UTC [28283][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-06 00:36:47.641 UTC [28283][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.674 UTC [28296][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.675 UTC [28296][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-06 00:36:47.675 UTC [28296][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.677 UTC [28296][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-06 00:36:47.766 UTC [28296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.091 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.805 UTC [28314][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.806 UTC [28314][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-06 00:36:47.806 UTC [28314][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.807 UTC [28314][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-06 00:36:47.860 UTC [28314][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.055 user=postgres database=postgres host=[local] 2024-03-06 00:36:47.928 UTC [28345][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:47.929 UTC [28345][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-06 00:36:47.929 UTC [28345][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:47.930 UTC [28345][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-06 00:36:47.968 UTC [28345][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.040 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.080 UTC [28373][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.081 UTC [28373][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-06 00:36:48.081 UTC [28373][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.083 UTC [28373][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-06 00:36:48.190 UTC [28373][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.115 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.350 UTC [28430][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.351 UTC [28430][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-06 00:36:48.351 UTC [28430][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.353 UTC [28430][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-06 00:36:48.406 UTC [28430][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.056 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.491 UTC [28442][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-06 00:36:48.492 UTC [28442][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-06 00:36:48.492 UTC [28442][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-06 00:36:48.494 UTC [28442][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-06 00:36:48.559 UTC [28442][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.067 user=postgres database=postgres host=[local] 2024-03-06 00:36:48.605 UTC [28211][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:48.605 UTC [28211][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:48.617 UTC [28211][postmaster] LOG: background worker "logical replication launcher" (PID 28231) exited with exit code 1 2024-03-06 00:36:48.618 UTC [28223][checkpointer] LOG: shutting down 2024-03-06 00:36:48.618 UTC [28223][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:48.736 UTC [28223][checkpointer] LOG: checkpoint complete: wrote 5650 buffers (34.5%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.118 s, sync=0.001 s, total=0.119 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45479 kB, estimate=45479 kB; lsn=0/4196518, redo lsn=0/4196518 2024-03-06 00:36:48.759 UTC [28211][postmaster] LOG: database system is shut down 2024-03-06 00:36:48.836 UTC [28475][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-06 00:36:48.836 UTC [28475][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:48.836 UTC [28475][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:48.855 UTC [28489][startup] LOG: database system was shut down at 2024-03-06 00:36:48 UTC 2024-03-06 00:36:48.863 UTC [28475][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:48.917 UTC [28475][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:48.917 UTC [28475][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:48.922 UTC [28475][postmaster] LOG: background worker "logical replication launcher" (PID 28497) exited with exit code 1 2024-03-06 00:36:48.926 UTC [28487][checkpointer] LOG: shutting down 2024-03-06 00:36:48.926 UTC [28487][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:48.927 UTC [28487][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/4196590, redo lsn=0/4196590 2024-03-06 00:36:48.933 UTC [28475][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.072 UTC [28543][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-06 00:36:49.072 UTC [28543][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.186 UTC [28560][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-06 00:36:49.186 UTC [28560][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:49.186 UTC [28560][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:49.197 UTC [28565][startup] LOG: database system was shut down at 2024-03-06 00:36:48 UTC 2024-03-06 00:36:49.219 UTC [28560][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:49.243 UTC [28560][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:49.243 UTC [28560][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:49.248 UTC [28560][postmaster] LOG: background worker "logical replication launcher" (PID 28569) exited with exit code 1 2024-03-06 00:36:49.253 UTC [28563][checkpointer] LOG: shutting down 2024-03-06 00:36:49.253 UTC [28563][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:49.254 UTC [28563][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/4196608, redo lsn=0/4196608 2024-03-06 00:36:49.261 UTC [28560][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.383 UTC [28596][postmaster] FATAL: could not set SSL protocol version range 2024-03-06 00:36:49.383 UTC [28596][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-06 00:36:49.383 UTC [28596][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.505 UTC [28619][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-06 00:36:49.505 UTC [28619][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:49.505 UTC [28619][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:49.509 UTC [28637][startup] LOG: database system was shut down at 2024-03-06 00:36:49 UTC 2024-03-06 00:36:49.518 UTC [28619][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:49.570 UTC [28619][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:49.570 UTC [28619][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:49.579 UTC [28619][postmaster] LOG: background worker "logical replication launcher" (PID 28642) exited with exit code 1 2024-03-06 00:36:49.580 UTC [28635][checkpointer] LOG: shutting down 2024-03-06 00:36:49.580 UTC [28635][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:49.581 UTC [28635][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/4196680, redo lsn=0/4196680 2024-03-06 00:36:49.586 UTC [28619][postmaster] LOG: database system is shut down 2024-03-06 00:36:49.709 UTC [28681][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-06 00:36:49.709 UTC [28681][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:49.709 UTC [28681][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:49.724 UTC [28686][startup] LOG: database system was shut down at 2024-03-06 00:36:49 UTC 2024-03-06 00:36:49.733 UTC [28681][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:49.794 UTC [28704][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42450 2024-03-06 00:36:49.794 UTC [28704][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-06 00:36:49.794 UTC [28704][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "localhost", forward lookup not checked. 2024-03-06 00:36:49.818 UTC [28709][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42452 2024-03-06 00:36:49.843 UTC [28709][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-06 00:36:49.843 UTC [28709][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-06 00:36:49.875 UTC [28709][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-06 00:36:49.877 UTC [28709][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.059 user=ssltestuser database=trustdb host=localhost port=42452 2024-03-06 00:36:49.897 UTC [28725][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42466 2024-03-06 00:36:49.899 UTC [28725][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-06 00:36:49.936 UTC [28731][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42480 2024-03-06 00:36:49.943 UTC [28731][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-06 00:36:49.972 UTC [28738][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42486 2024-03-06 00:36:49.982 UTC [28738][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-06 00:36:50.010 UTC [28753][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42492 2024-03-06 00:36:50.022 UTC [28753][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-06 00:36:50.037 UTC [28761][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42502 2024-03-06 00:36:50.048 UTC [28761][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-06 00:36:50.067 UTC [28773][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42516 2024-03-06 00:36:50.078 UTC [28773][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-06 00:36:50.115 UTC [28786][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42528 2024-03-06 00:36:50.126 UTC [28786][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-06 00:36:50.126 UTC [28786][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-06 00:36:50.137 UTC [28786][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-06 00:36:50.141 UTC [28786][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=localhost port=42528 2024-03-06 00:36:50.170 UTC [28802][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42540 2024-03-06 00:36:50.177 UTC [28802][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-06 00:36:50.177 UTC [28802][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-06 00:36:50.185 UTC [28802][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-06 00:36:50.188 UTC [28802][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=42540 2024-03-06 00:36:50.207 UTC [28812][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42546 2024-03-06 00:36:50.215 UTC [28812][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-06 00:36:50.215 UTC [28812][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-06 00:36:50.216 UTC [28812][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-06 00:36:50.220 UTC [28812][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=trustdb host=localhost port=42546 2024-03-06 00:36:50.247 UTC [28820][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42560 2024-03-06 00:36:50.254 UTC [28820][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-06 00:36:50.254 UTC [28820][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-06 00:36:50.256 UTC [28820][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-06 00:36:50.260 UTC [28820][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=42560 2024-03-06 00:36:50.306 UTC [28835][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42568 2024-03-06 00:36:50.314 UTC [28835][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-06 00:36:50.314 UTC [28835][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-06 00:36:50.316 UTC [28835][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-06 00:36:50.320 UTC [28835][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=ssltestuser database=trustdb host=localhost port=42568 2024-03-06 00:36:50.351 UTC [28846][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42582 2024-03-06 00:36:50.357 UTC [28846][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-06 00:36:50.357 UTC [28846][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-06 00:36:50.359 UTC [28846][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-06 00:36:50.365 UTC [28846][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=42582 2024-03-06 00:36:50.380 UTC [28852][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42586 2024-03-06 00:36:50.387 UTC [28852][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-06 00:36:50.388 UTC [28852][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-06 00:36:50.389 UTC [28852][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-06 00:36:50.396 UTC [28852][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=ssltestuser database=trustdb host=localhost port=42586 2024-03-06 00:36:50.421 UTC [28865][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42592 2024-03-06 00:36:50.430 UTC [28865][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-06 00:36:50.430 UTC [28865][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-06 00:36:50.435 UTC [28865][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=trustdb host=localhost port=42592 2024-03-06 00:36:50.457 UTC [28874][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42606 2024-03-06 00:36:50.467 UTC [28874][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-06 00:36:50.467 UTC [28874][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-06 00:36:50.469 UTC [28874][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-06 00:36:50.473 UTC [28874][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.017 user=ssltestuser database=trustdb host=localhost port=42606 2024-03-06 00:36:50.495 UTC [28879][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42614 2024-03-06 00:36:50.511 UTC [28879][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-06 00:36:50.535 UTC [28886][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42622 2024-03-06 00:36:50.545 UTC [28886][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-06 00:36:50.584 UTC [28894][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42626 2024-03-06 00:36:50.595 UTC [28894][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-06 00:36:50.595 UTC [28894][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-06 00:36:50.597 UTC [28894][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-06 00:36:50.603 UTC [28894][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=localhost port=42626 2024-03-06 00:36:50.628 UTC [28904][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42642 2024-03-06 00:36:50.640 UTC [28904][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-06 00:36:50.640 UTC [28904][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-06 00:36:50.643 UTC [28904][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-06 00:36:50.644 UTC [28904][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=ssltestuser database=trustdb host=localhost port=42642 2024-03-06 00:36:50.664 UTC [28913][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42650 2024-03-06 00:36:50.673 UTC [28913][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-06 00:36:50.673 UTC [28913][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-06 00:36:50.676 UTC [28913][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-06 00:36:50.676 UTC [28913][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=42650 2024-03-06 00:36:50.696 UTC [28923][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42652 2024-03-06 00:36:50.702 UTC [28923][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-06 00:36:50.702 UTC [28923][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-06 00:36:50.704 UTC [28923][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-06 00:36:50.706 UTC [28923][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=42652 2024-03-06 00:36:50.719 UTC [28929][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42656 2024-03-06 00:36:50.732 UTC [28681][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:50.732 UTC [28681][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:50.741 UTC [28681][postmaster] LOG: background worker "logical replication launcher" (PID 28691) exited with exit code 1 2024-03-06 00:36:50.742 UTC [28684][checkpointer] LOG: shutting down 2024-03-06 00:36:50.742 UTC [28684][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:50.743 UTC [28684][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/41966F8, redo lsn=0/41966F8 2024-03-06 00:36:50.749 UTC [28681][postmaster] LOG: database system is shut down 2024-03-06 00:36:50.872 UTC [28978][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-06 00:36:50.872 UTC [28978][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:50.872 UTC [28978][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:50.880 UTC [28990][startup] LOG: database system was shut down at 2024-03-06 00:36:50 UTC 2024-03-06 00:36:50.889 UTC [28978][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:50.969 UTC [29016][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42668 2024-03-06 00:36:50.991 UTC [29016][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-06 00:36:50.991 UTC [29016][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-06 00:36:51.005 UTC [29016][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-06 00:36:51.009 UTC [29016][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.040 user=ssltestuser database=trustdb host=localhost port=42668 2024-03-06 00:36:51.043 UTC [29029][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42670 2024-03-06 00:36:51.070 UTC [28978][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:51.070 UTC [28978][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:51.079 UTC [28978][postmaster] LOG: background worker "logical replication launcher" (PID 28994) exited with exit code 1 2024-03-06 00:36:51.079 UTC [28987][checkpointer] LOG: shutting down 2024-03-06 00:36:51.079 UTC [28987][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:51.080 UTC [28987][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/4196770, redo lsn=0/4196770 2024-03-06 00:36:51.086 UTC [28978][postmaster] LOG: database system is shut down 2024-03-06 00:36:51.208 UTC [29047][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-06 00:36:51.208 UTC [29047][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:51.208 UTC [29047][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:51.220 UTC [29063][startup] LOG: database system was shut down at 2024-03-06 00:36:51 UTC 2024-03-06 00:36:51.235 UTC [29047][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:51.289 UTC [29085][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42680 2024-03-06 00:36:51.295 UTC [29085][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-06 00:36:51.295 UTC [29085][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-06 00:36:51.310 UTC [29085][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-06 00:36:51.314 UTC [29085][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=localhost port=42680 2024-03-06 00:36:51.319 UTC [29047][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:51.319 UTC [29047][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:51.323 UTC [29047][postmaster] LOG: background worker "logical replication launcher" (PID 29071) exited with exit code 1 2024-03-06 00:36:51.327 UTC [29060][checkpointer] LOG: shutting down 2024-03-06 00:36:51.327 UTC [29060][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:51.328 UTC [29060][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/41967E8, redo lsn=0/41967E8 2024-03-06 00:36:51.334 UTC [29047][postmaster] LOG: database system is shut down 2024-03-06 00:36:51.449 UTC [29118][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-06 00:36:51.449 UTC [29118][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:51.449 UTC [29118][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:51.456 UTC [29130][startup] LOG: database system was shut down at 2024-03-06 00:36:51 UTC 2024-03-06 00:36:51.465 UTC [29118][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:51.533 UTC [29146][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42694 2024-03-06 00:36:51.539 UTC [29146][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-06 00:36:51.561 UTC [29146][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-06 00:36:51.589 UTC [29146][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-06 00:36:51.595 UTC [29146][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.062 user=ssltestuser database=trustdb host=localhost port=42694 2024-03-06 00:36:51.619 UTC [29167][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42704 2024-03-06 00:36:51.626 UTC [29167][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-06 00:36:51.626 UTC [29167][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-06 00:36:51.627 UTC [29167][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-06 00:36:51.633 UTC [29167][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.015 user=ssltestuser database=trustdb host=localhost port=42704 2024-03-06 00:36:51.648 UTC [29183][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42716 2024-03-06 00:36:51.656 UTC [29183][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-06 00:36:51.656 UTC [29183][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-06 00:36:51.659 UTC [29183][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-06 00:36:51.659 UTC [29183][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=42716 2024-03-06 00:36:51.677 UTC [29190][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42720 2024-03-06 00:36:51.698 UTC [29193][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=42734 2024-03-06 00:36:51.711 UTC [29118][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:51.711 UTC [29118][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:51.718 UTC [29118][postmaster] LOG: background worker "logical replication launcher" (PID 29133) exited with exit code 1 2024-03-06 00:36:51.719 UTC [29128][checkpointer] LOG: shutting down 2024-03-06 00:36:51.720 UTC [29128][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:51.720 UTC [29128][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/4196860, redo lsn=0/4196860 2024-03-06 00:36:51.726 UTC [29118][postmaster] LOG: database system is shut down 2024-03-06 00:36:51.865 UTC [29218][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-06 00:36:51.865 UTC [29218][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:51.865 UTC [29218][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:51.871 UTC [29225][startup] LOG: database system was shut down at 2024-03-06 00:36:51 UTC 2024-03-06 00:36:51.880 UTC [29218][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:51.950 UTC [29232][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57936 2024-03-06 00:36:51.957 UTC [29232][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-06 00:36:51.957 UTC [29232][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-06 00:36:51.984 UTC [29232][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-06 00:36:51.984 UTC [29232][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=localhost port=57936 2024-03-06 00:36:52.016 UTC [29238][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57938 2024-03-06 00:36:52.048 UTC [29243][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57952 2024-03-06 00:36:52.088 UTC [29218][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:52.088 UTC [29218][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:52.103 UTC [29218][postmaster] LOG: background worker "logical replication launcher" (PID 29228) exited with exit code 1 2024-03-06 00:36:52.103 UTC [29223][checkpointer] LOG: shutting down 2024-03-06 00:36:52.103 UTC [29223][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:52.104 UTC [29223][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/41968D8, redo lsn=0/41968D8 2024-03-06 00:36:52.109 UTC [29218][postmaster] LOG: database system is shut down 2024-03-06 00:36:52.251 UTC [29270][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-06 00:36:52.251 UTC [29270][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:52.251 UTC [29270][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:52.256 UTC [29277][startup] LOG: database system was shut down at 2024-03-06 00:36:52 UTC 2024-03-06 00:36:52.263 UTC [29270][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:52.331 UTC [29298][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57964 2024-03-06 00:36:52.337 UTC [29298][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-06 00:36:52.337 UTC [29298][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-06 00:36:52.353 UTC [29298][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-06 00:36:52.360 UTC [29298][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=localhost port=57964 2024-03-06 00:36:52.393 UTC [29308][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57966 2024-03-06 00:36:52.400 UTC [29308][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-06 00:36:52.400 UTC [29308][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-06 00:36:52.401 UTC [29308][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-06 00:36:52.407 UTC [29308][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=57966 2024-03-06 00:36:52.441 UTC [29314][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57968 2024-03-06 00:36:52.497 UTC [29321][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57972 2024-03-06 00:36:52.506 UTC [29321][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-06 00:36:52.506 UTC [29321][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-06 00:36:52.507 UTC [29321][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-06 00:36:52.510 UTC [29321][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=trustdb host=localhost port=57972 2024-03-06 00:36:52.541 UTC [29328][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57982 2024-03-06 00:36:52.551 UTC [29328][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-06 00:36:52.551 UTC [29328][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-06 00:36:52.553 UTC [29328][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-06 00:36:52.556 UTC [29328][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.015 user=ssltestuser database=trustdb host=localhost port=57982 2024-03-06 00:36:52.593 UTC [29336][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57984 2024-03-06 00:36:52.601 UTC [29336][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-06 00:36:52.601 UTC [29336][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-06 00:36:52.603 UTC [29336][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-06 00:36:52.609 UTC [29336][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=57984 2024-03-06 00:36:52.638 UTC [29345][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=57986 2024-03-06 00:36:52.685 UTC [29352][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58000 2024-03-06 00:36:52.718 UTC [29270][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:52.718 UTC [29270][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:52.723 UTC [29270][postmaster] LOG: background worker "logical replication launcher" (PID 29282) exited with exit code 1 2024-03-06 00:36:52.730 UTC [29275][checkpointer] LOG: shutting down 2024-03-06 00:36:52.730 UTC [29275][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:52.731 UTC [29275][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/4196950, redo lsn=0/4196950 2024-03-06 00:36:52.737 UTC [29270][postmaster] LOG: database system is shut down 2024-03-06 00:36:52.797 UTC [29361][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-06 00:36:52.797 UTC [29361][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:52.797 UTC [29361][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:52.804 UTC [29370][startup] LOG: database system was shut down at 2024-03-06 00:36:52 UTC 2024-03-06 00:36:52.813 UTC [29361][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:52.861 UTC [29386][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58014 2024-03-06 00:36:52.868 UTC [29386][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-06 00:36:52.868 UTC [29386][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-06 00:36:52.884 UTC [29386][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-06 00:36:52.894 UTC [29386][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=localhost port=58014 2024-03-06 00:36:52.919 UTC [29392][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58022 2024-03-06 00:36:52.926 UTC [29392][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-06 00:36:52.926 UTC [29392][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-06 00:36:52.928 UTC [29392][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-06 00:36:52.931 UTC [29392][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=ssltestuser database=trustdb host=localhost port=58022 2024-03-06 00:36:52.956 UTC [29398][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58026 2024-03-06 00:36:52.988 UTC [29361][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:52.988 UTC [29361][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:52.993 UTC [29361][postmaster] LOG: background worker "logical replication launcher" (PID 29374) exited with exit code 1 2024-03-06 00:36:52.993 UTC [29368][checkpointer] LOG: shutting down 2024-03-06 00:36:52.994 UTC [29368][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:52.994 UTC [29368][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/41969C8, redo lsn=0/41969C8 2024-03-06 00:36:53.001 UTC [29361][postmaster] LOG: database system is shut down 2024-03-06 00:36:53.160 UTC [29406][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-06 00:36:53.160 UTC [29406][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:53.160 UTC [29406][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:53.168 UTC [29416][startup] LOG: database system was shut down at 2024-03-06 00:36:52 UTC 2024-03-06 00:36:53.177 UTC [29406][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:53.226 UTC [29422][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58038 2024-03-06 00:36:53.241 UTC [29422][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-06 00:36:53.241 UTC [29422][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-06 00:36:53.254 UTC [29422][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-06 00:36:53.258 UTC [29422][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=localhost port=58038 2024-03-06 00:36:53.287 UTC [29431][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58048 2024-03-06 00:36:53.294 UTC [29431][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-06 00:36:53.294 UTC [29431][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-06 00:36:53.299 UTC [29431][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-06 00:36:53.300 UTC [29431][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=localhost port=58048 2024-03-06 00:36:53.322 UTC [29438][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58052 2024-03-06 00:36:53.338 UTC [29438][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-06 00:36:53.338 UTC [29438][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-06 00:36:53.339 UTC [29438][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-06 00:36:53.343 UTC [29438][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=localhost port=58052 2024-03-06 00:36:53.369 UTC [29406][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:53.369 UTC [29406][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:53.383 UTC [29406][postmaster] LOG: background worker "logical replication launcher" (PID 29419) exited with exit code 1 2024-03-06 00:36:53.383 UTC [29414][checkpointer] LOG: shutting down 2024-03-06 00:36:53.383 UTC [29414][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:53.384 UTC [29414][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/4196A40, redo lsn=0/4196A40 2024-03-06 00:36:53.390 UTC [29406][postmaster] LOG: database system is shut down 2024-03-06 00:36:53.510 UTC [29467][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-06 00:36:53.510 UTC [29467][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:53.510 UTC [29467][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:53.539 UTC [29471][startup] LOG: database system was shut down at 2024-03-06 00:36:53 UTC 2024-03-06 00:36:53.548 UTC [29467][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:53.635 UTC [29490][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58064 2024-03-06 00:36:53.642 UTC [29490][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-06 00:36:53.642 UTC [29490][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-06 00:36:53.655 UTC [29490][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-06 00:36:53.661 UTC [29490][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=localhost port=58064 2024-03-06 00:36:53.682 UTC [29498][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58078 2024-03-06 00:36:53.690 UTC [29498][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-06 00:36:53.690 UTC [29498][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-06 00:36:53.692 UTC [29498][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-06 00:36:53.696 UTC [29498][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.013 user=ssltestuser database=trustdb host=localhost port=58078 2024-03-06 00:36:53.713 UTC [29503][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58082 2024-03-06 00:36:53.739 UTC [29467][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:53.739 UTC [29467][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:53.746 UTC [29467][postmaster] LOG: background worker "logical replication launcher" (PID 29477) exited with exit code 1 2024-03-06 00:36:53.752 UTC [29469][checkpointer] LOG: shutting down 2024-03-06 00:36:53.752 UTC [29469][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:53.753 UTC [29469][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/4196AB8, redo lsn=0/4196AB8 2024-03-06 00:36:53.760 UTC [29467][postmaster] LOG: database system is shut down 2024-03-06 00:36:53.898 UTC [29512][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-06 00:36:53.898 UTC [29512][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:53.898 UTC [29512][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:53.913 UTC [29524][startup] LOG: database system was shut down at 2024-03-06 00:36:53 UTC 2024-03-06 00:36:53.922 UTC [29512][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:53.972 UTC [29538][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58084 2024-03-06 00:36:53.992 UTC [29538][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-06 00:36:53.992 UTC [29538][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-06 00:36:54.037 UTC [29538][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-06 00:36:54.041 UTC [29538][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.070 user=ssltestuser database=trustdb host=localhost port=58084 2024-03-06 00:36:54.078 UTC [29554][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58094 2024-03-06 00:36:54.085 UTC [29554][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-06 00:36:54.085 UTC [29554][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-06 00:36:54.087 UTC [29554][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-06 00:36:54.090 UTC [29554][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=trustdb host=localhost port=58094 2024-03-06 00:36:54.143 UTC [29567][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58108 2024-03-06 00:36:54.150 UTC [29567][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-06 00:36:54.150 UTC [29567][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-06 00:36:54.152 UTC [29567][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-06 00:36:54.155 UTC [29567][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=ssltestuser database=trustdb host=localhost port=58108 2024-03-06 00:36:54.166 UTC [29512][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:54.166 UTC [29512][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:54.180 UTC [29512][postmaster] LOG: background worker "logical replication launcher" (PID 29529) exited with exit code 1 2024-03-06 00:36:54.181 UTC [29520][checkpointer] LOG: shutting down 2024-03-06 00:36:54.181 UTC [29520][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:54.182 UTC [29520][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/4196B30, redo lsn=0/4196B30 2024-03-06 00:36:54.189 UTC [29512][postmaster] LOG: database system is shut down 2024-03-06 00:36:54.300 UTC [29583][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-06 00:36:54.301 UTC [29583][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:54.301 UTC [29583][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:54.321 UTC [29600][startup] LOG: database system was shut down at 2024-03-06 00:36:54 UTC 2024-03-06 00:36:54.330 UTC [29583][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:54.387 UTC [29628][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58114 2024-03-06 00:36:54.394 UTC [29628][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-06 00:36:54.394 UTC [29628][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-06 00:36:54.407 UTC [29628][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-06 00:36:54.410 UTC [29628][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=localhost port=58114 2024-03-06 00:36:54.463 UTC [29637][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58130 2024-03-06 00:36:54.481 UTC [29583][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:54.481 UTC [29583][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:54.486 UTC [29583][postmaster] LOG: background worker "logical replication launcher" (PID 29607) exited with exit code 1 2024-03-06 00:36:54.495 UTC [29598][checkpointer] LOG: shutting down 2024-03-06 00:36:54.495 UTC [29598][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:54.495 UTC [29598][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/4196BA8, redo lsn=0/4196BA8 2024-03-06 00:36:54.502 UTC [29583][postmaster] LOG: database system is shut down 2024-03-06 00:36:54.632 UTC [29665][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-06 00:36:54.632 UTC [29665][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:54.632 UTC [29665][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:54.659 UTC [29679][startup] LOG: database system was shut down at 2024-03-06 00:36:54 UTC 2024-03-06 00:36:54.668 UTC [29665][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:54.709 UTC [29693][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58134 2024-03-06 00:36:54.719 UTC [29693][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-06 00:36:54.786 UTC [29701][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58150 2024-03-06 00:36:54.794 UTC [29701][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-06 00:36:54.794 UTC [29701][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-06 00:36:54.819 UTC [29701][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-06 00:36:54.819 UTC [29701][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=localhost port=58150 2024-03-06 00:36:54.852 UTC [29713][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58154 2024-03-06 00:36:54.872 UTC [29665][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:54.873 UTC [29665][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:54.882 UTC [29665][postmaster] LOG: background worker "logical replication launcher" (PID 29687) exited with exit code 1 2024-03-06 00:36:54.882 UTC [29677][checkpointer] LOG: shutting down 2024-03-06 00:36:54.882 UTC [29677][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:54.883 UTC [29677][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/4196C20, redo lsn=0/4196C20 2024-03-06 00:36:54.889 UTC [29665][postmaster] LOG: database system is shut down 2024-03-06 00:36:54.971 UTC [29719][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-06 00:36:54.971 UTC [29719][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:54.971 UTC [29719][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:55.003 UTC [29738][startup] LOG: database system was shut down at 2024-03-06 00:36:54 UTC 2024-03-06 00:36:55.018 UTC [29719][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:55.123 UTC [29766][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58168 2024-03-06 00:36:55.150 UTC [29766][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-06 00:36:55.150 UTC [29766][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-06 00:36:55.163 UTC [29766][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-06 00:36:55.167 UTC [29766][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.047 user=ssltestuser database=trustdb host=localhost port=58168 2024-03-06 00:36:55.207 UTC [29780][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58170 2024-03-06 00:36:55.217 UTC [29780][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-06 00:36:55.254 UTC [29793][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58178 2024-03-06 00:36:55.264 UTC [29793][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-06 00:36:55.283 UTC [29803][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58190 2024-03-06 00:36:55.294 UTC [29803][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-06 00:36:55.294 UTC [29803][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-06 00:36:55.296 UTC [29803][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-06 00:36:55.302 UTC [29803][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=localhost port=58190 2024-03-06 00:36:55.325 UTC [29813][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58202 2024-03-06 00:36:55.338 UTC [29813][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-06 00:36:55.338 UTC [29813][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-06 00:36:55.339 UTC [29813][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-06 00:36:55.343 UTC [29813][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=localhost port=58202 2024-03-06 00:36:55.459 UTC [29843][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58214 2024-03-06 00:36:55.466 UTC [29843][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-06 00:36:55.489 UTC [29851][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58220 2024-03-06 00:36:55.515 UTC [29851][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-06 00:36:55.515 UTC [29851][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-06 00:36:55.530 UTC [29851][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_twAx/client.key$$ 2024-03-06 00:36:55.534 UTC [29851][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.046 user=ssltestuser database=certdb host=localhost port=58220 2024-03-06 00:36:55.559 UTC [29866][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58230 2024-03-06 00:36:55.567 UTC [29866][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-06 00:36:55.567 UTC [29866][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-06 00:36:55.569 UTC [29866][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_twAx/client-der.key$$ 2024-03-06 00:36:55.573 UTC [29866][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=certdb host=localhost port=58230 2024-03-06 00:36:55.599 UTC [29871][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58244 2024-03-06 00:36:55.611 UTC [29871][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-06 00:36:55.611 UTC [29871][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-06 00:36:55.618 UTC [29871][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_twAx/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-06 00:36:55.624 UTC [29871][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=certdb host=localhost port=58244 2024-03-06 00:36:55.641 UTC [29885][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58252 2024-03-06 00:36:55.659 UTC [29885][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-06 00:36:55.659 UTC [29885][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-06 00:36:55.661 UTC [29885][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_twAx/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-06 00:36:55.665 UTC [29885][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=certdb host=localhost port=58252 2024-03-06 00:36:55.703 UTC [29892][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58266 2024-03-06 00:36:55.714 UTC [29892][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-06 00:36:55.714 UTC [29892][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-06 00:36:55.717 UTC [29892][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_twAx/client.key$$ 2024-03-06 00:36:55.718 UTC [29892][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=certdb host=localhost port=58266 2024-03-06 00:36:55.739 UTC [29902][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58282 2024-03-06 00:36:55.748 UTC [29902][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-06 00:36:55.748 UTC [29902][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-06 00:36:55.750 UTC [29902][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_twAx/client.key$$ 2024-03-06 00:36:55.753 UTC [29902][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=ssltestuser database=certdb host=localhost port=58282 2024-03-06 00:36:55.777 UTC [29909][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58294 2024-03-06 00:36:55.808 UTC [29909][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-06 00:36:55.852 UTC [29923][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58296 2024-03-06 00:36:55.870 UTC [29923][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-06 00:36:55.897 UTC [29933][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58308 2024-03-06 00:36:55.909 UTC [29933][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-06 00:36:55.909 UTC [29933][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-06 00:36:55.942 UTC [29933][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_twAx/client-dn.key$$ 2024-03-06 00:36:55.949 UTC [29933][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.053 user=ssltestuser database=certdb_dn host=localhost port=58308 2024-03-06 00:36:55.979 UTC [29949][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58312 2024-03-06 00:36:55.992 UTC [29949][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-06 00:36:55.992 UTC [29949][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-06 00:36:56.011 UTC [29949][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_twAx/client-dn.key$$ 2024-03-06 00:36:56.014 UTC [29949][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb_dn_re host=localhost port=58312 2024-03-06 00:36:56.048 UTC [29964][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58314 2024-03-06 00:36:56.057 UTC [29964][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-06 00:36:56.057 UTC [29964][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-06 00:36:56.073 UTC [29964][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_twAx/client-dn.key$$ 2024-03-06 00:36:56.082 UTC [29964][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb_cn host=localhost port=58314 2024-03-06 00:36:56.125 UTC [29974][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58328 2024-03-06 00:36:56.133 UTC [29974][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-06 00:36:56.134 UTC [29974][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-06 00:36:56.140 UTC [29974][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-06 00:36:56.148 UTC [29974][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=ssltestuser database=certdb host=localhost port=58328 2024-03-06 00:36:56.172 UTC [29982][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58340 2024-03-06 00:36:56.179 UTC [29982][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-06 00:36:56.213 UTC [29993][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58352 2024-03-06 00:36:56.231 UTC [29993][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-06 00:36:56.231 UTC [29993][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-06 00:36:56.231 UTC [29993][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-06 00:36:56.231 UTC [29993][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-06 00:36:56.261 UTC [29999][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58360 2024-03-06 00:36:56.273 UTC [29999][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-06 00:36:56.273 UTC [29999][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-06 00:36:56.297 UTC [30002][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58374 2024-03-06 00:36:56.309 UTC [30002][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-06 00:36:56.309 UTC [30002][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-06 00:36:56.330 UTC [30002][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_twAx/client.key$$ 2024-03-06 00:36:56.334 UTC [30002][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.037 user=ssltestuser database=verifydb host=localhost port=58374 2024-03-06 00:36:56.359 UTC [30011][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58386 2024-03-06 00:36:56.368 UTC [30011][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-06 00:36:56.368 UTC [30011][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-06 00:36:56.368 UTC [30011][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-06 00:36:56.368 UTC [30011][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-06 00:36:56.396 UTC [30021][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58402 2024-03-06 00:36:56.404 UTC [30021][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-06 00:36:56.404 UTC [30021][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-06 00:36:56.406 UTC [30021][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_twAx/client.key$$ 2024-03-06 00:36:56.409 UTC [30021][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.014 user=yetanotheruser database=verifydb host=localhost port=58402 2024-03-06 00:36:56.424 UTC [29719][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:56.424 UTC [29719][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:56.441 UTC [29719][postmaster] LOG: background worker "logical replication launcher" (PID 29752) exited with exit code 1 2024-03-06 00:36:56.441 UTC [29736][checkpointer] LOG: shutting down 2024-03-06 00:36:56.441 UTC [29736][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:56.442 UTC [29736][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/4196C98, redo lsn=0/4196C98 2024-03-06 00:36:56.448 UTC [29719][postmaster] LOG: database system is shut down 2024-03-06 00:36:56.518 UTC [30030][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-06 00:36:56.518 UTC [30030][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:56.518 UTC [30030][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:56.543 UTC [30047][startup] LOG: database system was shut down at 2024-03-06 00:36:56 UTC 2024-03-06 00:36:56.560 UTC [30030][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:56.594 UTC [30059][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58406 2024-03-06 00:36:56.615 UTC [30059][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-06 00:36:56.615 UTC [30059][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-06 00:36:56.634 UTC [30059][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_twAx/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-06 00:36:56.641 UTC [30059][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.047 user=ssltestuser database=certdb host=localhost port=58406 2024-03-06 00:36:56.667 UTC [30069][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58416 2024-03-06 00:36:56.689 UTC [30069][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-06 00:36:56.689 UTC [30069][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-06 00:36:56.712 UTC [30079][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58420 2024-03-06 00:36:56.722 UTC [30079][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-06 00:36:56.722 UTC [30079][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-06 00:36:56.737 UTC [30030][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:56.737 UTC [30030][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:56.747 UTC [30030][postmaster] LOG: background worker "logical replication launcher" (PID 30054) exited with exit code 1 2024-03-06 00:36:56.748 UTC [30039][checkpointer] LOG: shutting down 2024-03-06 00:36:56.748 UTC [30039][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:56.749 UTC [30039][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/4196D10, redo lsn=0/4196D10 2024-03-06 00:36:56.755 UTC [30030][postmaster] LOG: database system is shut down 2024-03-06 00:36:56.797 UTC [30088][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-06 00:36:56.797 UTC [30088][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:56.797 UTC [30088][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:56.807 UTC [30097][startup] LOG: database system was shut down at 2024-03-06 00:36:56 UTC 2024-03-06 00:36:56.816 UTC [30088][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:56.890 UTC [30124][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58434 2024-03-06 00:36:56.899 UTC [30124][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-06 00:36:56.899 UTC [30124][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-06 00:36:56.912 UTC [30088][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:56.913 UTC [30088][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:56.918 UTC [30088][postmaster] LOG: background worker "logical replication launcher" (PID 30104) exited with exit code 1 2024-03-06 00:36:56.920 UTC [30095][checkpointer] LOG: shutting down 2024-03-06 00:36:56.920 UTC [30095][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:56.921 UTC [30095][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/4196D88, redo lsn=0/4196D88 2024-03-06 00:36:56.927 UTC [30088][postmaster] LOG: database system is shut down 2024-03-06 00:36:57.068 UTC [30171][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-06 00:36:57.068 UTC [30171][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:57.069 UTC [30171][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:57.074 UTC [30188][startup] LOG: database system was shut down at 2024-03-06 00:36:56 UTC 2024-03-06 00:36:57.083 UTC [30171][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:57.143 UTC [30209][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58450 2024-03-06 00:36:57.164 UTC [30209][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-06 00:36:57.164 UTC [30209][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-06 00:36:57.215 UTC [30221][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58454 2024-03-06 00:36:57.227 UTC [30221][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-06 00:36:57.227 UTC [30221][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-06 00:36:57.235 UTC [30171][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:57.235 UTC [30171][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:57.245 UTC [30171][postmaster] LOG: background worker "logical replication launcher" (PID 30192) exited with exit code 1 2024-03-06 00:36:57.245 UTC [30185][checkpointer] LOG: shutting down 2024-03-06 00:36:57.245 UTC [30185][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:57.246 UTC [30185][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/4196E00, redo lsn=0/4196E00 2024-03-06 00:36:57.253 UTC [30171][postmaster] LOG: database system is shut down 2024-03-06 00:36:57.423 UTC [30260][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-06 00:36:57.423 UTC [30260][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:57.423 UTC [30260][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:57.439 UTC [30280][startup] LOG: database system was shut down at 2024-03-06 00:36:57 UTC 2024-03-06 00:36:57.447 UTC [30260][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:57.571 UTC [30299][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58470 2024-03-06 00:36:57.573 UTC [30299][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:57.574 UTC [30299][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:57.579 UTC [30299][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert internal error 2024-03-06 00:36:57.617 UTC [30305][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58484 2024-03-06 00:36:57.624 UTC [30305][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-06 00:36:57.624 UTC [30305][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-06 00:36:57.637 UTC [30305][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-06 00:36:57.642 UTC [30305][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=localhost port=58484 2024-03-06 00:36:57.649 UTC [30260][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:57.649 UTC [30260][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:57.654 UTC [30260][postmaster] LOG: background worker "logical replication launcher" (PID 30287) exited with exit code 1 2024-03-06 00:36:57.658 UTC [30277][checkpointer] LOG: shutting down 2024-03-06 00:36:57.658 UTC [30277][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:57.659 UTC [30277][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/4196E78, redo lsn=0/4196E78 2024-03-06 00:36:57.665 UTC [30260][postmaster] LOG: database system is shut down 2024-03-06 00:36:57.791 UTC [30326][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-06 00:36:57.791 UTC [30326][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:57.791 UTC [30326][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:57.815 UTC [30332][startup] LOG: database system was shut down at 2024-03-06 00:36:57 UTC 2024-03-06 00:36:57.823 UTC [30326][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:57.887 UTC [30346][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58498 2024-03-06 00:36:57.897 UTC [30346][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:57.897 UTC [30346][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-06 00:36:57.929 UTC [30350][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58508 2024-03-06 00:36:57.936 UTC [30350][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-06 00:36:57.936 UTC [30350][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-06 00:36:57.953 UTC [30350][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-06 00:36:57.970 UTC [30326][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:57.970 UTC [30326][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:57.976 UTC [30326][postmaster] LOG: background worker "logical replication launcher" (PID 30341) exited with exit code 1 2024-03-06 00:36:57.976 UTC [30350][client backend] [001_ssltests.pl][0/0:0] FATAL: terminating connection due to administrator command 2024-03-06 00:36:57.976 UTC [30350][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.049 user=ssltestuser database=trustdb host=localhost port=58508 2024-03-06 00:36:57.981 UTC [30330][checkpointer] LOG: shutting down 2024-03-06 00:36:57.981 UTC [30330][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:57.982 UTC [30330][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/4196EF0, redo lsn=0/4196EF0 2024-03-06 00:36:57.988 UTC [30326][postmaster] LOG: database system is shut down 2024-03-06 00:36:58.133 UTC [30365][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-06 00:36:58.133 UTC [30365][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:58.133 UTC [30365][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:58.145 UTC [30372][startup] LOG: database system was shut down at 2024-03-06 00:36:57 UTC 2024-03-06 00:36:58.158 UTC [30365][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:58.207 UTC [30383][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58510 2024-03-06 00:36:58.210 UTC [30383][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:58.213 UTC [30383][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:58.220 UTC [30383][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert internal error 2024-03-06 00:36:58.237 UTC [30396][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58522 2024-03-06 00:36:58.250 UTC [30396][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-06 00:36:58.250 UTC [30396][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-06 00:36:58.275 UTC [30396][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-06 00:36:58.281 UTC [30396][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.045 user=ssltestuser database=trustdb host=localhost port=58522 2024-03-06 00:36:58.286 UTC [30365][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:58.286 UTC [30365][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:58.291 UTC [30365][postmaster] LOG: background worker "logical replication launcher" (PID 30376) exited with exit code 1 2024-03-06 00:36:58.295 UTC [30370][checkpointer] LOG: shutting down 2024-03-06 00:36:58.295 UTC [30370][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:58.296 UTC [30370][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/4196F68, redo lsn=0/4196F68 2024-03-06 00:36:58.302 UTC [30365][postmaster] LOG: database system is shut down 2024-03-06 00:36:58.453 UTC [30420][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-06 00:36:58.454 UTC [30420][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:58.454 UTC [30420][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:58.471 UTC [30438][startup] LOG: database system was shut down at 2024-03-06 00:36:58 UTC 2024-03-06 00:36:58.481 UTC [30420][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:58.523 UTC [30456][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58524 2024-03-06 00:36:58.526 UTC [30456][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:58.526 UTC [30456][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:58.535 UTC [30456][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert internal error 2024-03-06 00:36:58.559 UTC [30464][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58526 2024-03-06 00:36:58.565 UTC [30464][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-06 00:36:58.565 UTC [30464][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-06 00:36:58.577 UTC [30464][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-06 00:36:58.581 UTC [30464][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=localhost port=58526 2024-03-06 00:36:58.589 UTC [30420][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:58.589 UTC [30420][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:58.597 UTC [30420][postmaster] LOG: background worker "logical replication launcher" (PID 30449) exited with exit code 1 2024-03-06 00:36:58.597 UTC [30435][checkpointer] LOG: shutting down 2024-03-06 00:36:58.597 UTC [30435][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:58.598 UTC [30435][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/4196FE0, redo lsn=0/4196FE0 2024-03-06 00:36:58.603 UTC [30420][postmaster] LOG: database system is shut down 2024-03-06 00:36:58.767 UTC [30477][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-06 00:36:58.767 UTC [30477][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:58.767 UTC [30477][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:58.778 UTC [30493][startup] LOG: database system was shut down at 2024-03-06 00:36:58 UTC 2024-03-06 00:36:58.794 UTC [30477][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:58.845 UTC [30504][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58542 2024-03-06 00:36:58.847 UTC [30504][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:58.848 UTC [30504][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:58.856 UTC [30504][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-06 00:36:58.876 UTC [30510][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58554 2024-03-06 00:36:58.889 UTC [30510][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-06 00:36:58.889 UTC [30510][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-06 00:36:58.911 UTC [30510][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-06 00:36:58.918 UTC [30510][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.043 user=ssltestuser database=trustdb host=localhost port=58554 2024-03-06 00:36:58.926 UTC [30477][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:58.926 UTC [30477][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:58.935 UTC [30477][postmaster] LOG: background worker "logical replication launcher" (PID 30499) exited with exit code 1 2024-03-06 00:36:58.935 UTC [30491][checkpointer] LOG: shutting down 2024-03-06 00:36:58.936 UTC [30491][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:58.936 UTC [30491][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/4197058, redo lsn=0/4197058 2024-03-06 00:36:58.942 UTC [30477][postmaster] LOG: database system is shut down 2024-03-06 00:36:59.098 UTC [30545][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-06 00:36:59.098 UTC [30545][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:59.098 UTC [30545][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:59.116 UTC [30554][startup] LOG: database system was shut down at 2024-03-06 00:36:58 UTC 2024-03-06 00:36:59.127 UTC [30545][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:59.175 UTC [30561][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58558 2024-03-06 00:36:59.180 UTC [30561][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:59.180 UTC [30561][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-06 00:36:59.224 UTC [30576][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58568 2024-03-06 00:36:59.230 UTC [30576][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-06 00:36:59.230 UTC [30576][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-06 00:36:59.254 UTC [30576][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-06 00:36:59.260 UTC [30576][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.041 user=ssltestuser database=trustdb host=localhost port=58568 2024-03-06 00:36:59.268 UTC [30545][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:59.268 UTC [30545][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:59.272 UTC [30545][postmaster] LOG: background worker "logical replication launcher" (PID 30559) exited with exit code 1 2024-03-06 00:36:59.276 UTC [30552][checkpointer] LOG: shutting down 2024-03-06 00:36:59.276 UTC [30552][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:59.276 UTC [30552][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/41970D0, redo lsn=0/41970D0 2024-03-06 00:36:59.282 UTC [30545][postmaster] LOG: database system is shut down 2024-03-06 00:36:59.409 UTC [30599][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-06 00:36:59.409 UTC [30599][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:59.409 UTC [30599][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:59.445 UTC [30608][startup] LOG: database system was shut down at 2024-03-06 00:36:59 UTC 2024-03-06 00:36:59.454 UTC [30599][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:59.511 UTC [30624][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58580 2024-03-06 00:36:59.514 UTC [30624][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:59.514 UTC [30624][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-06 00:36:59.551 UTC [30631][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58592 2024-03-06 00:36:59.559 UTC [30631][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-06 00:36:59.559 UTC [30631][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-06 00:36:59.584 UTC [30631][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-06 00:36:59.590 UTC [30631][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.043 user=ssltestuser database=trustdb host=localhost port=58592 2024-03-06 00:36:59.601 UTC [30599][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:59.601 UTC [30599][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:59.608 UTC [30599][postmaster] LOG: background worker "logical replication launcher" (PID 30620) exited with exit code 1 2024-03-06 00:36:59.610 UTC [30605][checkpointer] LOG: shutting down 2024-03-06 00:36:59.610 UTC [30605][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:59.611 UTC [30605][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/4197148, redo lsn=0/4197148 2024-03-06 00:36:59.617 UTC [30599][postmaster] LOG: database system is shut down 2024-03-06 00:36:59.762 UTC [30652][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-06 00:36:59.762 UTC [30652][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:59.763 UTC [30652][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:59.776 UTC [30664][startup] LOG: database system was shut down at 2024-03-06 00:36:59 UTC 2024-03-06 00:36:59.794 UTC [30652][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:36:59.838 UTC [30679][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58600 2024-03-06 00:36:59.840 UTC [30679][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:36:59.840 UTC [30679][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-06 00:36:59.878 UTC [30689][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58612 2024-03-06 00:36:59.887 UTC [30689][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-06 00:36:59.887 UTC [30689][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-06 00:36:59.899 UTC [30689][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-06 00:36:59.905 UTC [30689][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=localhost port=58612 2024-03-06 00:36:59.913 UTC [30652][postmaster] LOG: received fast shutdown request 2024-03-06 00:36:59.913 UTC [30652][postmaster] LOG: aborting any active transactions 2024-03-06 00:36:59.921 UTC [30652][postmaster] LOG: background worker "logical replication launcher" (PID 30674) exited with exit code 1 2024-03-06 00:36:59.921 UTC [30661][checkpointer] LOG: shutting down 2024-03-06 00:36:59.921 UTC [30661][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:36:59.922 UTC [30661][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/41971C0, redo lsn=0/41971C0 2024-03-06 00:36:59.927 UTC [30652][postmaster] LOG: database system is shut down 2024-03-06 00:36:59.970 UTC [30703][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-06 00:36:59.970 UTC [30703][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 61742 2024-03-06 00:36:59.970 UTC [30703][postmaster] LOG: listening on Unix socket "/tmp/lwpVoisUKW/.s.PGSQL.61742" 2024-03-06 00:36:59.975 UTC [30709][startup] LOG: database system was shut down at 2024-03-06 00:36:59 UTC 2024-03-06 00:36:59.983 UTC [30703][postmaster] LOG: database system is ready to accept connections 2024-03-06 00:37:00.062 UTC [30728][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58614 2024-03-06 00:37:00.069 UTC [30728][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-06 00:37:00.069 UTC [30728][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-06 00:37:00.103 UTC [30735][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=58622 2024-03-06 00:37:00.118 UTC [30735][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-06 00:37:00.118 UTC [30735][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-06 00:37:00.141 UTC [30735][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-06 00:37:00.144 UTC [30735][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.043 user=ssltestuser database=trustdb host=localhost port=58622 2024-03-06 00:37:00.158 UTC [30703][postmaster] LOG: received fast shutdown request 2024-03-06 00:37:00.158 UTC [30703][postmaster] LOG: aborting any active transactions 2024-03-06 00:37:00.163 UTC [30703][postmaster] LOG: background worker "logical replication launcher" (PID 30714) exited with exit code 1 2024-03-06 00:37:00.167 UTC [30707][checkpointer] LOG: shutting down 2024-03-06 00:37:00.167 UTC [30707][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-06 00:37:00.168 UTC [30707][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/4197238, redo lsn=0/4197238 2024-03-06 00:37:00.175 UTC [30703][postmaster] LOG: database system is shut down 2024-03-06 00:37:00.293 UTC [30755][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-06 00:37:00.293 UTC [30755][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [00:37:00.369](0.223s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"