[08:41:29.262](0.034s) # setting up data directory # Checking port 49632 # Found port 49632 Name: primary Data directory: /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata Backup directory: /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/backup Archive directory: /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/archives Connection string: port=49632 host=/tmp/aD0Ii2bonw Log file: /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/log/001_ssltests_primary.log [08:41:29.273](0.010s) # initializing database system by copying initdb template # Running: cp -RPp /tmp/cirrus-ci-build/build/tmp_install/initdb-template /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata # Running: /tmp/cirrus-ci-build/build/src/test/regress/pg_regress --config-auth /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata ### Starting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/log/001_ssltests_primary.log -o --cluster-name=primary start waiting for server to start.... done server started # Postmaster PID for node "primary" is 49927 [08:41:29.554](0.282s) ok 1 - ssl_library parameter ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50225 [08:41:30.559](1.004s) # testing password-protected keys ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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-26 08:41:29.482 UTC [49927][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:29.482 UTC [49927][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:29.494 UTC [49945][startup] LOG: database system was shut down at 2024-03-26 08:38:51 UTC 2024-03-26 08:41:29.497 UTC [49927][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:29.547 UTC [49973][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.548 UTC [49973][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.548 UTC [49973][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.553 UTC [49973][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-26 08:41:29.556 UTC [49973][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.564 UTC [49986][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.564 UTC [49986][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.564 UTC [49986][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.565 UTC [49986][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-26 08:41:29.566 UTC [49986][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.605 UTC [49993][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.606 UTC [49993][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.606 UTC [49993][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.607 UTC [49993][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-26 08:41:29.607 UTC [49993][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.001 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.663 UTC [50009][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.664 UTC [50009][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.664 UTC [50009][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.665 UTC [50009][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-26 08:41:29.666 UTC [50009][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.711 UTC [50026][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.712 UTC [50026][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.712 UTC [50026][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.712 UTC [50026][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-26 08:41:29.713 UTC [50026][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.748 UTC [50037][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.749 UTC [50037][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.749 UTC [50037][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.750 UTC [50037][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-26 08:41:29.784 UTC [50037][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.793 UTC [50050][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.794 UTC [50050][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.794 UTC [50050][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.795 UTC [50050][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-26 08:41:29.853 UTC [50050][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.059 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.918 UTC [50093][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.918 UTC [50093][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.918 UTC [50093][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.919 UTC [50093][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-26 08:41:29.946 UTC [50093][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.964 UTC [50104][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.964 UTC [50104][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.964 UTC [50104][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.972 UTC [50104][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-26 08:41:30.051 UTC [50104][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.086 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.111 UTC [50132][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:30.112 UTC [50132][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:30.112 UTC [50132][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:30.114 UTC [50132][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-26 08:41:30.159 UTC [50132][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.048 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.232 UTC [50165][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:30.232 UTC [50165][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:30.232 UTC [50165][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:30.233 UTC [50165][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-26 08:41:30.278 UTC [50165][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.046 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.354 UTC [49927][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.354 UTC [49927][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.355 UTC [49927][postmaster] LOG: background worker "logical replication launcher" (PID 49954) exited with exit code 1 2024-03-26 08:41:30.357 UTC [49943][checkpointer] LOG: shutting down 2024-03-26 08:41:30.358 UTC [49943][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.395 UTC [49943][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.038 s, sync=0.001 s, total=0.038 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414DB70, redo lsn=0/414DB70 2024-03-26 08:41:30.411 UTC [49927][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:30.500 UTC [50239][startup] LOG: database system was shut down at 2024-03-26 08:41:30 UTC 2024-03-26 08:41:30.504 UTC [50225][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:30.561 UTC [50225][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.561 UTC [50225][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.563 UTC [50225][postmaster] LOG: background worker "logical replication launcher" (PID 50244) exited with exit code 1 2024-03-26 08:41:30.564 UTC [50236][checkpointer] LOG: shutting down 2024-03-26 08:41:30.564 UTC [50236][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.565 UTC [50236][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/414DBE8, redo lsn=0/414DBE8 2024-03-26 08:41:30.568 UTC [50225][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.677 UTC [50282][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-26 08:41:30.677 UTC [50282][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [08:41:30.763](0.204s) ok 2 - restart fails with password-protected key file with wrong password ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/log/001_ssltests_primary.log restart pg_ctl: PID file "/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/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 50308 [08:41:30.867](0.104s) ok 3 - restart succeeds with password-protected key file ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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-26 08:41:29.482 UTC [49927][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:29.482 UTC [49927][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:29.494 UTC [49945][startup] LOG: database system was shut down at 2024-03-26 08:38:51 UTC 2024-03-26 08:41:29.497 UTC [49927][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:29.547 UTC [49973][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.548 UTC [49973][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.548 UTC [49973][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.553 UTC [49973][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-26 08:41:29.556 UTC [49973][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.564 UTC [49986][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.564 UTC [49986][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.564 UTC [49986][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.565 UTC [49986][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-26 08:41:29.566 UTC [49986][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.605 UTC [49993][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.606 UTC [49993][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.606 UTC [49993][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.607 UTC [49993][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-26 08:41:29.607 UTC [49993][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.001 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.663 UTC [50009][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.664 UTC [50009][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.664 UTC [50009][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.665 UTC [50009][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-26 08:41:29.666 UTC [50009][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.711 UTC [50026][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.712 UTC [50026][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.712 UTC [50026][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.712 UTC [50026][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-26 08:41:29.713 UTC [50026][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.748 UTC [50037][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.749 UTC [50037][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.749 UTC [50037][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.750 UTC [50037][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-26 08:41:29.784 UTC [50037][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.793 UTC [50050][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.794 UTC [50050][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.794 UTC [50050][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.795 UTC [50050][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-26 08:41:29.853 UTC [50050][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.059 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.918 UTC [50093][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.918 UTC [50093][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.918 UTC [50093][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.919 UTC [50093][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-26 08:41:29.946 UTC [50093][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.964 UTC [50104][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.964 UTC [50104][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.964 UTC [50104][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.972 UTC [50104][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-26 08:41:30.051 UTC [50104][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.086 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.111 UTC [50132][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:30.112 UTC [50132][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:30.112 UTC [50132][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:30.114 UTC [50132][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-26 08:41:30.159 UTC [50132][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.048 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.232 UTC [50165][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:30.232 UTC [50165][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:30.232 UTC [50165][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:30.233 UTC [50165][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-26 08:41:30.278 UTC [50165][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.046 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.354 UTC [49927][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.354 UTC [49927][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.355 UTC [49927][postmaster] LOG: background worker "logical replication launcher" (PID 49954) exited with exit code 1 2024-03-26 08:41:30.357 UTC [49943][checkpointer] LOG: shutting down 2024-03-26 08:41:30.358 UTC [49943][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.395 UTC [49943][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.038 s, sync=0.001 s, total=0.038 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414DB70, redo lsn=0/414DB70 2024-03-26 08:41:30.411 UTC [49927][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:30.500 UTC [50239][startup] LOG: database system was shut down at 2024-03-26 08:41:30 UTC 2024-03-26 08:41:30.504 UTC [50225][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:30.561 UTC [50225][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.561 UTC [50225][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.563 UTC [50225][postmaster] LOG: background worker "logical replication launcher" (PID 50244) exited with exit code 1 2024-03-26 08:41:30.564 UTC [50236][checkpointer] LOG: shutting down 2024-03-26 08:41:30.564 UTC [50236][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.565 UTC [50236][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/414DBE8, redo lsn=0/414DBE8 2024-03-26 08:41:30.568 UTC [50225][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.677 UTC [50282][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-26 08:41:30.677 UTC [50282][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.786 UTC [50308][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:30.786 UTC [50308][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:30.786 UTC [50308][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:30.788 UTC [50313][startup] LOG: database system was shut down at 2024-03-26 08:41:30 UTC 2024-03-26 08:41:30.792 UTC [50308][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:30.869 UTC [50308][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.869 UTC [50308][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.872 UTC [50308][postmaster] LOG: background worker "logical replication launcher" (PID 50316) exited with exit code 1 2024-03-26 08:41:30.872 UTC [50311][checkpointer] LOG: shutting down 2024-03-26 08:41:30.872 UTC [50311][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.872 UTC [50311][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/414DC60, redo lsn=0/414DC60 2024-03-26 08:41:30.875 UTC [50308][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.984 UTC [50361][postmaster] FATAL: could not set SSL protocol version range 2024-03-26 08:41:30.984 UTC [50361][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-26 08:41:30.984 UTC [50361][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [08:41:31.071](0.204s) ok 4 - restart fails with incorrect SSL protocol bounds ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/log/001_ssltests_primary.log restart pg_ctl: PID file "/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/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 50377 [08:41:31.174](0.104s) ok 5 - restart succeeds with correct SSL protocol bounds [08:41:31.175](0.000s) # running client tests ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50432 [08:41:31.387](0.212s) ok 6 - server doesn't accept non-SSL connections [08:41:31.388](0.000s) ok 7 - server doesn't accept non-SSL connections: matches [08:41:31.405](0.017s) ok 8 - connect without server root cert sslmode=require [08:41:31.405](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr [08:41:31.413](0.008s) ok 10 - connect without server root cert sslmode=verify-ca [08:41:31.413](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches [08:41:31.421](0.008s) ok 12 - connect without server root cert sslmode=verify-full [08:41:31.421](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches [08:41:31.431](0.010s) ok 14 - connect with wrong server root cert sslmode=require [08:41:31.431](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches [08:41:31.443](0.012s) ok 16 - connect with wrong server root cert sslmode=verify-ca [08:41:31.443](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [08:41:31.455](0.011s) ok 18 - connect with wrong server root cert sslmode=verify-full [08:41:31.455](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [08:41:31.467](0.012s) ok 20 - connect with server CA cert, without root CA [08:41:31.467](0.000s) ok 21 - connect with server CA cert, without root CA: matches [08:41:31.481](0.014s) ok 22 - connect with correct server CA cert file sslmode=require [08:41:31.481](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [08:41:31.498](0.017s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [08:41:31.499](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [08:41:31.512](0.014s) ok 26 - connect with correct server CA cert file sslmode=verify-full [08:41:31.512](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [08:41:31.527](0.014s) ok 28 - cert root file that contains two certificates, order 1 [08:41:31.527](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr [08:41:31.542](0.015s) ok 30 - cert root file that contains two certificates, order 2 [08:41:31.542](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr [08:41:31.557](0.015s) ok 32 - connect with sslcertmode=disable [08:41:31.557](0.000s) ok 33 - connect with sslcertmode=disable: no stderr [08:41:31.573](0.015s) ok 34 - connect with sslcertmode=allow [08:41:31.573](0.000s) ok 35 - connect with sslcertmode=allow: no stderr [08:41:31.587](0.014s) ok 36 - connect with sslcertmode=require fails without a client certificate [08:41:31.587](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [08:41:31.602](0.014s) ok 38 - sslcrl option with invalid file name [08:41:31.602](0.000s) ok 39 - sslcrl option with invalid file name: no stderr [08:41:31.614](0.012s) ok 40 - CRL belonging to a different CA [08:41:31.614](0.000s) ok 41 - CRL belonging to a different CA: matches [08:41:31.627](0.012s) ok 42 - directory CRL belonging to a different CA [08:41:31.627](0.000s) ok 43 - directory CRL belonging to a different CA: matches [08:41:31.643](0.016s) ok 44 - CRL with a non-revoked cert [08:41:31.643](0.000s) ok 45 - CRL with a non-revoked cert: no stderr [08:41:31.658](0.015s) ok 46 - directory CRL with a non-revoked cert [08:41:31.658](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr [08:41:31.676](0.018s) ok 48 - mismatch between host name and server certificate sslmode=require [08:41:31.676](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [08:41:31.690](0.014s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [08:41:31.691](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [08:41:31.703](0.013s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [08:41:31.704](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50557 [08:41:31.927](0.223s) ok 54 - IP address in the Common Name [08:41:31.927](0.000s) ok 55 - IP address in the Common Name: no stderr [08:41:31.939](0.012s) ok 56 - mismatch between host name and server certificate IP address [08:41:31.939](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50582 [08:41:32.161](0.222s) ok 58 - IP address in a dNSName [08:41:32.161](0.000s) ok 59 - IP address in a dNSName: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50606 [08:41:32.384](0.223s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [08:41:32.385](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [08:41:32.399](0.014s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [08:41:32.399](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [08:41:32.412](0.013s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [08:41:32.412](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [08:41:32.424](0.012s) ok 66 - host name not matching with X.509 Subject Alternative Names [08:41:32.424](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [08:41:32.435](0.011s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [08:41:32.435](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50642 [08:41:32.658](0.224s) ok 70 - host name matching with a single X.509 Subject Alternative Name [08:41:32.659](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [08:41:32.671](0.012s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [08:41:32.671](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [08:41:32.683](0.012s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [08:41:32.683](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50671 [08:41:32.909](0.226s) ok 76 - host matching an IPv4 address (Subject Alternative Name 1) [08:41:32.910](0.000s) ok 77 - host matching an IPv4 address (Subject Alternative Name 1): no stderr [08:41:32.924](0.014s) ok 78 - host matching an IPv4 address in alternate form (Subject Alternative Name 1) [08:41:32.924](0.000s) ok 79 - host matching an IPv4 address in alternate form (Subject Alternative Name 1): no stderr [08:41:32.937](0.013s) ok 80 - host not matching an IPv4 address (Subject Alternative Name 1) [08:41:32.937](0.000s) ok 81 - host not matching an IPv4 address (Subject Alternative Name 1): matches [08:41:32.953](0.015s) ok 82 - host matching an IPv6 address (Subject Alternative Name 2) [08:41:32.953](0.000s) ok 83 - host matching an IPv6 address (Subject Alternative Name 2): no stderr [08:41:32.968](0.015s) ok 84 - host matching an IPv6 address in alternate form (Subject Alternative Name 2) [08:41:32.969](0.000s) ok 85 - host matching an IPv6 address in alternate form (Subject Alternative Name 2): no stderr [08:41:32.982](0.014s) ok 86 - host matching an IPv6 address in mixed form (Subject Alternative Name 2) [08:41:32.983](0.000s) ok 87 - host matching an IPv6 address in mixed form (Subject Alternative Name 2): no stderr [08:41:32.995](0.013s) ok 88 - host not matching an IPv6 address (Subject Alternative Name 2) [08:41:32.995](0.000s) ok 89 - host not matching an IPv6 address (Subject Alternative Name 2): matches [08:41:33.008](0.012s) ok 90 - IPv6 host with CIDR mask does not match [08:41:33.008](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50709 [08:41:33.231](0.223s) ok 92 - certificate with both a CN and SANs 1 [08:41:33.231](0.000s) ok 93 - certificate with both a CN and SANs 1: no stderr [08:41:33.245](0.014s) ok 94 - certificate with both a CN and SANs 2 [08:41:33.246](0.000s) ok 95 - certificate with both a CN and SANs 2: no stderr [08:41:33.257](0.012s) ok 96 - certificate with both a CN and SANs ignores CN [08:41:33.258](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50724 [08:41:33.484](0.226s) ok 98 - certificate with both a CN and IP SANs matches CN [08:41:33.484](0.000s) ok 99 - certificate with both a CN and IP SANs matches CN: no stderr [08:41:33.499](0.015s) ok 100 - certificate with both a CN and IP SANs matches SAN 1 [08:41:33.499](0.000s) ok 101 - certificate with both a CN and IP SANs matches SAN 1: no stderr [08:41:33.514](0.015s) ok 102 - certificate with both a CN and IP SANs matches SAN 2 [08:41:33.514](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50738 [08:41:33.737](0.223s) ok 104 - certificate with both an IP CN and IP SANs 1 [08:41:33.737](0.000s) ok 105 - certificate with both an IP CN and IP SANs 1: no stderr [08:41:33.751](0.014s) ok 106 - certificate with both an IP CN and IP SANs 2 [08:41:33.751](0.000s) ok 107 - certificate with both an IP CN and IP SANs 2: no stderr [08:41:33.763](0.012s) ok 108 - certificate with both an IP CN and IP SANs ignores CN [08:41:33.763](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50752 [08:41:33.987](0.224s) ok 110 - certificate with both an IP CN and DNS SANs matches CN [08:41:33.987](0.000s) ok 111 - certificate with both an IP CN and DNS SANs matches CN: no stderr [08:41:34.003](0.016s) ok 112 - certificate with both an IP CN and DNS SANs matches SAN 1 [08:41:34.003](0.000s) ok 113 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [08:41:34.018](0.014s) ok 114 - certificate with both an IP CN and DNS SANs matches SAN 2 [08:41:34.018](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50766 [08:41:34.242](0.224s) ok 116 - server certificate without CN or SANs sslmode=verify-ca [08:41:34.242](0.000s) ok 117 - server certificate without CN or SANs sslmode=verify-ca: no stderr [08:41:34.255](0.013s) ok 118 - server certificate without CN or SANs sslmode=verify-full [08:41:34.255](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50778 [08:41:34.475](0.220s) ok 120 - sslrootcert=system does not connect with private CA [08:41:34.476](0.000s) ok 121 - sslrootcert=system does not connect with private CA: matches [08:41:34.484](0.008s) ok 122 - sslrootcert=system only accepts sslmode=verify-full [08:41:34.484](0.000s) ok 123 - sslrootcert=system only accepts sslmode=verify-full: matches [08:41:34.503](0.018s) ok 124 - sslrootcert=system connects with overridden SSL_CERT_FILE [08:41:34.503](0.000s) ok 125 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [08:41:34.516](0.013s) ok 126 - sslrootcert=system defaults to sslmode=verify-full [08:41:34.516](0.000s) ok 127 - sslrootcert=system defaults to sslmode=verify-full: matches ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50793 [08:41:34.739](0.223s) ok 128 - connects without client-side CRL [08:41:34.739](0.000s) ok 129 - connects without client-side CRL: no stderr [08:41:34.751](0.012s) ok 130 - does not connect with client-side CRL file [08:41:34.751](0.000s) ok 131 - does not connect with client-side CRL file: matches [08:41:34.762](0.011s) ok 132 - does not connect with client-side CRL directory [08:41:34.762](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() [08:41:34.777](0.014s) ok 134 - pg_stat_ssl view without client certificate: exit code 0 [08:41:34.777](0.000s) ok 135 - pg_stat_ssl view without client certificate: no stderr [08:41:34.777](0.000s) ok 136 - pg_stat_ssl view without client certificate: matches [08:41:34.791](0.014s) ok 137 - connection success with correct range of TLS protocol versions [08:41:34.791](0.000s) ok 138 - connection success with correct range of TLS protocol versions: no stderr [08:41:34.798](0.007s) ok 139 - connection failure with incorrect range of TLS protocol versions [08:41:34.798](0.000s) ok 140 - connection failure with incorrect range of TLS protocol versions: matches [08:41:34.805](0.007s) ok 141 - connection failure with an incorrect SSL protocol minimum bound [08:41:34.805](0.000s) ok 142 - connection failure with an incorrect SSL protocol minimum bound: matches [08:41:34.812](0.007s) ok 143 - connection failure with an incorrect SSL protocol maximum bound [08:41:34.812](0.000s) ok 144 - connection failure with an incorrect SSL protocol maximum bound: matches [08:41:34.812](0.000s) # running server tests [08:41:34.824](0.012s) ok 145 - certificate authorization fails without client cert [08:41:34.824](0.000s) ok 146 - certificate authorization fails without client cert: matches [08:41:34.843](0.019s) ok 147 - certificate authorization succeeds with correct client cert in PEM format [08:41:34.843](0.000s) ok 148 - certificate authorization succeeds with correct client cert in PEM format: no stderr [08:41:34.860](0.016s) ok 149 - certificate authorization succeeds with correct client cert in DER format [08:41:34.860](0.000s) ok 150 - certificate authorization succeeds with correct client cert in DER format: no stderr [08:41:34.877](0.017s) ok 151 - certificate authorization succeeds with correct client cert in encrypted PEM format [08:41:34.877](0.000s) ok 152 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [08:41:34.893](0.016s) ok 153 - certificate authorization succeeds with correct client cert in encrypted DER format [08:41:34.894](0.000s) ok 154 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [08:41:34.909](0.016s) ok 155 - certificate authorization succeeds with correct client cert and sslcertmode=require [08:41:34.909](0.000s) ok 156 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [08:41:34.924](0.015s) ok 157 - certificate authorization succeeds with correct client cert and sslcertmode=allow [08:41:34.925](0.000s) ok 158 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [08:41:34.936](0.012s) ok 159 - certificate authorization fails with correct client cert and sslcertmode=disable [08:41:34.937](0.000s) ok 160 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [08:41:34.946](0.009s) ok 161 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [08:41:34.946](0.000s) ok 162 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [08:41:34.966](0.020s) ok 163 - certificate authorization succeeds with DN mapping [08:41:34.966](0.000s) ok 164 - certificate authorization succeeds with DN mapping: no stderr [08:41:34.966](0.000s) ok 165 - certificate authorization succeeds with DN mapping: log matches [08:41:34.984](0.018s) ok 166 - certificate authorization succeeds with DN regex mapping [08:41:34.984](0.000s) ok 167 - certificate authorization succeeds with DN regex mapping: no stderr [08:41:35.002](0.018s) ok 168 - certificate authorization succeeds with CN mapping [08:41:35.002](0.000s) ok 169 - certificate authorization succeeds with CN mapping: no stderr [08:41:35.002](0.000s) ok 170 - certificate authorization succeeds with CN mapping: log matches [08:41:35.003](0.000s) not ok 171 # TODO & SKIP Need Pty support [08:41:35.003](0.000s) not ok 172 # TODO & SKIP Need Pty support [08:41:35.003](0.000s) not ok 173 # TODO & SKIP Need Pty support [08:41:35.003](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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [08:41:35.029](0.026s) ok 175 - pg_stat_ssl with client certificate: exit code 0 [08:41:35.029](0.000s) ok 176 - pg_stat_ssl with client certificate: no stderr [08:41:35.029](0.000s) ok 177 - pg_stat_ssl with client certificate: matches [08:41:35.039](0.009s) ok 178 - certificate authorization fails because of file permissions [08:41:35.039](0.000s) ok 179 - certificate authorization fails because of file permissions: matches [08:41:35.053](0.015s) ok 180 - certificate authorization fails with client cert belonging to another user [08:41:35.054](0.000s) ok 181 - certificate authorization fails with client cert belonging to another user: matches [08:41:35.067](0.013s) ok 182 - certificate authorization fails with revoked client cert [08:41:35.067](0.000s) ok 183 - certificate authorization fails with revoked client cert: matches [08:41:35.067](0.000s) ok 184 - certificate authorization fails with revoked client cert: log does not match [08:41:35.085](0.018s) ok 185 - auth_option clientcert=verify-full succeeds with matching username and Common Name [08:41:35.085](0.000s) ok 186 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [08:41:35.086](0.000s) ok 187 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [08:41:35.099](0.013s) ok 188 - auth_option clientcert=verify-full fails with mismatching username and Common Name [08:41:35.099](0.000s) ok 189 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [08:41:35.100](0.000s) ok 190 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [08:41:35.114](0.014s) ok 191 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [08:41:35.114](0.000s) ok 192 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [08:41:35.114](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50853 [08:41:35.339](0.225s) ok 194 - intermediate client certificate is provided by client [08:41:35.339](0.000s) ok 195 - intermediate client certificate is provided by client: no stderr [08:41:35.352](0.013s) ok 196 - intermediate client certificate is missing [08:41:35.352](0.000s) ok 197 - intermediate client certificate is missing: matches [08:41:35.365](0.012s) ok 198 - logged client certificate Subjects are truncated if they're too long [08:41:35.365](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50867 [08:41:35.583](0.218s) ok 200 - intermediate client certificate is untrusted [08:41:35.583](0.000s) ok 201 - intermediate client certificate is untrusted: matches ### Restarting node "primary" # Running: pg_ctl -w -D /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50877 [08:41:35.802](0.219s) ok 202 - certificate authorization fails with revoked client cert with server-side CRL directory [08:41:35.802](0.000s) ok 203 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [08:41:35.816](0.014s) ok 204 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [08:41:35.816](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50889 [08:41:36.031](0.215s) not ok 206 - connect with valid stapled ocsp response when sslocspstapling=1 [08:41:36.031](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at /tmp/cirrus-ci-build/src/test/ssl/t/001_ssltests.pl line 923. [08:41:36.032](0.000s) # got: '2' # expected: '0' [08:41:36.032](0.000s) not ok 207 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [08:41:36.032](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at /tmp/cirrus-ci-build/src/test/ssl/t/001_ssltests.pl line 923. [08:41:36.032](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 49632 failed: server closed the connection unexpectedly # This probably means the server terminated abnormally # before or while processing the request. # SSL SYSCALL error: Connection reset by peer' # expected: '' [08:41:36.049](0.017s) ok 208 - connect without requesting ocsp response when sslocspstapling=0 [08:41:36.049](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50901 [08:41:36.264](0.215s) ok 210 - failed with a revoked ocsp response when sslocspstapling=1 [08:41:36.282](0.018s) ok 211 - connect without requesting ocsp response when sslocspstapling=0 [08:41:36.282](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50913 [08:41:36.498](0.216s) ok 213 - failed with a revoked ocsp response when sslocspstapling=1 [08:41:36.517](0.019s) ok 214 - connect without requesting ocsp response when sslocspstapling=0 [08:41:36.517](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50925 [08:41:36.733](0.216s) ok 216 - failed with an expired ocsp response when sslocspstapling=1 [08:41:36.751](0.017s) ok 217 - connect without requesting ocsp response when sslocspstapling=0 [08:41:36.751](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50937 [08:41:36.966](0.215s) not ok 219 - connect with valid stapled ocsp response when sslocspstapling=1 [08:41:36.966](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at /tmp/cirrus-ci-build/src/test/ssl/t/001_ssltests.pl line 1001. [08:41:36.967](0.000s) # got: '2' # expected: '0' [08:41:36.967](0.000s) not ok 220 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [08:41:36.967](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at /tmp/cirrus-ci-build/src/test/ssl/t/001_ssltests.pl line 1001. [08:41:36.967](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 49632 failed: server closed the connection unexpectedly # This probably means the server terminated abnormally # before or while processing the request. # SSL SYSCALL error: Connection reset by peer' # expected: '' [08:41:36.985](0.018s) ok 221 - connect without requesting ocsp response when sslocspstapling=0 [08:41:36.985](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50949 [08:41:37.200](0.215s) ok 223 - failed with a revoked ocsp response when sslocspstapling=1 [08:41:37.217](0.017s) ok 224 - connect without requesting ocsp response when sslocspstapling=0 [08:41:37.217](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50961 [08:41:37.432](0.215s) ok 226 - failed with a revoked ocsp response when sslocspstapling=1 [08:41:37.449](0.017s) ok 227 - connect without requesting ocsp response when sslocspstapling=0 [08:41:37.449](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50973 [08:41:37.663](0.215s) ok 229 - failed with an expired ocsp response when sslocspstapling=1 [08:41:37.681](0.017s) ok 230 - connect without requesting ocsp response when sslocspstapling=0 [08:41:37.681](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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 50985 [08:41:37.897](0.216s) ok 232 - failed with an expired ocsp response when sslocspstapling=1 [08:41:37.916](0.019s) ok 233 - connect without requesting ocsp response when sslocspstapling=0 [08:41:37.916](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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata -l /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/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-26 08:41:29.482 UTC [49927][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:29.482 UTC [49927][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:29.494 UTC [49945][startup] LOG: database system was shut down at 2024-03-26 08:38:51 UTC 2024-03-26 08:41:29.497 UTC [49927][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:29.547 UTC [49973][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.548 UTC [49973][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.548 UTC [49973][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.553 UTC [49973][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-26 08:41:29.556 UTC [49973][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.564 UTC [49986][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.564 UTC [49986][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.564 UTC [49986][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.565 UTC [49986][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-26 08:41:29.566 UTC [49986][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.605 UTC [49993][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.606 UTC [49993][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.606 UTC [49993][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.607 UTC [49993][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-26 08:41:29.607 UTC [49993][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.001 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.663 UTC [50009][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.664 UTC [50009][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.664 UTC [50009][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.665 UTC [50009][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-26 08:41:29.666 UTC [50009][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.004 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.711 UTC [50026][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.712 UTC [50026][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.712 UTC [50026][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.712 UTC [50026][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-26 08:41:29.713 UTC [50026][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.748 UTC [50037][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.749 UTC [50037][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.749 UTC [50037][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.750 UTC [50037][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-26 08:41:29.784 UTC [50037][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.793 UTC [50050][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.794 UTC [50050][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.794 UTC [50050][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.795 UTC [50050][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-26 08:41:29.853 UTC [50050][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.059 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.918 UTC [50093][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.918 UTC [50093][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.918 UTC [50093][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.919 UTC [50093][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-26 08:41:29.946 UTC [50093][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=postgres database=postgres host=[local] 2024-03-26 08:41:29.964 UTC [50104][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:29.964 UTC [50104][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:29.964 UTC [50104][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:29.972 UTC [50104][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-26 08:41:30.051 UTC [50104][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.086 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.111 UTC [50132][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:30.112 UTC [50132][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:30.112 UTC [50132][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:30.114 UTC [50132][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-26 08:41:30.159 UTC [50132][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.048 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.232 UTC [50165][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-26 08:41:30.232 UTC [50165][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="postgres" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-26 08:41:30.232 UTC [50165][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-26 08:41:30.233 UTC [50165][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-26 08:41:30.278 UTC [50165][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.046 user=postgres database=postgres host=[local] 2024-03-26 08:41:30.354 UTC [49927][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.354 UTC [49927][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.355 UTC [49927][postmaster] LOG: background worker "logical replication launcher" (PID 49954) exited with exit code 1 2024-03-26 08:41:30.357 UTC [49943][checkpointer] LOG: shutting down 2024-03-26 08:41:30.358 UTC [49943][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.395 UTC [49943][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.038 s, sync=0.001 s, total=0.038 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414DB70, redo lsn=0/414DB70 2024-03-26 08:41:30.411 UTC [49927][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:30.486 UTC [50225][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:30.500 UTC [50239][startup] LOG: database system was shut down at 2024-03-26 08:41:30 UTC 2024-03-26 08:41:30.504 UTC [50225][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:30.561 UTC [50225][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.561 UTC [50225][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.563 UTC [50225][postmaster] LOG: background worker "logical replication launcher" (PID 50244) exited with exit code 1 2024-03-26 08:41:30.564 UTC [50236][checkpointer] LOG: shutting down 2024-03-26 08:41:30.564 UTC [50236][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.565 UTC [50236][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/414DBE8, redo lsn=0/414DBE8 2024-03-26 08:41:30.568 UTC [50225][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.677 UTC [50282][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-26 08:41:30.677 UTC [50282][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.786 UTC [50308][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:30.786 UTC [50308][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:30.786 UTC [50308][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:30.788 UTC [50313][startup] LOG: database system was shut down at 2024-03-26 08:41:30 UTC 2024-03-26 08:41:30.792 UTC [50308][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:30.869 UTC [50308][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:30.869 UTC [50308][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:30.872 UTC [50308][postmaster] LOG: background worker "logical replication launcher" (PID 50316) exited with exit code 1 2024-03-26 08:41:30.872 UTC [50311][checkpointer] LOG: shutting down 2024-03-26 08:41:30.872 UTC [50311][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:30.872 UTC [50311][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/414DC60, redo lsn=0/414DC60 2024-03-26 08:41:30.875 UTC [50308][postmaster] LOG: database system is shut down 2024-03-26 08:41:30.984 UTC [50361][postmaster] FATAL: could not set SSL protocol version range 2024-03-26 08:41:30.984 UTC [50361][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-26 08:41:30.984 UTC [50361][postmaster] LOG: database system is shut down 2024-03-26 08:41:31.093 UTC [50377][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:31.093 UTC [50377][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:31.093 UTC [50377][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:31.103 UTC [50385][startup] LOG: database system was shut down at 2024-03-26 08:41:30 UTC 2024-03-26 08:41:31.106 UTC [50377][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:31.177 UTC [50377][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:31.177 UTC [50377][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:31.181 UTC [50377][postmaster] LOG: background worker "logical replication launcher" (PID 50390) exited with exit code 1 2024-03-26 08:41:31.181 UTC [50383][checkpointer] LOG: shutting down 2024-03-26 08:41:31.181 UTC [50383][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:31.182 UTC [50383][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/414DCD8, redo lsn=0/414DCD8 2024-03-26 08:41:31.185 UTC [50377][postmaster] LOG: database system is shut down 2024-03-26 08:41:31.296 UTC [50432][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:31.296 UTC [50432][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:31.296 UTC [50432][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:31.298 UTC [50445][startup] LOG: database system was shut down at 2024-03-26 08:41:31 UTC 2024-03-26 08:41:31.301 UTC [50432][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:31.385 UTC [50467][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59058 2024-03-26 08:41:31.386 UTC [50467][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-26 08:41:31.386 UTC [50467][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "localhost", forward lookup not checked. 2024-03-26 08:41:31.394 UTC [50470][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59070 2024-03-26 08:41:31.398 UTC [50470][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.398 UTC [50470][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-26 08:41:31.403 UTC [50470][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-26 08:41:31.403 UTC [50470][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=59070 2024-03-26 08:41:31.411 UTC [50475][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59080 2024-03-26 08:41:31.412 UTC [50475][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-26 08:41:31.419 UTC [50478][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59086 2024-03-26 08:41:31.420 UTC [50478][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-26 08:41:31.427 UTC [50481][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59092 2024-03-26 08:41:31.430 UTC [50481][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-26 08:41:31.438 UTC [50487][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59098 2024-03-26 08:41:31.441 UTC [50487][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-26 08:41:31.451 UTC [50494][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59108 2024-03-26 08:41:31.456 UTC [50494][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-26 08:41:31.463 UTC [50500][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59116 2024-03-26 08:41:31.466 UTC [50500][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-26 08:41:31.474 UTC [50506][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59126 2024-03-26 08:41:31.478 UTC [50506][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.478 UTC [50506][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-26 08:41:31.479 UTC [50506][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-26 08:41:31.480 UTC [50506][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59126 2024-03-26 08:41:31.492 UTC [50511][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59138 2024-03-26 08:41:31.496 UTC [50511][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.496 UTC [50511][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-26 08:41:31.497 UTC [50511][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-26 08:41:31.497 UTC [50511][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59138 2024-03-26 08:41:31.505 UTC [50513][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59152 2024-03-26 08:41:31.509 UTC [50513][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.509 UTC [50513][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-26 08:41:31.510 UTC [50513][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-26 08:41:31.511 UTC [50513][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59152 2024-03-26 08:41:31.519 UTC [50515][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59158 2024-03-26 08:41:31.523 UTC [50515][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.523 UTC [50515][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-26 08:41:31.524 UTC [50515][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-26 08:41:31.525 UTC [50515][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59158 2024-03-26 08:41:31.535 UTC [50517][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59160 2024-03-26 08:41:31.539 UTC [50517][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.539 UTC [50517][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-26 08:41:31.540 UTC [50517][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-26 08:41:31.541 UTC [50517][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59160 2024-03-26 08:41:31.550 UTC [50519][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59162 2024-03-26 08:41:31.554 UTC [50519][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.554 UTC [50519][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-26 08:41:31.555 UTC [50519][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-26 08:41:31.555 UTC [50519][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59162 2024-03-26 08:41:31.565 UTC [50521][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59178 2024-03-26 08:41:31.569 UTC [50521][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.569 UTC [50521][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-26 08:41:31.570 UTC [50521][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-26 08:41:31.571 UTC [50521][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59178 2024-03-26 08:41:31.581 UTC [50524][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59186 2024-03-26 08:41:31.585 UTC [50524][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.585 UTC [50524][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-26 08:41:31.586 UTC [50524][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59186 2024-03-26 08:41:31.595 UTC [50532][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59196 2024-03-26 08:41:31.599 UTC [50532][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.599 UTC [50532][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-26 08:41:31.600 UTC [50532][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-26 08:41:31.600 UTC [50532][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59196 2024-03-26 08:41:31.609 UTC [50534][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59206 2024-03-26 08:41:31.612 UTC [50534][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-26 08:41:31.622 UTC [50536][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59216 2024-03-26 08:41:31.625 UTC [50536][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-26 08:41:31.635 UTC [50539][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59222 2024-03-26 08:41:31.640 UTC [50539][client backend] [[unknown]][11/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.640 UTC [50539][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-26 08:41:31.641 UTC [50539][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-26 08:41:31.641 UTC [50539][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59222 2024-03-26 08:41:31.651 UTC [50542][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59238 2024-03-26 08:41:31.655 UTC [50542][client backend] [[unknown]][12/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.655 UTC [50542][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-26 08:41:31.656 UTC [50542][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-26 08:41:31.656 UTC [50542][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59238 2024-03-26 08:41:31.665 UTC [50544][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59250 2024-03-26 08:41:31.672 UTC [50544][client backend] [[unknown]][13/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.672 UTC [50544][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-26 08:41:31.674 UTC [50544][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-26 08:41:31.674 UTC [50544][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=59250 2024-03-26 08:41:31.683 UTC [50548][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59256 2024-03-26 08:41:31.687 UTC [50548][client backend] [[unknown]][14/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.687 UTC [50548][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-26 08:41:31.688 UTC [50548][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-26 08:41:31.689 UTC [50548][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59256 2024-03-26 08:41:31.698 UTC [50551][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59260 2024-03-26 08:41:31.706 UTC [50432][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:31.706 UTC [50432][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:31.708 UTC [50432][postmaster] LOG: background worker "logical replication launcher" (PID 50449) exited with exit code 1 2024-03-26 08:41:31.708 UTC [50443][checkpointer] LOG: shutting down 2024-03-26 08:41:31.708 UTC [50443][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:31.709 UTC [50443][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/414DD50, redo lsn=0/414DD50 2024-03-26 08:41:31.712 UTC [50432][postmaster] LOG: database system is shut down 2024-03-26 08:41:31.826 UTC [50557][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:31.826 UTC [50557][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:31.826 UTC [50557][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:31.829 UTC [50564][startup] LOG: database system was shut down at 2024-03-26 08:41:31 UTC 2024-03-26 08:41:31.832 UTC [50557][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:31.915 UTC [50574][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34854 2024-03-26 08:41:31.918 UTC [50574][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:31.918 UTC [50574][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-26 08:41:31.923 UTC [50574][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-26 08:41:31.924 UTC [50574][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=34854 2024-03-26 08:41:31.934 UTC [50577][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34856 2024-03-26 08:41:31.941 UTC [50557][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:31.941 UTC [50557][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:31.943 UTC [50557][postmaster] LOG: background worker "logical replication launcher" (PID 50570) exited with exit code 1 2024-03-26 08:41:31.943 UTC [50562][checkpointer] LOG: shutting down 2024-03-26 08:41:31.943 UTC [50562][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:31.943 UTC [50562][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/414DDC8, redo lsn=0/414DDC8 2024-03-26 08:41:31.946 UTC [50557][postmaster] LOG: database system is shut down 2024-03-26 08:41:32.061 UTC [50582][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:32.061 UTC [50582][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:32.061 UTC [50582][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:32.063 UTC [50591][startup] LOG: database system was shut down at 2024-03-26 08:41:31 UTC 2024-03-26 08:41:32.066 UTC [50582][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:32.150 UTC [50601][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34862 2024-03-26 08:41:32.154 UTC [50601][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.154 UTC [50601][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-26 08:41:32.159 UTC [50601][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-26 08:41:32.159 UTC [50601][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=34862 2024-03-26 08:41:32.163 UTC [50582][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:32.163 UTC [50582][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:32.164 UTC [50582][postmaster] LOG: background worker "logical replication launcher" (PID 50594) exited with exit code 1 2024-03-26 08:41:32.165 UTC [50589][checkpointer] LOG: shutting down 2024-03-26 08:41:32.165 UTC [50589][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:32.166 UTC [50589][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/414DE40, redo lsn=0/414DE40 2024-03-26 08:41:32.169 UTC [50582][postmaster] LOG: database system is shut down 2024-03-26 08:41:32.282 UTC [50606][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:32.282 UTC [50606][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:32.282 UTC [50606][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:32.284 UTC [50615][startup] LOG: database system was shut down at 2024-03-26 08:41:32 UTC 2024-03-26 08:41:32.287 UTC [50606][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:32.372 UTC [50622][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34872 2024-03-26 08:41:32.377 UTC [50622][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.377 UTC [50622][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-26 08:41:32.382 UTC [50622][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-26 08:41:32.383 UTC [50622][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=trustdb host=localhost port=34872 2024-03-26 08:41:32.392 UTC [50625][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34886 2024-03-26 08:41:32.396 UTC [50625][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.396 UTC [50625][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-26 08:41:32.397 UTC [50625][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-26 08:41:32.397 UTC [50625][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=34886 2024-03-26 08:41:32.406 UTC [50627][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34898 2024-03-26 08:41:32.410 UTC [50627][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.410 UTC [50627][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-26 08:41:32.410 UTC [50627][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-26 08:41:32.411 UTC [50627][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=34898 2024-03-26 08:41:32.419 UTC [50630][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34910 2024-03-26 08:41:32.430 UTC [50633][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34920 2024-03-26 08:41:32.438 UTC [50606][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:32.438 UTC [50606][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:32.439 UTC [50606][postmaster] LOG: background worker "logical replication launcher" (PID 50618) exited with exit code 1 2024-03-26 08:41:32.440 UTC [50613][checkpointer] LOG: shutting down 2024-03-26 08:41:32.440 UTC [50613][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:32.441 UTC [50613][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/414DEB8, redo lsn=0/414DEB8 2024-03-26 08:41:32.444 UTC [50606][postmaster] LOG: database system is shut down 2024-03-26 08:41:32.558 UTC [50642][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:32.558 UTC [50642][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:32.558 UTC [50642][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:32.560 UTC [50645][startup] LOG: database system was shut down at 2024-03-26 08:41:32 UTC 2024-03-26 08:41:32.563 UTC [50642][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:32.647 UTC [50655][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34932 2024-03-26 08:41:32.651 UTC [50655][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.651 UTC [50655][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-26 08:41:32.656 UTC [50655][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-26 08:41:32.657 UTC [50655][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=34932 2024-03-26 08:41:32.666 UTC [50659][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34938 2024-03-26 08:41:32.678 UTC [50661][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34952 2024-03-26 08:41:32.689 UTC [50642][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:32.689 UTC [50642][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:32.690 UTC [50642][postmaster] LOG: background worker "logical replication launcher" (PID 50648) exited with exit code 1 2024-03-26 08:41:32.691 UTC [50643][checkpointer] LOG: shutting down 2024-03-26 08:41:32.691 UTC [50643][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:32.692 UTC [50643][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/414DF30, redo lsn=0/414DF30 2024-03-26 08:41:32.695 UTC [50642][postmaster] LOG: database system is shut down 2024-03-26 08:41:32.809 UTC [50671][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:32.809 UTC [50671][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:32.809 UTC [50671][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:32.811 UTC [50675][startup] LOG: database system was shut down at 2024-03-26 08:41:32 UTC 2024-03-26 08:41:32.814 UTC [50671][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:32.898 UTC [50683][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34962 2024-03-26 08:41:32.902 UTC [50683][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.902 UTC [50683][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-26 08:41:32.907 UTC [50683][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-26 08:41:32.908 UTC [50683][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=34962 2024-03-26 08:41:32.917 UTC [50685][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34974 2024-03-26 08:41:32.921 UTC [50685][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.921 UTC [50685][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-26 08:41:32.922 UTC [50685][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-26 08:41:32.923 UTC [50685][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=34974 2024-03-26 08:41:32.932 UTC [50687][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34978 2024-03-26 08:41:32.945 UTC [50690][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34982 2024-03-26 08:41:32.949 UTC [50690][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.949 UTC [50690][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-26 08:41:32.950 UTC [50690][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-26 08:41:32.951 UTC [50690][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=34982 2024-03-26 08:41:32.961 UTC [50694][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=34994 2024-03-26 08:41:32.965 UTC [50694][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.965 UTC [50694][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-26 08:41:32.966 UTC [50694][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-26 08:41:32.967 UTC [50694][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=34994 2024-03-26 08:41:32.976 UTC [50700][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35010 2024-03-26 08:41:32.980 UTC [50700][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:32.980 UTC [50700][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-26 08:41:32.981 UTC [50700][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-26 08:41:32.981 UTC [50700][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=35010 2024-03-26 08:41:32.990 UTC [50702][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35016 2024-03-26 08:41:33.003 UTC [50704][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35028 2024-03-26 08:41:33.011 UTC [50671][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:33.011 UTC [50671][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:33.012 UTC [50671][postmaster] LOG: background worker "logical replication launcher" (PID 50679) exited with exit code 1 2024-03-26 08:41:33.012 UTC [50673][checkpointer] LOG: shutting down 2024-03-26 08:41:33.013 UTC [50673][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:33.013 UTC [50673][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/414DFA8, redo lsn=0/414DFA8 2024-03-26 08:41:33.016 UTC [50671][postmaster] LOG: database system is shut down 2024-03-26 08:41:33.129 UTC [50709][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:33.129 UTC [50709][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:33.129 UTC [50709][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:33.131 UTC [50712][startup] LOG: database system was shut down at 2024-03-26 08:41:33 UTC 2024-03-26 08:41:33.134 UTC [50709][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:33.220 UTC [50717][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35032 2024-03-26 08:41:33.224 UTC [50717][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.224 UTC [50717][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-26 08:41:33.229 UTC [50717][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-26 08:41:33.230 UTC [50717][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35032 2024-03-26 08:41:33.239 UTC [50719][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35048 2024-03-26 08:41:33.243 UTC [50719][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.243 UTC [50719][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-26 08:41:33.244 UTC [50719][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-26 08:41:33.244 UTC [50719][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=35048 2024-03-26 08:41:33.253 UTC [50721][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35050 2024-03-26 08:41:33.262 UTC [50709][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:33.262 UTC [50709][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:33.264 UTC [50709][postmaster] LOG: background worker "logical replication launcher" (PID 50715) exited with exit code 1 2024-03-26 08:41:33.264 UTC [50710][checkpointer] LOG: shutting down 2024-03-26 08:41:33.264 UTC [50710][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:33.264 UTC [50710][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/414E038, redo lsn=0/414E038 2024-03-26 08:41:33.267 UTC [50709][postmaster] LOG: database system is shut down 2024-03-26 08:41:33.382 UTC [50724][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:33.382 UTC [50724][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:33.382 UTC [50724][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:33.384 UTC [50727][startup] LOG: database system was shut down at 2024-03-26 08:41:33 UTC 2024-03-26 08:41:33.388 UTC [50724][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:33.473 UTC [50732][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35058 2024-03-26 08:41:33.477 UTC [50732][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.477 UTC [50732][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-26 08:41:33.481 UTC [50732][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-26 08:41:33.482 UTC [50732][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35058 2024-03-26 08:41:33.492 UTC [50734][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35070 2024-03-26 08:41:33.496 UTC [50734][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.496 UTC [50734][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-26 08:41:33.497 UTC [50734][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-26 08:41:33.497 UTC [50734][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=35070 2024-03-26 08:41:33.507 UTC [50736][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35084 2024-03-26 08:41:33.511 UTC [50736][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.511 UTC [50736][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-26 08:41:33.512 UTC [50736][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-26 08:41:33.512 UTC [50736][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=35084 2024-03-26 08:41:33.516 UTC [50724][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:33.517 UTC [50724][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:33.518 UTC [50724][postmaster] LOG: background worker "logical replication launcher" (PID 50730) exited with exit code 1 2024-03-26 08:41:33.518 UTC [50725][checkpointer] LOG: shutting down 2024-03-26 08:41:33.518 UTC [50725][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:33.519 UTC [50725][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/414E0B0, redo lsn=0/414E0B0 2024-03-26 08:41:33.521 UTC [50724][postmaster] LOG: database system is shut down 2024-03-26 08:41:33.636 UTC [50738][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:33.636 UTC [50738][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:33.637 UTC [50738][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:33.639 UTC [50741][startup] LOG: database system was shut down at 2024-03-26 08:41:33 UTC 2024-03-26 08:41:33.642 UTC [50738][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:33.726 UTC [50746][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35086 2024-03-26 08:41:33.730 UTC [50746][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.730 UTC [50746][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-26 08:41:33.735 UTC [50746][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-26 08:41:33.735 UTC [50746][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35086 2024-03-26 08:41:33.744 UTC [50748][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35100 2024-03-26 08:41:33.748 UTC [50748][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.748 UTC [50748][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-26 08:41:33.749 UTC [50748][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-26 08:41:33.749 UTC [50748][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=35100 2024-03-26 08:41:33.759 UTC [50750][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35116 2024-03-26 08:41:33.766 UTC [50738][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:33.766 UTC [50738][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:33.767 UTC [50738][postmaster] LOG: background worker "logical replication launcher" (PID 50744) exited with exit code 1 2024-03-26 08:41:33.767 UTC [50739][checkpointer] LOG: shutting down 2024-03-26 08:41:33.767 UTC [50739][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:33.768 UTC [50739][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/414E128, redo lsn=0/414E128 2024-03-26 08:41:33.771 UTC [50738][postmaster] LOG: database system is shut down 2024-03-26 08:41:33.885 UTC [50752][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:33.885 UTC [50752][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:33.885 UTC [50752][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:33.888 UTC [50755][startup] LOG: database system was shut down at 2024-03-26 08:41:33 UTC 2024-03-26 08:41:33.891 UTC [50752][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:33.975 UTC [50760][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35130 2024-03-26 08:41:33.979 UTC [50760][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:33.979 UTC [50760][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-26 08:41:33.984 UTC [50760][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-26 08:41:33.985 UTC [50760][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=35130 2024-03-26 08:41:33.996 UTC [50762][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35138 2024-03-26 08:41:34.000 UTC [50762][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:34.000 UTC [50762][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-26 08:41:34.001 UTC [50762][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-26 08:41:34.001 UTC [50762][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=35138 2024-03-26 08:41:34.011 UTC [50764][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35150 2024-03-26 08:41:34.015 UTC [50764][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:34.015 UTC [50764][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-26 08:41:34.016 UTC [50764][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-26 08:41:34.016 UTC [50764][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=35150 2024-03-26 08:41:34.020 UTC [50752][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:34.020 UTC [50752][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:34.022 UTC [50752][postmaster] LOG: background worker "logical replication launcher" (PID 50758) exited with exit code 1 2024-03-26 08:41:34.022 UTC [50753][checkpointer] LOG: shutting down 2024-03-26 08:41:34.022 UTC [50753][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:34.023 UTC [50753][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/414E1A0, redo lsn=0/414E1A0 2024-03-26 08:41:34.026 UTC [50752][postmaster] LOG: database system is shut down 2024-03-26 08:41:34.140 UTC [50766][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:34.140 UTC [50766][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:34.140 UTC [50766][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:34.143 UTC [50769][startup] LOG: database system was shut down at 2024-03-26 08:41:34 UTC 2024-03-26 08:41:34.146 UTC [50766][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:34.230 UTC [50774][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35152 2024-03-26 08:41:34.234 UTC [50774][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:34.234 UTC [50774][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-26 08:41:34.239 UTC [50774][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-26 08:41:34.240 UTC [50774][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=35152 2024-03-26 08:41:34.250 UTC [50776][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35160 2024-03-26 08:41:34.258 UTC [50766][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:34.258 UTC [50766][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:34.259 UTC [50766][postmaster] LOG: background worker "logical replication launcher" (PID 50772) exited with exit code 1 2024-03-26 08:41:34.259 UTC [50767][checkpointer] LOG: shutting down 2024-03-26 08:41:34.259 UTC [50767][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:34.260 UTC [50767][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/414E218, redo lsn=0/414E218 2024-03-26 08:41:34.263 UTC [50766][postmaster] LOG: database system is shut down 2024-03-26 08:41:34.378 UTC [50778][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:34.378 UTC [50778][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:34.378 UTC [50778][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:34.380 UTC [50781][startup] LOG: database system was shut down at 2024-03-26 08:41:34 UTC 2024-03-26 08:41:34.383 UTC [50778][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:34.471 UTC [50786][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35176 2024-03-26 08:41:34.474 UTC [50786][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-26 08:41:34.491 UTC [50789][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35188 2024-03-26 08:41:34.495 UTC [50789][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:34.495 UTC [50789][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-26 08:41:34.500 UTC [50789][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-26 08:41:34.501 UTC [50789][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=35188 2024-03-26 08:41:34.511 UTC [50791][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35204 2024-03-26 08:41:34.518 UTC [50778][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:34.518 UTC [50778][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:34.520 UTC [50778][postmaster] LOG: background worker "logical replication launcher" (PID 50784) exited with exit code 1 2024-03-26 08:41:34.520 UTC [50779][checkpointer] LOG: shutting down 2024-03-26 08:41:34.520 UTC [50779][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:34.520 UTC [50779][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/414E290, redo lsn=0/414E290 2024-03-26 08:41:34.523 UTC [50778][postmaster] LOG: database system is shut down 2024-03-26 08:41:34.638 UTC [50793][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:34.638 UTC [50793][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:34.638 UTC [50793][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:34.640 UTC [50796][startup] LOG: database system was shut down at 2024-03-26 08:41:34 UTC 2024-03-26 08:41:34.643 UTC [50793][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:34.728 UTC [50801][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35210 2024-03-26 08:41:34.731 UTC [50801][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:34.732 UTC [50801][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-26 08:41:34.737 UTC [50801][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-26 08:41:34.737 UTC [50801][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35210 2024-03-26 08:41:34.747 UTC [50803][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35224 2024-03-26 08:41:34.750 UTC [50803][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-26 08:41:34.758 UTC [50805][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35236 2024-03-26 08:41:34.761 UTC [50805][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-26 08:41:34.769 UTC [50807][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35244 2024-03-26 08:41:34.773 UTC [50807][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:34.773 UTC [50807][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-26 08:41:34.774 UTC [50807][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-26 08:41:34.776 UTC [50807][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=35244 2024-03-26 08:41:34.784 UTC [50809][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35248 2024-03-26 08:41:34.788 UTC [50809][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:34.788 UTC [50809][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-26 08:41:34.789 UTC [50809][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-26 08:41:34.790 UTC [50809][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=35248 2024-03-26 08:41:34.819 UTC [50814][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35264 2024-03-26 08:41:34.823 UTC [50814][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-26 08:41:34.831 UTC [50816][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35266 2024-03-26 08:41:34.837 UTC [50816][client backend] [[unknown]][4/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:34.837 UTC [50816][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-26 08:41:34.842 UTC [50816][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client.key$$ 2024-03-26 08:41:34.842 UTC [50816][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=certdb host=localhost port=35266 2024-03-26 08:41:34.851 UTC [50818][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35274 2024-03-26 08:41:34.857 UTC [50818][client backend] [[unknown]][5/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:34.857 UTC [50818][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-26 08:41:34.858 UTC [50818][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client-der.key$$ 2024-03-26 08:41:34.859 UTC [50818][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=ssltestuser database=certdb host=localhost port=35274 2024-03-26 08:41:34.868 UTC [50820][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35284 2024-03-26 08:41:34.874 UTC [50820][client backend] [[unknown]][6/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:34.874 UTC [50820][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-26 08:41:34.875 UTC [50820][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-26 08:41:34.876 UTC [50820][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=ssltestuser database=certdb host=localhost port=35284 2024-03-26 08:41:34.885 UTC [50822][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35290 2024-03-26 08:41:34.890 UTC [50822][client backend] [[unknown]][7/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:34.890 UTC [50822][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-26 08:41:34.892 UTC [50822][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-26 08:41:34.892 UTC [50822][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=ssltestuser database=certdb host=localhost port=35290 2024-03-26 08:41:34.901 UTC [50824][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35296 2024-03-26 08:41:34.906 UTC [50824][client backend] [[unknown]][8/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:34.906 UTC [50824][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-26 08:41:34.907 UTC [50824][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client.key$$ 2024-03-26 08:41:34.908 UTC [50824][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=ssltestuser database=certdb host=localhost port=35296 2024-03-26 08:41:34.916 UTC [50826][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35306 2024-03-26 08:41:34.922 UTC [50826][client backend] [[unknown]][9/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:34.922 UTC [50826][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-26 08:41:34.923 UTC [50826][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client.key$$ 2024-03-26 08:41:34.923 UTC [50826][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=ssltestuser database=certdb host=localhost port=35306 2024-03-26 08:41:34.931 UTC [50828][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35322 2024-03-26 08:41:34.935 UTC [50828][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-26 08:41:34.943 UTC [50830][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35334 2024-03-26 08:41:34.945 UTC [50830][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-26 08:41:34.953 UTC [50832][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35346 2024-03-26 08:41:34.958 UTC [50832][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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:8) 2024-03-26 08:41:34.959 UTC [50832][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-26 08:41:34.964 UTC [50832][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client-dn.key$$ 2024-03-26 08:41:34.964 UTC [50832][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=certdb_dn host=localhost port=35346 2024-03-26 08:41:34.973 UTC [50834][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35352 2024-03-26 08:41:34.978 UTC [50834][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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:9) 2024-03-26 08:41:34.978 UTC [50834][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-26 08:41:34.982 UTC [50834][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client-dn.key$$ 2024-03-26 08:41:34.982 UTC [50834][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=certdb_dn_re host=localhost port=35352 2024-03-26 08:41:34.990 UTC [50836][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35364 2024-03-26 08:41:34.995 UTC [50836][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/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:10) 2024-03-26 08:41:34.995 UTC [50836][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-26 08:41:35.000 UTC [50836][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client-dn.key$$ 2024-03-26 08:41:35.000 UTC [50836][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=certdb_cn host=localhost port=35364 2024-03-26 08:41:35.020 UTC [50839][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35366 2024-03-26 08:41:35.025 UTC [50839][client backend] [[unknown]][14/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:35.025 UTC [50839][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-26 08:41:35.026 UTC [50839][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-26 08:41:35.028 UTC [50839][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=ssltestuser database=certdb host=localhost port=35366 2024-03-26 08:41:35.036 UTC [50841][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35374 2024-03-26 08:41:35.038 UTC [50841][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-26 08:41:35.047 UTC [50843][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35384 2024-03-26 08:41:35.052 UTC [50843][client backend] [[unknown]][15/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:35.052 UTC [50843][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-26 08:41:35.052 UTC [50843][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-26 08:41:35.052 UTC [50843][client backend] [[unknown]][15/1:0] DETAIL: Connection matched file "/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf" line 7: "hostssl certdb all 127.0.0.1/32 cert" 2024-03-26 08:41:35.061 UTC [50845][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35396 2024-03-26 08:41:35.066 UTC [50845][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-26 08:41:35.066 UTC [50845][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-26 08:41:35.074 UTC [50847][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35410 2024-03-26 08:41:35.079 UTC [50847][client backend] [[unknown]][16/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:4) 2024-03-26 08:41:35.079 UTC [50847][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-26 08:41:35.084 UTC [50847][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client.key$$ 2024-03-26 08:41:35.084 UTC [50847][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=verifydb host=localhost port=35410 2024-03-26 08:41:35.093 UTC [50849][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35422 2024-03-26 08:41:35.098 UTC [50849][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-26 08:41:35.098 UTC [50849][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-26 08:41:35.098 UTC [50849][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-26 08:41:35.098 UTC [50849][client backend] [[unknown]][17/1:0] DETAIL: Connection matched file "/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/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-26 08:41:35.106 UTC [50851][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35432 2024-03-26 08:41:35.112 UTC [50851][client backend] [[unknown]][18/1:0] LOG: connection authenticated: user="yetanotheruser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:6) 2024-03-26 08:41:35.112 UTC [50851][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-26 08:41:35.112 UTC [50851][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/client.key$$ 2024-03-26 08:41:35.113 UTC [50851][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=yetanotheruser database=verifydb host=localhost port=35432 2024-03-26 08:41:35.117 UTC [50793][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:35.117 UTC [50793][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:35.118 UTC [50793][postmaster] LOG: background worker "logical replication launcher" (PID 50799) exited with exit code 1 2024-03-26 08:41:35.118 UTC [50794][checkpointer] LOG: shutting down 2024-03-26 08:41:35.118 UTC [50794][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:35.119 UTC [50794][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/414E308, redo lsn=0/414E308 2024-03-26 08:41:35.122 UTC [50793][postmaster] LOG: database system is shut down 2024-03-26 08:41:35.235 UTC [50853][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:35.235 UTC [50853][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:35.236 UTC [50853][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:35.238 UTC [50856][startup] LOG: database system was shut down at 2024-03-26 08:41:35 UTC 2024-03-26 08:41:35.242 UTC [50853][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:35.326 UTC [50861][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35436 2024-03-26 08:41:35.332 UTC [50861][client backend] [[unknown]][0/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-26 08:41:35.332 UTC [50861][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-26 08:41:35.337 UTC [50861][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/build/testrun/ssl/001_ssltests/data/tmp_test_2Jfs/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-26 08:41:35.338 UTC [50861][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=certdb host=localhost port=35436 2024-03-26 08:41:35.346 UTC [50863][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35452 2024-03-26 08:41:35.351 UTC [50863][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-26 08:41:35.351 UTC [50863][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-26 08:41:35.359 UTC [50865][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35462 2024-03-26 08:41:35.364 UTC [50865][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-26 08:41:35.364 UTC [50865][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-26 08:41:35.367 UTC [50853][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:35.367 UTC [50853][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:35.368 UTC [50853][postmaster] LOG: background worker "logical replication launcher" (PID 50859) exited with exit code 1 2024-03-26 08:41:35.369 UTC [50854][checkpointer] LOG: shutting down 2024-03-26 08:41:35.369 UTC [50854][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:35.369 UTC [50854][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/414E380, redo lsn=0/414E380 2024-03-26 08:41:35.372 UTC [50853][postmaster] LOG: database system is shut down 2024-03-26 08:41:35.486 UTC [50867][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:35.486 UTC [50867][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:35.486 UTC [50867][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:35.488 UTC [50870][startup] LOG: database system was shut down at 2024-03-26 08:41:35 UTC 2024-03-26 08:41:35.491 UTC [50867][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:35.576 UTC [50875][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35474 2024-03-26 08:41:35.581 UTC [50875][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-26 08:41:35.581 UTC [50875][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-26 08:41:35.586 UTC [50867][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:35.586 UTC [50867][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:35.587 UTC [50867][postmaster] LOG: background worker "logical replication launcher" (PID 50873) exited with exit code 1 2024-03-26 08:41:35.587 UTC [50868][checkpointer] LOG: shutting down 2024-03-26 08:41:35.587 UTC [50868][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:35.588 UTC [50868][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/414E3F8, redo lsn=0/414E3F8 2024-03-26 08:41:35.590 UTC [50867][postmaster] LOG: database system is shut down 2024-03-26 08:41:35.705 UTC [50877][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:35.705 UTC [50877][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:35.705 UTC [50877][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:35.707 UTC [50880][startup] LOG: database system was shut down at 2024-03-26 08:41:35 UTC 2024-03-26 08:41:35.710 UTC [50877][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:35.796 UTC [50885][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35478 2024-03-26 08:41:35.800 UTC [50885][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-26 08:41:35.800 UTC [50885][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-26 08:41:35.810 UTC [50887][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35490 2024-03-26 08:41:35.814 UTC [50887][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-26 08:41:35.814 UTC [50887][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-26 08:41:35.818 UTC [50877][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:35.818 UTC [50877][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:35.819 UTC [50877][postmaster] LOG: background worker "logical replication launcher" (PID 50883) exited with exit code 1 2024-03-26 08:41:35.820 UTC [50878][checkpointer] LOG: shutting down 2024-03-26 08:41:35.820 UTC [50878][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:35.820 UTC [50878][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/414E470, redo lsn=0/414E470 2024-03-26 08:41:35.823 UTC [50877][postmaster] LOG: database system is shut down 2024-03-26 08:41:35.937 UTC [50889][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:35.937 UTC [50889][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:35.937 UTC [50889][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:35.939 UTC [50892][startup] LOG: database system was shut down at 2024-03-26 08:41:35 UTC 2024-03-26 08:41:35.942 UTC [50889][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:36.027 UTC [50897][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35494 2024-03-26 08:41:36.029 UTC [50897][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:36.029 UTC [50897][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:36.039 UTC [50899][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35504 2024-03-26 08:41:36.042 UTC [50899][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:36.042 UTC [50899][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-26 08:41:36.047 UTC [50899][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-26 08:41:36.048 UTC [50899][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35504 2024-03-26 08:41:36.051 UTC [50889][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:36.051 UTC [50889][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:36.053 UTC [50889][postmaster] LOG: background worker "logical replication launcher" (PID 50895) exited with exit code 1 2024-03-26 08:41:36.053 UTC [50890][checkpointer] LOG: shutting down 2024-03-26 08:41:36.053 UTC [50890][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:36.053 UTC [50890][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/414E4E8, redo lsn=0/414E4E8 2024-03-26 08:41:36.056 UTC [50889][postmaster] LOG: database system is shut down 2024-03-26 08:41:36.170 UTC [50901][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:36.170 UTC [50901][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:36.170 UTC [50901][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:36.173 UTC [50904][startup] LOG: database system was shut down at 2024-03-26 08:41:36 UTC 2024-03-26 08:41:36.176 UTC [50901][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:36.261 UTC [50909][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35520 2024-03-26 08:41:36.262 UTC [50909][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:36.262 UTC [50909][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:36.271 UTC [50911][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35536 2024-03-26 08:41:36.275 UTC [50911][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:36.275 UTC [50911][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-26 08:41:36.280 UTC [50911][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-26 08:41:36.281 UTC [50911][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35536 2024-03-26 08:41:36.285 UTC [50901][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:36.285 UTC [50901][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:36.287 UTC [50901][postmaster] LOG: background worker "logical replication launcher" (PID 50907) exited with exit code 1 2024-03-26 08:41:36.287 UTC [50902][checkpointer] LOG: shutting down 2024-03-26 08:41:36.287 UTC [50902][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:36.287 UTC [50902][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/414E560, redo lsn=0/414E560 2024-03-26 08:41:36.290 UTC [50901][postmaster] LOG: database system is shut down 2024-03-26 08:41:36.404 UTC [50913][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:36.404 UTC [50913][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:36.404 UTC [50913][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:36.406 UTC [50916][startup] LOG: database system was shut down at 2024-03-26 08:41:36 UTC 2024-03-26 08:41:36.409 UTC [50913][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:36.494 UTC [50921][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35552 2024-03-26 08:41:36.496 UTC [50921][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:36.496 UTC [50921][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:36.506 UTC [50923][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35568 2024-03-26 08:41:36.510 UTC [50923][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:36.510 UTC [50923][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-26 08:41:36.515 UTC [50923][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-26 08:41:36.515 UTC [50923][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35568 2024-03-26 08:41:36.520 UTC [50913][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:36.520 UTC [50913][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:36.522 UTC [50913][postmaster] LOG: background worker "logical replication launcher" (PID 50919) exited with exit code 1 2024-03-26 08:41:36.522 UTC [50914][checkpointer] LOG: shutting down 2024-03-26 08:41:36.522 UTC [50914][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:36.523 UTC [50914][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/414E5D8, redo lsn=0/414E5D8 2024-03-26 08:41:36.526 UTC [50913][postmaster] LOG: database system is shut down 2024-03-26 08:41:36.639 UTC [50925][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:36.639 UTC [50925][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:36.639 UTC [50925][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:36.641 UTC [50928][startup] LOG: database system was shut down at 2024-03-26 08:41:36 UTC 2024-03-26 08:41:36.644 UTC [50925][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:36.729 UTC [50933][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35572 2024-03-26 08:41:36.731 UTC [50933][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:36.731 UTC [50933][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:36.740 UTC [50935][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35576 2024-03-26 08:41:36.744 UTC [50935][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:36.744 UTC [50935][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-26 08:41:36.748 UTC [50935][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-26 08:41:36.749 UTC [50935][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35576 2024-03-26 08:41:36.753 UTC [50925][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:36.753 UTC [50925][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:36.755 UTC [50925][postmaster] LOG: background worker "logical replication launcher" (PID 50931) exited with exit code 1 2024-03-26 08:41:36.755 UTC [50926][checkpointer] LOG: shutting down 2024-03-26 08:41:36.755 UTC [50926][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:36.756 UTC [50926][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/414E650, redo lsn=0/414E650 2024-03-26 08:41:36.758 UTC [50925][postmaster] LOG: database system is shut down 2024-03-26 08:41:36.872 UTC [50937][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:36.872 UTC [50937][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:36.872 UTC [50937][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:36.875 UTC [50940][startup] LOG: database system was shut down at 2024-03-26 08:41:36 UTC 2024-03-26 08:41:36.877 UTC [50937][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:36.962 UTC [50945][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35586 2024-03-26 08:41:36.964 UTC [50945][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:36.964 UTC [50945][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:36.974 UTC [50947][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35594 2024-03-26 08:41:36.978 UTC [50947][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:36.978 UTC [50947][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-26 08:41:36.983 UTC [50947][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-26 08:41:36.983 UTC [50947][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35594 2024-03-26 08:41:36.987 UTC [50937][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:36.987 UTC [50937][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:36.989 UTC [50937][postmaster] LOG: background worker "logical replication launcher" (PID 50943) exited with exit code 1 2024-03-26 08:41:36.989 UTC [50938][checkpointer] LOG: shutting down 2024-03-26 08:41:36.989 UTC [50938][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:36.989 UTC [50938][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/414E6C8, redo lsn=0/414E6C8 2024-03-26 08:41:36.992 UTC [50937][postmaster] LOG: database system is shut down 2024-03-26 08:41:37.107 UTC [50949][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:37.107 UTC [50949][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:37.107 UTC [50949][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:37.109 UTC [50952][startup] LOG: database system was shut down at 2024-03-26 08:41:36 UTC 2024-03-26 08:41:37.112 UTC [50949][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:37.196 UTC [50957][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35598 2024-03-26 08:41:37.198 UTC [50957][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:37.198 UTC [50957][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:37.207 UTC [50959][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35608 2024-03-26 08:41:37.210 UTC [50959][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:37.210 UTC [50959][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-26 08:41:37.215 UTC [50959][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-26 08:41:37.216 UTC [50959][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35608 2024-03-26 08:41:37.219 UTC [50949][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:37.219 UTC [50949][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:37.221 UTC [50949][postmaster] LOG: background worker "logical replication launcher" (PID 50955) exited with exit code 1 2024-03-26 08:41:37.221 UTC [50950][checkpointer] LOG: shutting down 2024-03-26 08:41:37.221 UTC [50950][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:37.221 UTC [50950][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/414E740, redo lsn=0/414E740 2024-03-26 08:41:37.224 UTC [50949][postmaster] LOG: database system is shut down 2024-03-26 08:41:37.339 UTC [50961][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:37.339 UTC [50961][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:37.339 UTC [50961][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:37.341 UTC [50964][startup] LOG: database system was shut down at 2024-03-26 08:41:37 UTC 2024-03-26 08:41:37.344 UTC [50961][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:37.428 UTC [50969][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35616 2024-03-26 08:41:37.430 UTC [50969][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:37.430 UTC [50969][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:37.438 UTC [50971][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35624 2024-03-26 08:41:37.442 UTC [50971][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:37.442 UTC [50971][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-26 08:41:37.447 UTC [50971][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-26 08:41:37.447 UTC [50971][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35624 2024-03-26 08:41:37.451 UTC [50961][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:37.451 UTC [50961][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:37.452 UTC [50961][postmaster] LOG: background worker "logical replication launcher" (PID 50967) exited with exit code 1 2024-03-26 08:41:37.452 UTC [50962][checkpointer] LOG: shutting down 2024-03-26 08:41:37.452 UTC [50962][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:37.453 UTC [50962][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/414E7B8, redo lsn=0/414E7B8 2024-03-26 08:41:37.455 UTC [50961][postmaster] LOG: database system is shut down 2024-03-26 08:41:37.570 UTC [50973][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:37.570 UTC [50973][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:37.570 UTC [50973][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:37.572 UTC [50976][startup] LOG: database system was shut down at 2024-03-26 08:41:37 UTC 2024-03-26 08:41:37.575 UTC [50973][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:37.660 UTC [50981][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35634 2024-03-26 08:41:37.661 UTC [50981][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:37.661 UTC [50981][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:37.670 UTC [50983][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35642 2024-03-26 08:41:37.674 UTC [50983][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:37.674 UTC [50983][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-26 08:41:37.679 UTC [50983][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-26 08:41:37.679 UTC [50983][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35642 2024-03-26 08:41:37.683 UTC [50973][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:37.683 UTC [50973][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:37.684 UTC [50973][postmaster] LOG: background worker "logical replication launcher" (PID 50979) exited with exit code 1 2024-03-26 08:41:37.685 UTC [50974][checkpointer] LOG: shutting down 2024-03-26 08:41:37.685 UTC [50974][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:37.685 UTC [50974][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/414E830, redo lsn=0/414E830 2024-03-26 08:41:37.688 UTC [50973][postmaster] LOG: database system is shut down 2024-03-26 08:41:37.803 UTC [50985][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-26 08:41:37.803 UTC [50985][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49632 2024-03-26 08:41:37.803 UTC [50985][postmaster] LOG: listening on Unix socket "/tmp/aD0Ii2bonw/.s.PGSQL.49632" 2024-03-26 08:41:37.805 UTC [50988][startup] LOG: database system was shut down at 2024-03-26 08:41:37 UTC 2024-03-26 08:41:37.808 UTC [50985][postmaster] LOG: database system is ready to accept connections 2024-03-26 08:41:37.893 UTC [50993][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35646 2024-03-26 08:41:37.895 UTC [50993][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-26 08:41:37.895 UTC [50993][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-26 08:41:37.905 UTC [50995][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=35660 2024-03-26 08:41:37.909 UTC [50995][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (/tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-26 08:41:37.909 UTC [50995][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-26 08:41:37.914 UTC [50995][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-26 08:41:37.914 UTC [50995][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=35660 2024-03-26 08:41:37.919 UTC [50985][postmaster] LOG: received fast shutdown request 2024-03-26 08:41:37.919 UTC [50985][postmaster] LOG: aborting any active transactions 2024-03-26 08:41:37.921 UTC [50985][postmaster] LOG: background worker "logical replication launcher" (PID 50991) exited with exit code 1 2024-03-26 08:41:37.921 UTC [50986][checkpointer] LOG: shutting down 2024-03-26 08:41:37.921 UTC [50986][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-26 08:41:37.921 UTC [50986][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/414E8A8, redo lsn=0/414E8A8 2024-03-26 08:41:37.924 UTC [50985][postmaster] LOG: database system is shut down 2024-03-26 08:41:38.033 UTC [50997][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-26 08:41:38.033 UTC [50997][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [08:41:38.121](0.205s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"