[08:09:21.803](0.028s) # setting up data directory # Checking port 51236 # Found port 51236 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=51236 host=/tmp/WN2fTY6kKf Log file: /tmp/cirrus-ci-build/build/testrun/ssl/001_ssltests/log/001_ssltests_primary.log [08:09:21.807](0.004s) # 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 50272 [08:09:22.026](0.219s) 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 50563 [08:09:22.921](0.895s) # 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-30 08:09:21.929 UTC [50272][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:21.929 UTC [50272][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:21.933 UTC [50280][startup] LOG: database system was shut down at 2024-03-30 08:06:55 UTC 2024-03-30 08:09:21.935 UTC [50272][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:22.018 UTC [50321][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.019 UTC [50321][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-30 08:09:22.019 UTC [50321][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.024 UTC [50321][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-30 08:09:22.027 UTC [50321][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.035 UTC [50328][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.036 UTC [50328][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-30 08:09:22.036 UTC [50328][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.040 UTC [50328][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-30 08:09:22.045 UTC [50328][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.085 UTC [50348][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.085 UTC [50348][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-30 08:09:22.085 UTC [50348][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.086 UTC [50348][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-30 08:09:22.087 UTC [50348][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.127 UTC [50372][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.128 UTC [50372][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-30 08:09:22.128 UTC [50372][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.128 UTC [50372][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-30 08:09:22.129 UTC [50372][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.179 UTC [50400][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.179 UTC [50400][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-30 08:09:22.179 UTC [50400][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.180 UTC [50400][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-30 08:09:22.181 UTC [50400][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.221 UTC [50408][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.221 UTC [50408][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-30 08:09:22.221 UTC [50408][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.222 UTC [50408][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-30 08:09:22.255 UTC [50408][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.264 UTC [50416][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.265 UTC [50416][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-30 08:09:22.265 UTC [50416][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.266 UTC [50416][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-30 08:09:22.313 UTC [50416][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.049 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.386 UTC [50435][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.387 UTC [50435][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-30 08:09:22.387 UTC [50435][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.388 UTC [50435][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-30 08:09:22.414 UTC [50435][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.440 UTC [50451][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.441 UTC [50451][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-30 08:09:22.441 UTC [50451][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.442 UTC [50451][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-30 08:09:22.502 UTC [50451][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.062 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.553 UTC [50489][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.554 UTC [50489][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-30 08:09:22.554 UTC [50489][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.555 UTC [50489][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-30 08:09:22.585 UTC [50489][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.598 UTC [50503][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.599 UTC [50503][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-30 08:09:22.599 UTC [50503][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.599 UTC [50503][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-30 08:09:22.645 UTC [50503][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.046 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.719 UTC [50272][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:22.719 UTC [50272][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:22.721 UTC [50272][postmaster] LOG: background worker "logical replication launcher" (PID 50286) exited with exit code 1 2024-03-30 08:09:22.722 UTC [50278][checkpointer] LOG: shutting down 2024-03-30 08:09:22.722 UTC [50278][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:22.771 UTC [50278][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.037 s, sync=0.001 s, total=0.050 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414C400, redo lsn=0/414C400 2024-03-30 08:09:22.780 UTC [50272][postmaster] LOG: database system is shut down 2024-03-30 08:09:22.850 UTC [50563][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:22.851 UTC [50563][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:22.851 UTC [50563][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:22.869 UTC [50580][startup] LOG: database system was shut down at 2024-03-30 08:09:22 UTC 2024-03-30 08:09:22.872 UTC [50563][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:22.924 UTC [50563][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:22.924 UTC [50563][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:22.926 UTC [50563][postmaster] LOG: background worker "logical replication launcher" (PID 50587) exited with exit code 1 2024-03-30 08:09:22.926 UTC [50578][checkpointer] LOG: shutting down 2024-03-30 08:09:22.926 UTC [50578][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:22.927 UTC [50578][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/414C478, redo lsn=0/414C478 2024-03-30 08:09:22.930 UTC [50563][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.037 UTC [50639][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-30 08:09:23.037 UTC [50639][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [08:09:23.125](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 50667 [08:09:23.228](0.103s) 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-30 08:09:21.929 UTC [50272][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:21.929 UTC [50272][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:21.933 UTC [50280][startup] LOG: database system was shut down at 2024-03-30 08:06:55 UTC 2024-03-30 08:09:21.935 UTC [50272][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:22.018 UTC [50321][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.019 UTC [50321][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-30 08:09:22.019 UTC [50321][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.024 UTC [50321][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-30 08:09:22.027 UTC [50321][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.035 UTC [50328][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.036 UTC [50328][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-30 08:09:22.036 UTC [50328][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.040 UTC [50328][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-30 08:09:22.045 UTC [50328][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.085 UTC [50348][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.085 UTC [50348][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-30 08:09:22.085 UTC [50348][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.086 UTC [50348][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-30 08:09:22.087 UTC [50348][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.127 UTC [50372][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.128 UTC [50372][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-30 08:09:22.128 UTC [50372][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.128 UTC [50372][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-30 08:09:22.129 UTC [50372][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.179 UTC [50400][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.179 UTC [50400][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-30 08:09:22.179 UTC [50400][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.180 UTC [50400][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-30 08:09:22.181 UTC [50400][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.221 UTC [50408][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.221 UTC [50408][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-30 08:09:22.221 UTC [50408][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.222 UTC [50408][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-30 08:09:22.255 UTC [50408][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.264 UTC [50416][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.265 UTC [50416][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-30 08:09:22.265 UTC [50416][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.266 UTC [50416][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-30 08:09:22.313 UTC [50416][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.049 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.386 UTC [50435][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.387 UTC [50435][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-30 08:09:22.387 UTC [50435][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.388 UTC [50435][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-30 08:09:22.414 UTC [50435][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.440 UTC [50451][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.441 UTC [50451][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-30 08:09:22.441 UTC [50451][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.442 UTC [50451][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-30 08:09:22.502 UTC [50451][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.062 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.553 UTC [50489][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.554 UTC [50489][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-30 08:09:22.554 UTC [50489][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.555 UTC [50489][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-30 08:09:22.585 UTC [50489][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.598 UTC [50503][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.599 UTC [50503][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-30 08:09:22.599 UTC [50503][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.599 UTC [50503][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-30 08:09:22.645 UTC [50503][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.046 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.719 UTC [50272][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:22.719 UTC [50272][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:22.721 UTC [50272][postmaster] LOG: background worker "logical replication launcher" (PID 50286) exited with exit code 1 2024-03-30 08:09:22.722 UTC [50278][checkpointer] LOG: shutting down 2024-03-30 08:09:22.722 UTC [50278][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:22.771 UTC [50278][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.037 s, sync=0.001 s, total=0.050 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414C400, redo lsn=0/414C400 2024-03-30 08:09:22.780 UTC [50272][postmaster] LOG: database system is shut down 2024-03-30 08:09:22.850 UTC [50563][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:22.851 UTC [50563][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:22.851 UTC [50563][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:22.869 UTC [50580][startup] LOG: database system was shut down at 2024-03-30 08:09:22 UTC 2024-03-30 08:09:22.872 UTC [50563][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:22.924 UTC [50563][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:22.924 UTC [50563][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:22.926 UTC [50563][postmaster] LOG: background worker "logical replication launcher" (PID 50587) exited with exit code 1 2024-03-30 08:09:22.926 UTC [50578][checkpointer] LOG: shutting down 2024-03-30 08:09:22.926 UTC [50578][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:22.927 UTC [50578][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/414C478, redo lsn=0/414C478 2024-03-30 08:09:22.930 UTC [50563][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.037 UTC [50639][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-30 08:09:23.037 UTC [50639][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.147 UTC [50667][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:23.147 UTC [50667][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:23.147 UTC [50667][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:23.149 UTC [50671][startup] LOG: database system was shut down at 2024-03-30 08:09:22 UTC 2024-03-30 08:09:23.153 UTC [50667][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:23.235 UTC [50667][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:23.235 UTC [50667][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:23.238 UTC [50667][postmaster] LOG: background worker "logical replication launcher" (PID 50674) exited with exit code 1 2024-03-30 08:09:23.238 UTC [50669][checkpointer] LOG: shutting down 2024-03-30 08:09:23.238 UTC [50669][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:23.239 UTC [50669][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/414C4F0, redo lsn=0/414C4F0 2024-03-30 08:09:23.242 UTC [50667][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.352 UTC [50734][postmaster] FATAL: could not set SSL protocol version range 2024-03-30 08:09:23.352 UTC [50734][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-30 08:09:23.352 UTC [50734][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [08:09:23.439](0.211s) 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 50755 [08:09:23.543](0.104s) ok 5 - restart succeeds with correct SSL protocol bounds [08:09:23.543](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 50816 [08:09:23.762](0.219s) ok 6 - server doesn't accept non-SSL connections [08:09:23.762](0.000s) ok 7 - server doesn't accept non-SSL connections: matches [08:09:23.781](0.019s) ok 8 - connect without server root cert sslmode=require [08:09:23.781](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr [08:09:23.792](0.010s) ok 10 - connect without server root cert sslmode=verify-ca [08:09:23.792](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches [08:09:23.802](0.010s) ok 12 - connect without server root cert sslmode=verify-full [08:09:23.802](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches [08:09:23.815](0.013s) ok 14 - connect with wrong server root cert sslmode=require [08:09:23.816](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches [08:09:23.829](0.013s) ok 16 - connect with wrong server root cert sslmode=verify-ca [08:09:23.829](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [08:09:23.841](0.012s) ok 18 - connect with wrong server root cert sslmode=verify-full [08:09:23.842](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [08:09:23.855](0.013s) ok 20 - connect with server CA cert, without root CA [08:09:23.855](0.000s) ok 21 - connect with server CA cert, without root CA: matches [08:09:23.870](0.015s) ok 22 - connect with correct server CA cert file sslmode=require [08:09:23.870](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [08:09:23.886](0.015s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [08:09:23.886](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [08:09:23.903](0.017s) ok 26 - connect with correct server CA cert file sslmode=verify-full [08:09:23.903](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [08:09:23.918](0.015s) ok 28 - cert root file that contains two certificates, order 1 [08:09:23.918](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr [08:09:23.933](0.015s) ok 30 - cert root file that contains two certificates, order 2 [08:09:23.934](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr [08:09:23.948](0.015s) ok 32 - connect with sslcertmode=disable [08:09:23.948](0.000s) ok 33 - connect with sslcertmode=disable: no stderr [08:09:23.963](0.015s) ok 34 - connect with sslcertmode=allow [08:09:23.963](0.000s) ok 35 - connect with sslcertmode=allow: no stderr [08:09:23.978](0.015s) ok 36 - connect with sslcertmode=require fails without a client certificate [08:09:23.978](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [08:09:23.994](0.015s) ok 38 - sslcrl option with invalid file name [08:09:23.994](0.000s) ok 39 - sslcrl option with invalid file name: no stderr [08:09:24.007](0.013s) ok 40 - CRL belonging to a different CA [08:09:24.007](0.000s) ok 41 - CRL belonging to a different CA: matches [08:09:24.019](0.012s) ok 42 - directory CRL belonging to a different CA [08:09:24.020](0.000s) ok 43 - directory CRL belonging to a different CA: matches [08:09:24.033](0.014s) ok 44 - CRL with a non-revoked cert [08:09:24.034](0.000s) ok 45 - CRL with a non-revoked cert: no stderr [08:09:24.048](0.014s) ok 46 - directory CRL with a non-revoked cert [08:09:24.048](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr [08:09:24.063](0.015s) ok 48 - mismatch between host name and server certificate sslmode=require [08:09:24.063](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [08:09:24.076](0.013s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [08:09:24.076](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [08:09:24.091](0.015s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [08:09:24.091](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 50934 [08:09:24.314](0.223s) ok 54 - IP address in the Common Name [08:09:24.314](0.000s) ok 55 - IP address in the Common Name: no stderr [08:09:24.327](0.013s) ok 56 - mismatch between host name and server certificate IP address [08:09:24.327](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 50964 [08:09:24.550](0.223s) ok 58 - IP address in a dNSName [08:09:24.551](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 50987 [08:09:24.774](0.224s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [08:09:24.774](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [08:09:24.789](0.015s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [08:09:24.790](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [08:09:24.806](0.016s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [08:09:24.806](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [08:09:24.819](0.013s) ok 66 - host name not matching with X.509 Subject Alternative Names [08:09:24.820](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [08:09:24.833](0.014s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [08:09:24.833](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 51018 [08:09:25.057](0.223s) ok 70 - host name matching with a single X.509 Subject Alternative Name [08:09:25.057](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [08:09:25.070](0.013s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [08:09:25.071](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [08:09:25.083](0.013s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [08:09:25.084](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 51047 [08:09:25.310](0.226s) ok 76 - host matching an IPv4 address (Subject Alternative Name 1) [08:09:25.310](0.000s) ok 77 - host matching an IPv4 address (Subject Alternative Name 1): no stderr [08:09:25.326](0.016s) ok 78 - host matching an IPv4 address in alternate form (Subject Alternative Name 1) [08:09:25.326](0.000s) ok 79 - host matching an IPv4 address in alternate form (Subject Alternative Name 1): no stderr [08:09:25.339](0.013s) ok 80 - host not matching an IPv4 address (Subject Alternative Name 1) [08:09:25.339](0.000s) ok 81 - host not matching an IPv4 address (Subject Alternative Name 1): matches [08:09:25.354](0.015s) ok 82 - host matching an IPv6 address (Subject Alternative Name 2) [08:09:25.354](0.000s) ok 83 - host matching an IPv6 address (Subject Alternative Name 2): no stderr [08:09:25.369](0.015s) ok 84 - host matching an IPv6 address in alternate form (Subject Alternative Name 2) [08:09:25.369](0.000s) ok 85 - host matching an IPv6 address in alternate form (Subject Alternative Name 2): no stderr [08:09:25.384](0.014s) ok 86 - host matching an IPv6 address in mixed form (Subject Alternative Name 2) [08:09:25.384](0.000s) ok 87 - host matching an IPv6 address in mixed form (Subject Alternative Name 2): no stderr [08:09:25.396](0.012s) ok 88 - host not matching an IPv6 address (Subject Alternative Name 2) [08:09:25.396](0.000s) ok 89 - host not matching an IPv6 address (Subject Alternative Name 2): matches [08:09:25.408](0.012s) ok 90 - IPv6 host with CIDR mask does not match [08:09:25.408](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 51075 [08:09:25.632](0.223s) ok 92 - certificate with both a CN and SANs 1 [08:09:25.632](0.000s) ok 93 - certificate with both a CN and SANs 1: no stderr [08:09:25.647](0.015s) ok 94 - certificate with both a CN and SANs 2 [08:09:25.647](0.000s) ok 95 - certificate with both a CN and SANs 2: no stderr [08:09:25.659](0.012s) ok 96 - certificate with both a CN and SANs ignores CN [08:09:25.660](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 51090 [08:09:25.886](0.227s) ok 98 - certificate with both a CN and IP SANs matches CN [08:09:25.886](0.000s) ok 99 - certificate with both a CN and IP SANs matches CN: no stderr [08:09:25.901](0.014s) ok 100 - certificate with both a CN and IP SANs matches SAN 1 [08:09:25.901](0.000s) ok 101 - certificate with both a CN and IP SANs matches SAN 1: no stderr [08:09:25.915](0.014s) ok 102 - certificate with both a CN and IP SANs matches SAN 2 [08:09:25.915](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 51104 [08:09:26.139](0.224s) ok 104 - certificate with both an IP CN and IP SANs 1 [08:09:26.139](0.000s) ok 105 - certificate with both an IP CN and IP SANs 1: no stderr [08:09:26.155](0.016s) ok 106 - certificate with both an IP CN and IP SANs 2 [08:09:26.155](0.000s) ok 107 - certificate with both an IP CN and IP SANs 2: no stderr [08:09:26.168](0.013s) ok 108 - certificate with both an IP CN and IP SANs ignores CN [08:09:26.169](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 51118 [08:09:26.392](0.224s) ok 110 - certificate with both an IP CN and DNS SANs matches CN [08:09:26.393](0.000s) ok 111 - certificate with both an IP CN and DNS SANs matches CN: no stderr [08:09:26.408](0.016s) ok 112 - certificate with both an IP CN and DNS SANs matches SAN 1 [08:09:26.409](0.000s) ok 113 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [08:09:26.424](0.015s) ok 114 - certificate with both an IP CN and DNS SANs matches SAN 2 [08:09:26.424](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 51132 [08:09:26.647](0.223s) ok 116 - server certificate without CN or SANs sslmode=verify-ca [08:09:26.648](0.000s) ok 117 - server certificate without CN or SANs sslmode=verify-ca: no stderr [08:09:26.661](0.013s) ok 118 - server certificate without CN or SANs sslmode=verify-full [08:09:26.661](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 51144 [08:09:26.879](0.218s) ok 120 - sslrootcert=system does not connect with private CA [08:09:26.880](0.000s) ok 121 - sslrootcert=system does not connect with private CA: matches [08:09:26.887](0.007s) ok 122 - sslrootcert=system only accepts sslmode=verify-full [08:09:26.887](0.000s) ok 123 - sslrootcert=system only accepts sslmode=verify-full: matches [08:09:26.905](0.018s) ok 124 - sslrootcert=system connects with overridden SSL_CERT_FILE [08:09:26.905](0.000s) ok 125 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [08:09:26.917](0.012s) ok 126 - sslrootcert=system defaults to sslmode=verify-full [08:09:26.918](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 51159 [08:09:27.140](0.222s) ok 128 - connects without client-side CRL [08:09:27.140](0.000s) ok 129 - connects without client-side CRL: no stderr [08:09:27.151](0.011s) ok 130 - does not connect with client-side CRL file [08:09:27.151](0.000s) ok 131 - does not connect with client-side CRL file: matches [08:09:27.162](0.011s) ok 132 - does not connect with client-side CRL directory [08:09:27.162](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:09:27.175](0.013s) ok 134 - pg_stat_ssl view without client certificate: exit code 0 [08:09:27.175](0.000s) ok 135 - pg_stat_ssl view without client certificate: no stderr [08:09:27.176](0.000s) ok 136 - pg_stat_ssl view without client certificate: matches [08:09:27.189](0.013s) ok 137 - connection success with correct range of TLS protocol versions [08:09:27.189](0.000s) ok 138 - connection success with correct range of TLS protocol versions: no stderr [08:09:27.196](0.007s) ok 139 - connection failure with incorrect range of TLS protocol versions [08:09:27.197](0.000s) ok 140 - connection failure with incorrect range of TLS protocol versions: matches [08:09:27.204](0.007s) ok 141 - connection failure with an incorrect SSL protocol minimum bound [08:09:27.204](0.000s) ok 142 - connection failure with an incorrect SSL protocol minimum bound: matches [08:09:27.211](0.007s) ok 143 - connection failure with an incorrect SSL protocol maximum bound [08:09:27.212](0.000s) ok 144 - connection failure with an incorrect SSL protocol maximum bound: matches [08:09:27.212](0.000s) # running server tests [08:09:27.224](0.012s) ok 145 - certificate authorization fails without client cert [08:09:27.225](0.000s) ok 146 - certificate authorization fails without client cert: matches [08:09:27.242](0.018s) ok 147 - certificate authorization succeeds with correct client cert in PEM format [08:09:27.242](0.000s) ok 148 - certificate authorization succeeds with correct client cert in PEM format: no stderr [08:09:27.256](0.013s) ok 149 - certificate authorization succeeds with correct client cert in DER format [08:09:27.256](0.000s) ok 150 - certificate authorization succeeds with correct client cert in DER format: no stderr [08:09:27.270](0.014s) ok 151 - certificate authorization succeeds with correct client cert in encrypted PEM format [08:09:27.270](0.000s) ok 152 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [08:09:27.283](0.013s) ok 153 - certificate authorization succeeds with correct client cert in encrypted DER format [08:09:27.283](0.000s) ok 154 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [08:09:27.299](0.016s) ok 155 - certificate authorization succeeds with correct client cert and sslcertmode=require [08:09:27.300](0.000s) ok 156 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [08:09:27.318](0.018s) ok 157 - certificate authorization succeeds with correct client cert and sslcertmode=allow [08:09:27.318](0.000s) ok 158 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [08:09:27.332](0.014s) ok 159 - certificate authorization fails with correct client cert and sslcertmode=disable [08:09:27.332](0.000s) ok 160 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [08:09:27.343](0.011s) ok 161 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [08:09:27.343](0.000s) ok 162 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [08:09:27.364](0.021s) ok 163 - certificate authorization succeeds with DN mapping [08:09:27.364](0.000s) ok 164 - certificate authorization succeeds with DN mapping: no stderr [08:09:27.365](0.000s) ok 165 - certificate authorization succeeds with DN mapping: log matches [08:09:27.385](0.021s) ok 166 - certificate authorization succeeds with DN regex mapping [08:09:27.386](0.000s) ok 167 - certificate authorization succeeds with DN regex mapping: no stderr [08:09:27.407](0.021s) ok 168 - certificate authorization succeeds with CN mapping [08:09:27.407](0.000s) ok 169 - certificate authorization succeeds with CN mapping: no stderr [08:09:27.407](0.000s) ok 170 - certificate authorization succeeds with CN mapping: log matches [08:09:27.408](0.000s) not ok 171 # TODO & SKIP Need Pty support [08:09:27.408](0.000s) not ok 172 # TODO & SKIP Need Pty support [08:09:27.408](0.000s) not ok 173 # TODO & SKIP Need Pty support [08:09:27.408](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_IiR4/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [08:09:27.435](0.027s) ok 175 - pg_stat_ssl with client certificate: exit code 0 [08:09:27.436](0.000s) ok 176 - pg_stat_ssl with client certificate: no stderr [08:09:27.436](0.000s) ok 177 - pg_stat_ssl with client certificate: matches [08:09:27.446](0.010s) ok 178 - certificate authorization fails because of file permissions [08:09:27.446](0.000s) ok 179 - certificate authorization fails because of file permissions: matches [08:09:27.461](0.015s) ok 180 - certificate authorization fails with client cert belonging to another user [08:09:27.461](0.000s) ok 181 - certificate authorization fails with client cert belonging to another user: matches [08:09:27.475](0.014s) ok 182 - certificate authorization fails with revoked client cert [08:09:27.475](0.000s) ok 183 - certificate authorization fails with revoked client cert: matches [08:09:27.476](0.000s) ok 184 - certificate authorization fails with revoked client cert: log does not match [08:09:27.496](0.021s) ok 185 - auth_option clientcert=verify-full succeeds with matching username and Common Name [08:09:27.496](0.000s) ok 186 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [08:09:27.497](0.000s) ok 187 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [08:09:27.512](0.016s) ok 188 - auth_option clientcert=verify-full fails with mismatching username and Common Name [08:09:27.513](0.000s) ok 189 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [08:09:27.513](0.000s) ok 190 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [08:09:27.530](0.017s) ok 191 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [08:09:27.530](0.000s) ok 192 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [08:09:27.530](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 51219 [08:09:27.756](0.225s) ok 194 - intermediate client certificate is provided by client [08:09:27.756](0.000s) ok 195 - intermediate client certificate is provided by client: no stderr [08:09:27.770](0.014s) ok 196 - intermediate client certificate is missing [08:09:27.770](0.000s) ok 197 - intermediate client certificate is missing: matches [08:09:27.784](0.014s) ok 198 - logged client certificate Subjects are truncated if they're too long [08:09:27.785](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 51233 [08:09:28.002](0.217s) ok 200 - intermediate client certificate is untrusted [08:09:28.002](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 51243 [08:09:28.219](0.217s) ok 202 - certificate authorization fails with revoked client cert with server-side CRL directory [08:09:28.219](0.000s) ok 203 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [08:09:28.233](0.014s) ok 204 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [08:09:28.233](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 51255 [08:09:28.450](0.217s) not ok 206 - connect with valid stapled ocsp response when sslocspstapling=1 [08:09:28.450](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:09:28.450](0.000s) # got: '2' # expected: '0' [08:09:28.451](0.000s) not ok 207 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [08:09:28.451](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:09:28.451](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 51236 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:09:28.469](0.019s) ok 208 - connect without requesting ocsp response when sslocspstapling=0 [08:09:28.470](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 51267 [08:09:28.685](0.216s) ok 210 - failed with a revoked ocsp response when sslocspstapling=1 [08:09:28.703](0.018s) ok 211 - connect without requesting ocsp response when sslocspstapling=0 [08:09:28.703](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 51279 [08:09:28.919](0.216s) ok 213 - failed with a revoked ocsp response when sslocspstapling=1 [08:09:28.937](0.019s) ok 214 - connect without requesting ocsp response when sslocspstapling=0 [08:09:28.938](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 51291 [08:09:29.154](0.216s) ok 216 - failed with an expired ocsp response when sslocspstapling=1 [08:09:29.172](0.019s) ok 217 - connect without requesting ocsp response when sslocspstapling=0 [08:09:29.173](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 51303 [08:09:29.389](0.217s) not ok 219 - connect with valid stapled ocsp response when sslocspstapling=1 [08:09:29.390](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:09:29.390](0.000s) # got: '2' # expected: '0' [08:09:29.390](0.000s) not ok 220 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [08:09:29.390](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:09:29.390](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 51236 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:09:29.409](0.019s) ok 221 - connect without requesting ocsp response when sslocspstapling=0 [08:09:29.409](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 51315 [08:09:29.629](0.220s) ok 223 - failed with a revoked ocsp response when sslocspstapling=1 [08:09:29.650](0.021s) ok 224 - connect without requesting ocsp response when sslocspstapling=0 [08:09:29.650](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 51327 [08:09:29.867](0.217s) ok 226 - failed with a revoked ocsp response when sslocspstapling=1 [08:09:29.888](0.021s) ok 227 - connect without requesting ocsp response when sslocspstapling=0 [08:09:29.889](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 51339 [08:09:30.105](0.217s) ok 229 - failed with an expired ocsp response when sslocspstapling=1 [08:09:30.124](0.019s) ok 230 - connect without requesting ocsp response when sslocspstapling=0 [08:09:30.125](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 51351 [08:09:30.344](0.220s) ok 232 - failed with an expired ocsp response when sslocspstapling=1 [08:09:30.364](0.020s) ok 233 - connect without requesting ocsp response when sslocspstapling=0 [08:09:30.364](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-30 08:09:21.929 UTC [50272][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:21.929 UTC [50272][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:21.933 UTC [50280][startup] LOG: database system was shut down at 2024-03-30 08:06:55 UTC 2024-03-30 08:09:21.935 UTC [50272][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:22.018 UTC [50321][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.019 UTC [50321][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-30 08:09:22.019 UTC [50321][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.024 UTC [50321][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-30 08:09:22.027 UTC [50321][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.035 UTC [50328][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.036 UTC [50328][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-30 08:09:22.036 UTC [50328][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.040 UTC [50328][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-30 08:09:22.045 UTC [50328][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.085 UTC [50348][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.085 UTC [50348][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-30 08:09:22.085 UTC [50348][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.086 UTC [50348][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-30 08:09:22.087 UTC [50348][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.127 UTC [50372][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.128 UTC [50372][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-30 08:09:22.128 UTC [50372][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.128 UTC [50372][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-30 08:09:22.129 UTC [50372][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.179 UTC [50400][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.179 UTC [50400][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-30 08:09:22.179 UTC [50400][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.180 UTC [50400][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-30 08:09:22.181 UTC [50400][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.002 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.221 UTC [50408][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.221 UTC [50408][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-30 08:09:22.221 UTC [50408][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.222 UTC [50408][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-30 08:09:22.255 UTC [50408][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.264 UTC [50416][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.265 UTC [50416][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-30 08:09:22.265 UTC [50416][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.266 UTC [50416][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-30 08:09:22.313 UTC [50416][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.049 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.386 UTC [50435][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.387 UTC [50435][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-30 08:09:22.387 UTC [50435][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.388 UTC [50435][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-30 08:09:22.414 UTC [50435][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.440 UTC [50451][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.441 UTC [50451][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-30 08:09:22.441 UTC [50451][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.442 UTC [50451][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-30 08:09:22.502 UTC [50451][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.062 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.553 UTC [50489][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.554 UTC [50489][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-30 08:09:22.554 UTC [50489][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.555 UTC [50489][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-30 08:09:22.585 UTC [50489][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.598 UTC [50503][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-30 08:09:22.599 UTC [50503][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-30 08:09:22.599 UTC [50503][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=postgres database=postgres application_name=001_ssltests.pl 2024-03-30 08:09:22.599 UTC [50503][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-30 08:09:22.645 UTC [50503][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.046 user=postgres database=postgres host=[local] 2024-03-30 08:09:22.719 UTC [50272][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:22.719 UTC [50272][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:22.721 UTC [50272][postmaster] LOG: background worker "logical replication launcher" (PID 50286) exited with exit code 1 2024-03-30 08:09:22.722 UTC [50278][checkpointer] LOG: shutting down 2024-03-30 08:09:22.722 UTC [50278][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:22.771 UTC [50278][checkpointer] LOG: checkpoint complete: wrote 5620 buffers (34.3%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.037 s, sync=0.001 s, total=0.050 s; sync files=0, longest=0.000 s, average=0.000 s; distance=45238 kB, estimate=45238 kB; lsn=0/414C400, redo lsn=0/414C400 2024-03-30 08:09:22.780 UTC [50272][postmaster] LOG: database system is shut down 2024-03-30 08:09:22.850 UTC [50563][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:22.851 UTC [50563][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:22.851 UTC [50563][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:22.869 UTC [50580][startup] LOG: database system was shut down at 2024-03-30 08:09:22 UTC 2024-03-30 08:09:22.872 UTC [50563][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:22.924 UTC [50563][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:22.924 UTC [50563][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:22.926 UTC [50563][postmaster] LOG: background worker "logical replication launcher" (PID 50587) exited with exit code 1 2024-03-30 08:09:22.926 UTC [50578][checkpointer] LOG: shutting down 2024-03-30 08:09:22.926 UTC [50578][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:22.927 UTC [50578][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/414C478, redo lsn=0/414C478 2024-03-30 08:09:22.930 UTC [50563][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.037 UTC [50639][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-30 08:09:23.037 UTC [50639][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.147 UTC [50667][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:23.147 UTC [50667][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:23.147 UTC [50667][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:23.149 UTC [50671][startup] LOG: database system was shut down at 2024-03-30 08:09:22 UTC 2024-03-30 08:09:23.153 UTC [50667][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:23.235 UTC [50667][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:23.235 UTC [50667][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:23.238 UTC [50667][postmaster] LOG: background worker "logical replication launcher" (PID 50674) exited with exit code 1 2024-03-30 08:09:23.238 UTC [50669][checkpointer] LOG: shutting down 2024-03-30 08:09:23.238 UTC [50669][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:23.239 UTC [50669][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/414C4F0, redo lsn=0/414C4F0 2024-03-30 08:09:23.242 UTC [50667][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.352 UTC [50734][postmaster] FATAL: could not set SSL protocol version range 2024-03-30 08:09:23.352 UTC [50734][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-30 08:09:23.352 UTC [50734][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.462 UTC [50755][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:23.462 UTC [50755][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:23.462 UTC [50755][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:23.465 UTC [50767][startup] LOG: database system was shut down at 2024-03-30 08:09:23 UTC 2024-03-30 08:09:23.471 UTC [50755][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:23.546 UTC [50755][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:23.546 UTC [50755][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:23.547 UTC [50755][postmaster] LOG: background worker "logical replication launcher" (PID 50770) exited with exit code 1 2024-03-30 08:09:23.548 UTC [50764][checkpointer] LOG: shutting down 2024-03-30 08:09:23.549 UTC [50764][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:23.549 UTC [50764][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/414C568, redo lsn=0/414C568 2024-03-30 08:09:23.552 UTC [50755][postmaster] LOG: database system is shut down 2024-03-30 08:09:23.669 UTC [50816][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:23.669 UTC [50816][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:23.669 UTC [50816][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:23.673 UTC [50825][startup] LOG: database system was shut down at 2024-03-30 08:09:23 UTC 2024-03-30 08:09:23.676 UTC [50816][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:23.760 UTC [50850][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59274 2024-03-30 08:09:23.760 UTC [50850][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-30 08:09:23.760 UTC [50850][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "localhost", forward lookup not checked. 2024-03-30 08:09:23.770 UTC [50852][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59286 2024-03-30 08:09:23.773 UTC [50852][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-30 08:09:23.773 UTC [50852][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-30 08:09:23.779 UTC [50852][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-30 08:09:23.779 UTC [50852][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=59286 2024-03-30 08:09:23.789 UTC [50854][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59292 2024-03-30 08:09:23.790 UTC [50854][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-30 08:09:23.800 UTC [50857][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59306 2024-03-30 08:09:23.801 UTC [50857][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-30 08:09:23.810 UTC [50859][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59322 2024-03-30 08:09:23.814 UTC [50859][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-30 08:09:23.824 UTC [50871][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59324 2024-03-30 08:09:23.827 UTC [50871][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-30 08:09:23.836 UTC [50875][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59340 2024-03-30 08:09:23.839 UTC [50875][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-30 08:09:23.850 UTC [50879][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59344 2024-03-30 08:09:23.854 UTC [50879][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-30 08:09:23.863 UTC [50884][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59346 2024-03-30 08:09:23.867 UTC [50884][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-30 08:09:23.867 UTC [50884][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-30 08:09:23.868 UTC [50884][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-30 08:09:23.869 UTC [50884][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59346 2024-03-30 08:09:23.879 UTC [50886][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59354 2024-03-30 08:09:23.883 UTC [50886][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-30 08:09:23.883 UTC [50886][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-30 08:09:23.884 UTC [50886][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-30 08:09:23.885 UTC [50886][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59354 2024-03-30 08:09:23.894 UTC [50888][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59362 2024-03-30 08:09:23.898 UTC [50888][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-30 08:09:23.898 UTC [50888][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-30 08:09:23.899 UTC [50888][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-30 08:09:23.900 UTC [50888][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59362 2024-03-30 08:09:23.911 UTC [50892][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59368 2024-03-30 08:09:23.915 UTC [50892][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-30 08:09:23.915 UTC [50892][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-30 08:09:23.916 UTC [50892][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-30 08:09:23.918 UTC [50892][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=ssltestuser database=trustdb host=localhost port=59368 2024-03-30 08:09:23.926 UTC [50895][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59374 2024-03-30 08:09:23.930 UTC [50895][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-30 08:09:23.930 UTC [50895][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-30 08:09:23.931 UTC [50895][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-30 08:09:23.932 UTC [50895][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59374 2024-03-30 08:09:23.941 UTC [50897][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59384 2024-03-30 08:09:23.945 UTC [50897][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-30 08:09:23.945 UTC [50897][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-30 08:09:23.946 UTC [50897][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-30 08:09:23.946 UTC [50897][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59384 2024-03-30 08:09:23.956 UTC [50899][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59394 2024-03-30 08:09:23.960 UTC [50899][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-30 08:09:23.960 UTC [50899][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-30 08:09:23.961 UTC [50899][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-30 08:09:23.961 UTC [50899][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59394 2024-03-30 08:09:23.971 UTC [50902][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59398 2024-03-30 08:09:23.975 UTC [50902][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-30 08:09:23.975 UTC [50902][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-30 08:09:23.976 UTC [50902][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59398 2024-03-30 08:09:23.986 UTC [50910][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59412 2024-03-30 08:09:23.990 UTC [50910][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-30 08:09:23.990 UTC [50910][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-30 08:09:23.991 UTC [50910][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-30 08:09:23.992 UTC [50910][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59412 2024-03-30 08:09:24.002 UTC [50912][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59420 2024-03-30 08:09:24.005 UTC [50912][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-30 08:09:24.014 UTC [50916][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59422 2024-03-30 08:09:24.018 UTC [50916][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-30 08:09:24.026 UTC [50918][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59424 2024-03-30 08:09:24.031 UTC [50918][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-30 08:09:24.031 UTC [50918][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-30 08:09:24.032 UTC [50918][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-30 08:09:24.033 UTC [50918][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59424 2024-03-30 08:09:24.041 UTC [50920][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59432 2024-03-30 08:09:24.045 UTC [50920][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-30 08:09:24.045 UTC [50920][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-30 08:09:24.046 UTC [50920][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-30 08:09:24.046 UTC [50920][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59432 2024-03-30 08:09:24.055 UTC [50922][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59436 2024-03-30 08:09:24.059 UTC [50922][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-30 08:09:24.059 UTC [50922][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-30 08:09:24.059 UTC [50922][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-30 08:09:24.060 UTC [50922][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59436 2024-03-30 08:09:24.071 UTC [50926][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59444 2024-03-30 08:09:24.074 UTC [50926][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-30 08:09:24.074 UTC [50926][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-30 08:09:24.075 UTC [50926][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-30 08:09:24.077 UTC [50926][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=ssltestuser database=trustdb host=localhost port=59444 2024-03-30 08:09:24.086 UTC [50929][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59448 2024-03-30 08:09:24.094 UTC [50816][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:24.094 UTC [50816][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:24.095 UTC [50816][postmaster] LOG: background worker "logical replication launcher" (PID 50829) exited with exit code 1 2024-03-30 08:09:24.097 UTC [50823][checkpointer] LOG: shutting down 2024-03-30 08:09:24.097 UTC [50823][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:24.097 UTC [50823][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/414C5E0, redo lsn=0/414C5E0 2024-03-30 08:09:24.101 UTC [50816][postmaster] LOG: database system is shut down 2024-03-30 08:09:24.214 UTC [50934][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:24.214 UTC [50934][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:24.214 UTC [50934][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:24.216 UTC [50943][startup] LOG: database system was shut down at 2024-03-30 08:09:24 UTC 2024-03-30 08:09:24.220 UTC [50934][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:24.303 UTC [50951][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59458 2024-03-30 08:09:24.307 UTC [50951][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-30 08:09:24.307 UTC [50951][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-30 08:09:24.312 UTC [50951][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-30 08:09:24.312 UTC [50951][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=59458 2024-03-30 08:09:24.322 UTC [50954][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59460 2024-03-30 08:09:24.330 UTC [50934][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:24.330 UTC [50934][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:24.332 UTC [50934][postmaster] LOG: background worker "logical replication launcher" (PID 50946) exited with exit code 1 2024-03-30 08:09:24.332 UTC [50941][checkpointer] LOG: shutting down 2024-03-30 08:09:24.332 UTC [50941][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:24.332 UTC [50941][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/414C658, redo lsn=0/414C658 2024-03-30 08:09:24.335 UTC [50934][postmaster] LOG: database system is shut down 2024-03-30 08:09:24.449 UTC [50964][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:24.449 UTC [50964][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:24.449 UTC [50964][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:24.452 UTC [50967][startup] LOG: database system was shut down at 2024-03-30 08:09:24 UTC 2024-03-30 08:09:24.455 UTC [50964][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:24.539 UTC [50977][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59468 2024-03-30 08:09:24.543 UTC [50977][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-30 08:09:24.543 UTC [50977][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-30 08:09:24.548 UTC [50977][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-30 08:09:24.549 UTC [50977][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=59468 2024-03-30 08:09:24.553 UTC [50964][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:24.553 UTC [50964][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:24.555 UTC [50964][postmaster] LOG: background worker "logical replication launcher" (PID 50970) exited with exit code 1 2024-03-30 08:09:24.556 UTC [50965][checkpointer] LOG: shutting down 2024-03-30 08:09:24.556 UTC [50965][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:24.556 UTC [50965][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/414C6D0, redo lsn=0/414C6D0 2024-03-30 08:09:24.559 UTC [50964][postmaster] LOG: database system is shut down 2024-03-30 08:09:24.672 UTC [50987][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:24.672 UTC [50987][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:24.672 UTC [50987][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:24.675 UTC [50991][startup] LOG: database system was shut down at 2024-03-30 08:09:24 UTC 2024-03-30 08:09:24.678 UTC [50987][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:24.763 UTC [50999][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59470 2024-03-30 08:09:24.767 UTC [50999][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-30 08:09:24.767 UTC [50999][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-30 08:09:24.772 UTC [50999][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-30 08:09:24.772 UTC [50999][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59470 2024-03-30 08:09:24.782 UTC [51001][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59474 2024-03-30 08:09:24.786 UTC [51001][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-30 08:09:24.786 UTC [51001][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-30 08:09:24.787 UTC [51001][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-30 08:09:24.788 UTC [51001][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59474 2024-03-30 08:09:24.798 UTC [51005][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59490 2024-03-30 08:09:24.802 UTC [51005][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-30 08:09:24.802 UTC [51005][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-30 08:09:24.803 UTC [51005][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-30 08:09:24.804 UTC [51005][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59490 2024-03-30 08:09:24.814 UTC [51007][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59504 2024-03-30 08:09:24.828 UTC [51009][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59518 2024-03-30 08:09:24.836 UTC [50987][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:24.836 UTC [50987][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:24.838 UTC [50987][postmaster] LOG: background worker "logical replication launcher" (PID 50994) exited with exit code 1 2024-03-30 08:09:24.839 UTC [50989][checkpointer] LOG: shutting down 2024-03-30 08:09:24.839 UTC [50989][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:24.840 UTC [50989][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/414C748, redo lsn=0/414C748 2024-03-30 08:09:24.843 UTC [50987][postmaster] LOG: database system is shut down 2024-03-30 08:09:24.955 UTC [51018][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:24.955 UTC [51018][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:24.955 UTC [51018][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:24.957 UTC [51023][startup] LOG: database system was shut down at 2024-03-30 08:09:24 UTC 2024-03-30 08:09:24.960 UTC [51018][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:25.046 UTC [51031][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59526 2024-03-30 08:09:25.050 UTC [51031][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-30 08:09:25.050 UTC [51031][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-30 08:09:25.055 UTC [51031][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-30 08:09:25.055 UTC [51031][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59526 2024-03-30 08:09:25.065 UTC [51033][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59530 2024-03-30 08:09:25.078 UTC [51035][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59544 2024-03-30 08:09:25.090 UTC [51018][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:25.090 UTC [51018][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:25.091 UTC [51018][postmaster] LOG: background worker "logical replication launcher" (PID 51026) exited with exit code 1 2024-03-30 08:09:25.092 UTC [51021][checkpointer] LOG: shutting down 2024-03-30 08:09:25.092 UTC [51021][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:25.092 UTC [51021][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/414C7C0, redo lsn=0/414C7C0 2024-03-30 08:09:25.095 UTC [51018][postmaster] LOG: database system is shut down 2024-03-30 08:09:25.209 UTC [51047][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:25.209 UTC [51047][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:25.209 UTC [51047][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:25.212 UTC [51052][startup] LOG: database system was shut down at 2024-03-30 08:09:25 UTC 2024-03-30 08:09:25.215 UTC [51047][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:25.298 UTC [51059][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59556 2024-03-30 08:09:25.302 UTC [51059][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-30 08:09:25.302 UTC [51059][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-30 08:09:25.307 UTC [51059][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-30 08:09:25.308 UTC [51059][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59556 2024-03-30 08:09:25.318 UTC [51061][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59558 2024-03-30 08:09:25.323 UTC [51061][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-30 08:09:25.323 UTC [51061][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-30 08:09:25.324 UTC [51061][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-30 08:09:25.324 UTC [51061][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59558 2024-03-30 08:09:25.334 UTC [51063][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59562 2024-03-30 08:09:25.347 UTC [51065][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59574 2024-03-30 08:09:25.351 UTC [51065][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-30 08:09:25.351 UTC [51065][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-30 08:09:25.352 UTC [51065][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-30 08:09:25.353 UTC [51065][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59574 2024-03-30 08:09:25.362 UTC [51067][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59582 2024-03-30 08:09:25.366 UTC [51067][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-30 08:09:25.366 UTC [51067][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-30 08:09:25.367 UTC [51067][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-30 08:09:25.368 UTC [51067][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59582 2024-03-30 08:09:25.377 UTC [51069][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59586 2024-03-30 08:09:25.381 UTC [51069][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-30 08:09:25.381 UTC [51069][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-30 08:09:25.382 UTC [51069][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-30 08:09:25.382 UTC [51069][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59586 2024-03-30 08:09:25.391 UTC [51071][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59590 2024-03-30 08:09:25.403 UTC [51073][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59596 2024-03-30 08:09:25.411 UTC [51047][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:25.411 UTC [51047][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:25.413 UTC [51047][postmaster] LOG: background worker "logical replication launcher" (PID 51055) exited with exit code 1 2024-03-30 08:09:25.413 UTC [51050][checkpointer] LOG: shutting down 2024-03-30 08:09:25.413 UTC [51050][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:25.413 UTC [51050][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/414C838, redo lsn=0/414C838 2024-03-30 08:09:25.416 UTC [51047][postmaster] LOG: database system is shut down 2024-03-30 08:09:25.530 UTC [51075][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:25.530 UTC [51075][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:25.531 UTC [51075][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:25.533 UTC [51078][startup] LOG: database system was shut down at 2024-03-30 08:09:25 UTC 2024-03-30 08:09:25.537 UTC [51075][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:25.620 UTC [51083][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59608 2024-03-30 08:09:25.624 UTC [51083][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-30 08:09:25.624 UTC [51083][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-30 08:09:25.629 UTC [51083][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-30 08:09:25.630 UTC [51083][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59608 2024-03-30 08:09:25.640 UTC [51085][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59614 2024-03-30 08:09:25.644 UTC [51085][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-30 08:09:25.644 UTC [51085][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-30 08:09:25.645 UTC [51085][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-30 08:09:25.645 UTC [51085][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59614 2024-03-30 08:09:25.655 UTC [51087][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59624 2024-03-30 08:09:25.666 UTC [51075][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:25.666 UTC [51075][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:25.669 UTC [51075][postmaster] LOG: background worker "logical replication launcher" (PID 51081) exited with exit code 1 2024-03-30 08:09:25.669 UTC [51076][checkpointer] LOG: shutting down 2024-03-30 08:09:25.669 UTC [51076][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:25.670 UTC [51076][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/414C8B0, redo lsn=0/414C8B0 2024-03-30 08:09:25.673 UTC [51075][postmaster] LOG: database system is shut down 2024-03-30 08:09:25.785 UTC [51090][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:25.785 UTC [51090][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:25.785 UTC [51090][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:25.788 UTC [51093][startup] LOG: database system was shut down at 2024-03-30 08:09:25 UTC 2024-03-30 08:09:25.791 UTC [51090][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:25.875 UTC [51098][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59628 2024-03-30 08:09:25.879 UTC [51098][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-30 08:09:25.879 UTC [51098][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-30 08:09:25.884 UTC [51098][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-30 08:09:25.885 UTC [51098][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59628 2024-03-30 08:09:25.894 UTC [51100][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59644 2024-03-30 08:09:25.898 UTC [51100][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-30 08:09:25.898 UTC [51100][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-30 08:09:25.899 UTC [51100][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-30 08:09:25.899 UTC [51100][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59644 2024-03-30 08:09:25.908 UTC [51102][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59656 2024-03-30 08:09:25.912 UTC [51102][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-30 08:09:25.912 UTC [51102][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-30 08:09:25.913 UTC [51102][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-30 08:09:25.914 UTC [51102][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59656 2024-03-30 08:09:25.918 UTC [51090][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:25.918 UTC [51090][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:25.919 UTC [51090][postmaster] LOG: background worker "logical replication launcher" (PID 51096) exited with exit code 1 2024-03-30 08:09:25.919 UTC [51091][checkpointer] LOG: shutting down 2024-03-30 08:09:25.919 UTC [51091][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:25.920 UTC [51091][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/414C928, redo lsn=0/414C928 2024-03-30 08:09:25.923 UTC [51090][postmaster] LOG: database system is shut down 2024-03-30 08:09:26.037 UTC [51104][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:26.037 UTC [51104][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:26.037 UTC [51104][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:26.039 UTC [51107][startup] LOG: database system was shut down at 2024-03-30 08:09:25 UTC 2024-03-30 08:09:26.042 UTC [51104][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:26.127 UTC [51112][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59662 2024-03-30 08:09:26.131 UTC [51112][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-30 08:09:26.131 UTC [51112][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-30 08:09:26.136 UTC [51112][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-30 08:09:26.137 UTC [51112][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59662 2024-03-30 08:09:26.147 UTC [51114][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59672 2024-03-30 08:09:26.151 UTC [51114][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-30 08:09:26.151 UTC [51114][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-30 08:09:26.152 UTC [51114][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-30 08:09:26.153 UTC [51114][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59672 2024-03-30 08:09:26.164 UTC [51116][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59688 2024-03-30 08:09:26.171 UTC [51104][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:26.171 UTC [51104][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:26.173 UTC [51104][postmaster] LOG: background worker "logical replication launcher" (PID 51110) exited with exit code 1 2024-03-30 08:09:26.173 UTC [51105][checkpointer] LOG: shutting down 2024-03-30 08:09:26.173 UTC [51105][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:26.174 UTC [51105][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/414C9A0, redo lsn=0/414C9A0 2024-03-30 08:09:26.177 UTC [51104][postmaster] LOG: database system is shut down 2024-03-30 08:09:26.291 UTC [51118][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:26.291 UTC [51118][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:26.291 UTC [51118][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:26.293 UTC [51121][startup] LOG: database system was shut down at 2024-03-30 08:09:26 UTC 2024-03-30 08:09:26.297 UTC [51118][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:26.381 UTC [51126][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59690 2024-03-30 08:09:26.385 UTC [51126][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-30 08:09:26.385 UTC [51126][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-30 08:09:26.390 UTC [51126][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-30 08:09:26.391 UTC [51126][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59690 2024-03-30 08:09:26.400 UTC [51128][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59706 2024-03-30 08:09:26.405 UTC [51128][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-30 08:09:26.405 UTC [51128][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-30 08:09:26.406 UTC [51128][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-30 08:09:26.407 UTC [51128][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59706 2024-03-30 08:09:26.417 UTC [51130][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59716 2024-03-30 08:09:26.421 UTC [51130][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-30 08:09:26.421 UTC [51130][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-30 08:09:26.422 UTC [51130][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-30 08:09:26.422 UTC [51130][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59716 2024-03-30 08:09:26.427 UTC [51118][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:26.427 UTC [51118][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:26.428 UTC [51118][postmaster] LOG: background worker "logical replication launcher" (PID 51124) exited with exit code 1 2024-03-30 08:09:26.428 UTC [51119][checkpointer] LOG: shutting down 2024-03-30 08:09:26.429 UTC [51119][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:26.429 UTC [51119][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/414CA18, redo lsn=0/414CA18 2024-03-30 08:09:26.432 UTC [51118][postmaster] LOG: database system is shut down 2024-03-30 08:09:26.546 UTC [51132][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:26.546 UTC [51132][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:26.546 UTC [51132][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:26.549 UTC [51135][startup] LOG: database system was shut down at 2024-03-30 08:09:26 UTC 2024-03-30 08:09:26.553 UTC [51132][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:26.636 UTC [51140][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59732 2024-03-30 08:09:26.640 UTC [51140][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-30 08:09:26.640 UTC [51140][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-30 08:09:26.645 UTC [51140][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-30 08:09:26.646 UTC [51140][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=59732 2024-03-30 08:09:26.656 UTC [51142][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59738 2024-03-30 08:09:26.664 UTC [51132][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:26.664 UTC [51132][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:26.666 UTC [51132][postmaster] LOG: background worker "logical replication launcher" (PID 51138) exited with exit code 1 2024-03-30 08:09:26.666 UTC [51133][checkpointer] LOG: shutting down 2024-03-30 08:09:26.666 UTC [51133][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:26.667 UTC [51133][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/414CA90, redo lsn=0/414CA90 2024-03-30 08:09:26.670 UTC [51132][postmaster] LOG: database system is shut down 2024-03-30 08:09:26.783 UTC [51144][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:26.783 UTC [51144][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:26.783 UTC [51144][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:26.786 UTC [51147][startup] LOG: database system was shut down at 2024-03-30 08:09:26 UTC 2024-03-30 08:09:26.789 UTC [51144][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:26.874 UTC [51152][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59746 2024-03-30 08:09:26.878 UTC [51152][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-30 08:09:26.894 UTC [51155][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59752 2024-03-30 08:09:26.898 UTC [51155][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-30 08:09:26.898 UTC [51155][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-30 08:09:26.903 UTC [51155][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-30 08:09:26.904 UTC [51155][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=59752 2024-03-30 08:09:26.913 UTC [51157][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59768 2024-03-30 08:09:26.920 UTC [51144][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:26.920 UTC [51144][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:26.921 UTC [51144][postmaster] LOG: background worker "logical replication launcher" (PID 51150) exited with exit code 1 2024-03-30 08:09:26.922 UTC [51145][checkpointer] LOG: shutting down 2024-03-30 08:09:26.922 UTC [51145][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:26.922 UTC [51145][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/414CB08, redo lsn=0/414CB08 2024-03-30 08:09:26.925 UTC [51144][postmaster] LOG: database system is shut down 2024-03-30 08:09:27.039 UTC [51159][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:27.039 UTC [51159][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:27.040 UTC [51159][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:27.042 UTC [51162][startup] LOG: database system was shut down at 2024-03-30 08:09:26 UTC 2024-03-30 08:09:27.046 UTC [51159][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:27.129 UTC [51167][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59772 2024-03-30 08:09:27.133 UTC [51167][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-30 08:09:27.133 UTC [51167][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-30 08:09:27.138 UTC [51167][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-30 08:09:27.138 UTC [51167][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=59772 2024-03-30 08:09:27.147 UTC [51169][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59788 2024-03-30 08:09:27.150 UTC [51169][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-30 08:09:27.158 UTC [51171][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59800 2024-03-30 08:09:27.161 UTC [51171][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-30 08:09:27.168 UTC [51173][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59808 2024-03-30 08:09:27.172 UTC [51173][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-30 08:09:27.172 UTC [51173][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-30 08:09:27.173 UTC [51173][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-30 08:09:27.174 UTC [51173][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=trustdb host=localhost port=59808 2024-03-30 08:09:27.182 UTC [51175][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59812 2024-03-30 08:09:27.186 UTC [51175][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-30 08:09:27.186 UTC [51175][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-30 08:09:27.187 UTC [51175][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-30 08:09:27.187 UTC [51175][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.005 user=ssltestuser database=trustdb host=localhost port=59812 2024-03-30 08:09:27.219 UTC [51180][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59818 2024-03-30 08:09:27.223 UTC [51180][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-30 08:09:27.231 UTC [51182][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59830 2024-03-30 08:09:27.236 UTC [51182][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-30 08:09:27.236 UTC [51182][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-30 08:09:27.241 UTC [51182][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_IiR4/client.key$$ 2024-03-30 08:09:27.241 UTC [51182][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=certdb host=localhost port=59830 2024-03-30 08:09:27.249 UTC [51184][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59832 2024-03-30 08:09:27.254 UTC [51184][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-30 08:09:27.254 UTC [51184][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-30 08:09:27.255 UTC [51184][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_IiR4/client-der.key$$ 2024-03-30 08:09:27.255 UTC [51184][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=certdb host=localhost port=59832 2024-03-30 08:09:27.262 UTC [51186][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59838 2024-03-30 08:09:27.267 UTC [51186][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-30 08:09:27.267 UTC [51186][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-30 08:09:27.268 UTC [51186][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_IiR4/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-30 08:09:27.269 UTC [51186][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=ssltestuser database=certdb host=localhost port=59838 2024-03-30 08:09:27.276 UTC [51188][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59846 2024-03-30 08:09:27.281 UTC [51188][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-30 08:09:27.281 UTC [51188][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-30 08:09:27.282 UTC [51188][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_IiR4/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-30 08:09:27.282 UTC [51188][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.006 user=ssltestuser database=certdb host=localhost port=59846 2024-03-30 08:09:27.290 UTC [51190][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59848 2024-03-30 08:09:27.296 UTC [51190][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-30 08:09:27.296 UTC [51190][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-30 08:09:27.297 UTC [51190][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_IiR4/client.key$$ 2024-03-30 08:09:27.298 UTC [51190][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=ssltestuser database=certdb host=localhost port=59848 2024-03-30 08:09:27.308 UTC [51192][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59860 2024-03-30 08:09:27.314 UTC [51192][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-30 08:09:27.314 UTC [51192][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-30 08:09:27.315 UTC [51192][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_IiR4/client.key$$ 2024-03-30 08:09:27.316 UTC [51192][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=ssltestuser database=certdb host=localhost port=59860 2024-03-30 08:09:27.326 UTC [51194][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59866 2024-03-30 08:09:27.330 UTC [51194][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-30 08:09:27.340 UTC [51196][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59874 2024-03-30 08:09:27.341 UTC [51196][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-30 08:09:27.351 UTC [51198][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59882 2024-03-30 08:09:27.357 UTC [51198][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-30 08:09:27.357 UTC [51198][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-30 08:09:27.362 UTC [51198][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_IiR4/client-dn.key$$ 2024-03-30 08:09:27.363 UTC [51198][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=certdb_dn host=localhost port=59882 2024-03-30 08:09:27.373 UTC [51200][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59898 2024-03-30 08:09:27.378 UTC [51200][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-30 08:09:27.378 UTC [51200][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-30 08:09:27.383 UTC [51200][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_IiR4/client-dn.key$$ 2024-03-30 08:09:27.384 UTC [51200][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=certdb_dn_re host=localhost port=59898 2024-03-30 08:09:27.394 UTC [51202][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59900 2024-03-30 08:09:27.400 UTC [51202][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-30 08:09:27.400 UTC [51202][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-30 08:09:27.405 UTC [51202][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_IiR4/client-dn.key$$ 2024-03-30 08:09:27.405 UTC [51202][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.012 user=ssltestuser database=certdb_cn host=localhost port=59900 2024-03-30 08:09:27.426 UTC [51205][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59906 2024-03-30 08:09:27.431 UTC [51205][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-30 08:09:27.432 UTC [51205][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-30 08:09:27.433 UTC [51205][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-30 08:09:27.434 UTC [51205][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=ssltestuser database=certdb host=localhost port=59906 2024-03-30 08:09:27.444 UTC [51207][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59920 2024-03-30 08:09:27.445 UTC [51207][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-30 08:09:27.454 UTC [51209][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59922 2024-03-30 08:09:27.459 UTC [51209][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-30 08:09:27.459 UTC [51209][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-30 08:09:27.459 UTC [51209][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-30 08:09:27.459 UTC [51209][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-30 08:09:27.469 UTC [51211][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59936 2024-03-30 08:09:27.474 UTC [51211][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-30 08:09:27.474 UTC [51211][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-30 08:09:27.484 UTC [51213][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59942 2024-03-30 08:09:27.489 UTC [51213][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-30 08:09:27.489 UTC [51213][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-30 08:09:27.494 UTC [51213][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_IiR4/client.key$$ 2024-03-30 08:09:27.495 UTC [51213][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=verifydb host=localhost port=59942 2024-03-30 08:09:27.505 UTC [51215][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59944 2024-03-30 08:09:27.511 UTC [51215][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-30 08:09:27.511 UTC [51215][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-30 08:09:27.511 UTC [51215][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-30 08:09:27.511 UTC [51215][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-30 08:09:27.521 UTC [51217][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59952 2024-03-30 08:09:27.526 UTC [51217][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-30 08:09:27.526 UTC [51217][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-30 08:09:27.528 UTC [51217][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_IiR4/client.key$$ 2024-03-30 08:09:27.528 UTC [51217][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=yetanotheruser database=verifydb host=localhost port=59952 2024-03-30 08:09:27.533 UTC [51159][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:27.533 UTC [51159][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:27.534 UTC [51159][postmaster] LOG: background worker "logical replication launcher" (PID 51165) exited with exit code 1 2024-03-30 08:09:27.535 UTC [51160][checkpointer] LOG: shutting down 2024-03-30 08:09:27.535 UTC [51160][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:27.535 UTC [51160][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/414CB80, redo lsn=0/414CB80 2024-03-30 08:09:27.539 UTC [51159][postmaster] LOG: database system is shut down 2024-03-30 08:09:27.653 UTC [51219][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:27.653 UTC [51219][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:27.653 UTC [51219][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:27.656 UTC [51222][startup] LOG: database system was shut down at 2024-03-30 08:09:27 UTC 2024-03-30 08:09:27.660 UTC [51219][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:27.743 UTC [51227][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59958 2024-03-30 08:09:27.748 UTC [51227][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-30 08:09:27.748 UTC [51227][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-30 08:09:27.753 UTC [51227][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_IiR4/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-30 08:09:27.754 UTC [51227][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=ssltestuser database=certdb host=localhost port=59958 2024-03-30 08:09:27.764 UTC [51229][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59964 2024-03-30 08:09:27.768 UTC [51229][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-30 08:09:27.768 UTC [51229][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-30 08:09:27.778 UTC [51231][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59976 2024-03-30 08:09:27.783 UTC [51231][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-30 08:09:27.783 UTC [51231][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-30 08:09:27.787 UTC [51219][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:27.787 UTC [51219][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:27.789 UTC [51219][postmaster] LOG: background worker "logical replication launcher" (PID 51225) exited with exit code 1 2024-03-30 08:09:27.789 UTC [51220][checkpointer] LOG: shutting down 2024-03-30 08:09:27.789 UTC [51220][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:27.790 UTC [51220][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/414CBF8, redo lsn=0/414CBF8 2024-03-30 08:09:27.793 UTC [51219][postmaster] LOG: database system is shut down 2024-03-30 08:09:27.905 UTC [51233][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:27.905 UTC [51233][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:27.905 UTC [51233][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:27.907 UTC [51236][startup] LOG: database system was shut down at 2024-03-30 08:09:27 UTC 2024-03-30 08:09:27.910 UTC [51233][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:27.996 UTC [51241][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59992 2024-03-30 08:09:28.000 UTC [51241][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-30 08:09:28.000 UTC [51241][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-30 08:09:28.004 UTC [51233][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:28.004 UTC [51233][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:28.006 UTC [51233][postmaster] LOG: background worker "logical replication launcher" (PID 51239) exited with exit code 1 2024-03-30 08:09:28.006 UTC [51234][checkpointer] LOG: shutting down 2024-03-30 08:09:28.006 UTC [51234][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:28.006 UTC [51234][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/414CC70, redo lsn=0/414CC70 2024-03-30 08:09:28.009 UTC [51233][postmaster] LOG: database system is shut down 2024-03-30 08:09:28.122 UTC [51243][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:28.122 UTC [51243][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:28.122 UTC [51243][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:28.124 UTC [51246][startup] LOG: database system was shut down at 2024-03-30 08:09:28 UTC 2024-03-30 08:09:28.127 UTC [51243][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:28.213 UTC [51251][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=59996 2024-03-30 08:09:28.218 UTC [51251][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-30 08:09:28.218 UTC [51251][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-30 08:09:28.227 UTC [51253][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60008 2024-03-30 08:09:28.231 UTC [51253][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-30 08:09:28.231 UTC [51253][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-30 08:09:28.236 UTC [51243][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:28.236 UTC [51243][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:28.237 UTC [51243][postmaster] LOG: background worker "logical replication launcher" (PID 51249) exited with exit code 1 2024-03-30 08:09:28.238 UTC [51244][checkpointer] LOG: shutting down 2024-03-30 08:09:28.238 UTC [51244][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:28.238 UTC [51244][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/414CCE8, redo lsn=0/414CCE8 2024-03-30 08:09:28.241 UTC [51243][postmaster] LOG: database system is shut down 2024-03-30 08:09:28.355 UTC [51255][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:28.355 UTC [51255][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:28.355 UTC [51255][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:28.357 UTC [51258][startup] LOG: database system was shut down at 2024-03-30 08:09:28 UTC 2024-03-30 08:09:28.360 UTC [51255][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:28.446 UTC [51263][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60012 2024-03-30 08:09:28.447 UTC [51263][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:28.447 UTC [51263][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:28.458 UTC [51265][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60020 2024-03-30 08:09:28.462 UTC [51265][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-30 08:09:28.462 UTC [51265][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-30 08:09:28.467 UTC [51265][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-30 08:09:28.468 UTC [51265][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=60020 2024-03-30 08:09:28.472 UTC [51255][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:28.472 UTC [51255][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:28.474 UTC [51255][postmaster] LOG: background worker "logical replication launcher" (PID 51261) exited with exit code 1 2024-03-30 08:09:28.474 UTC [51256][checkpointer] LOG: shutting down 2024-03-30 08:09:28.474 UTC [51256][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:28.475 UTC [51256][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/414CD60, redo lsn=0/414CD60 2024-03-30 08:09:28.478 UTC [51255][postmaster] LOG: database system is shut down 2024-03-30 08:09:28.591 UTC [51267][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:28.592 UTC [51267][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:28.592 UTC [51267][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:28.594 UTC [51270][startup] LOG: database system was shut down at 2024-03-30 08:09:28 UTC 2024-03-30 08:09:28.598 UTC [51267][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:28.681 UTC [51275][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60022 2024-03-30 08:09:28.682 UTC [51275][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:28.682 UTC [51275][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:28.692 UTC [51277][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60034 2024-03-30 08:09:28.696 UTC [51277][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-30 08:09:28.696 UTC [51277][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-30 08:09:28.701 UTC [51277][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-30 08:09:28.701 UTC [51277][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=60034 2024-03-30 08:09:28.706 UTC [51267][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:28.706 UTC [51267][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:28.707 UTC [51267][postmaster] LOG: background worker "logical replication launcher" (PID 51273) exited with exit code 1 2024-03-30 08:09:28.707 UTC [51268][checkpointer] LOG: shutting down 2024-03-30 08:09:28.707 UTC [51268][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:28.708 UTC [51268][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/414CDD8, redo lsn=0/414CDD8 2024-03-30 08:09:28.711 UTC [51267][postmaster] LOG: database system is shut down 2024-03-30 08:09:28.826 UTC [51279][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:28.826 UTC [51279][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:28.826 UTC [51279][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:28.828 UTC [51282][startup] LOG: database system was shut down at 2024-03-30 08:09:28 UTC 2024-03-30 08:09:28.832 UTC [51279][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:28.915 UTC [51287][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60044 2024-03-30 08:09:28.916 UTC [51287][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:28.916 UTC [51287][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:28.926 UTC [51289][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60050 2024-03-30 08:09:28.930 UTC [51289][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-30 08:09:28.930 UTC [51289][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-30 08:09:28.935 UTC [51289][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-30 08:09:28.936 UTC [51289][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=60050 2024-03-30 08:09:28.940 UTC [51279][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:28.940 UTC [51279][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:28.942 UTC [51279][postmaster] LOG: background worker "logical replication launcher" (PID 51285) exited with exit code 1 2024-03-30 08:09:28.942 UTC [51280][checkpointer] LOG: shutting down 2024-03-30 08:09:28.942 UTC [51280][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:28.942 UTC [51280][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/414CE50, redo lsn=0/414CE50 2024-03-30 08:09:28.945 UTC [51279][postmaster] LOG: database system is shut down 2024-03-30 08:09:29.059 UTC [51291][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:29.059 UTC [51291][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:29.059 UTC [51291][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:29.061 UTC [51294][startup] LOG: database system was shut down at 2024-03-30 08:09:28 UTC 2024-03-30 08:09:29.064 UTC [51291][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:29.150 UTC [51299][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60056 2024-03-30 08:09:29.151 UTC [51299][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:29.151 UTC [51299][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:29.161 UTC [51301][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60068 2024-03-30 08:09:29.165 UTC [51301][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-30 08:09:29.165 UTC [51301][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-30 08:09:29.170 UTC [51301][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-30 08:09:29.171 UTC [51301][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=60068 2024-03-30 08:09:29.175 UTC [51291][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:29.175 UTC [51291][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:29.177 UTC [51291][postmaster] LOG: background worker "logical replication launcher" (PID 51297) exited with exit code 1 2024-03-30 08:09:29.177 UTC [51292][checkpointer] LOG: shutting down 2024-03-30 08:09:29.177 UTC [51292][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:29.178 UTC [51292][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/414CEC8, redo lsn=0/414CEC8 2024-03-30 08:09:29.181 UTC [51291][postmaster] LOG: database system is shut down 2024-03-30 08:09:29.294 UTC [51303][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:29.294 UTC [51303][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:29.295 UTC [51303][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:29.297 UTC [51306][startup] LOG: database system was shut down at 2024-03-30 08:09:29 UTC 2024-03-30 08:09:29.300 UTC [51303][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:29.385 UTC [51311][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60072 2024-03-30 08:09:29.386 UTC [51311][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:29.386 UTC [51311][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:29.398 UTC [51313][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60080 2024-03-30 08:09:29.402 UTC [51313][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-30 08:09:29.402 UTC [51313][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-30 08:09:29.407 UTC [51313][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-30 08:09:29.408 UTC [51313][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=60080 2024-03-30 08:09:29.412 UTC [51303][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:29.412 UTC [51303][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:29.413 UTC [51303][postmaster] LOG: background worker "logical replication launcher" (PID 51309) exited with exit code 1 2024-03-30 08:09:29.414 UTC [51304][checkpointer] LOG: shutting down 2024-03-30 08:09:29.414 UTC [51304][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:29.414 UTC [51304][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/414CF40, redo lsn=0/414CF40 2024-03-30 08:09:29.417 UTC [51303][postmaster] LOG: database system is shut down 2024-03-30 08:09:29.532 UTC [51315][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:29.532 UTC [51315][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:29.532 UTC [51315][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:29.534 UTC [51318][startup] LOG: database system was shut down at 2024-03-30 08:09:29 UTC 2024-03-30 08:09:29.538 UTC [51315][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:29.625 UTC [51323][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60082 2024-03-30 08:09:29.626 UTC [51323][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:29.626 UTC [51323][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:29.637 UTC [51325][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60098 2024-03-30 08:09:29.642 UTC [51325][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-30 08:09:29.642 UTC [51325][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-30 08:09:29.647 UTC [51325][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-30 08:09:29.648 UTC [51325][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=60098 2024-03-30 08:09:29.653 UTC [51315][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:29.653 UTC [51315][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:29.655 UTC [51315][postmaster] LOG: background worker "logical replication launcher" (PID 51321) exited with exit code 1 2024-03-30 08:09:29.655 UTC [51316][checkpointer] LOG: shutting down 2024-03-30 08:09:29.655 UTC [51316][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:29.656 UTC [51316][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/414CFB8, redo lsn=0/414CFB8 2024-03-30 08:09:29.659 UTC [51315][postmaster] LOG: database system is shut down 2024-03-30 08:09:29.773 UTC [51327][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:29.773 UTC [51327][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:29.773 UTC [51327][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:29.775 UTC [51330][startup] LOG: database system was shut down at 2024-03-30 08:09:29 UTC 2024-03-30 08:09:29.779 UTC [51327][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:29.862 UTC [51335][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60100 2024-03-30 08:09:29.864 UTC [51335][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:29.864 UTC [51335][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:29.876 UTC [51337][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60112 2024-03-30 08:09:29.881 UTC [51337][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-30 08:09:29.881 UTC [51337][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-30 08:09:29.886 UTC [51337][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-30 08:09:29.886 UTC [51337][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=60112 2024-03-30 08:09:29.891 UTC [51327][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:29.891 UTC [51327][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:29.893 UTC [51327][postmaster] LOG: background worker "logical replication launcher" (PID 51333) exited with exit code 1 2024-03-30 08:09:29.893 UTC [51328][checkpointer] LOG: shutting down 2024-03-30 08:09:29.893 UTC [51328][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:29.894 UTC [51328][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/414D030, redo lsn=0/414D030 2024-03-30 08:09:29.898 UTC [51327][postmaster] LOG: database system is shut down 2024-03-30 08:09:30.010 UTC [51339][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:30.010 UTC [51339][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:30.011 UTC [51339][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:30.013 UTC [51342][startup] LOG: database system was shut down at 2024-03-30 08:09:29 UTC 2024-03-30 08:09:30.016 UTC [51339][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:30.101 UTC [51347][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60118 2024-03-30 08:09:30.102 UTC [51347][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:30.103 UTC [51347][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:30.113 UTC [51349][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60132 2024-03-30 08:09:30.117 UTC [51349][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-30 08:09:30.117 UTC [51349][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-30 08:09:30.122 UTC [51349][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-30 08:09:30.123 UTC [51349][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=ssltestuser database=trustdb host=localhost port=60132 2024-03-30 08:09:30.127 UTC [51339][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:30.127 UTC [51339][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:30.129 UTC [51339][postmaster] LOG: background worker "logical replication launcher" (PID 51345) exited with exit code 1 2024-03-30 08:09:30.129 UTC [51340][checkpointer] LOG: shutting down 2024-03-30 08:09:30.129 UTC [51340][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:30.130 UTC [51340][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/414D0A8, redo lsn=0/414D0A8 2024-03-30 08:09:30.132 UTC [51339][postmaster] LOG: database system is shut down 2024-03-30 08:09:30.250 UTC [51351][postmaster] LOG: starting PostgreSQL 17devel on x86_64-linux, compiled by gcc-10.2.1, 64-bit 2024-03-30 08:09:30.250 UTC [51351][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 51236 2024-03-30 08:09:30.250 UTC [51351][postmaster] LOG: listening on Unix socket "/tmp/WN2fTY6kKf/.s.PGSQL.51236" 2024-03-30 08:09:30.253 UTC [51354][startup] LOG: database system was shut down at 2024-03-30 08:09:30 UTC 2024-03-30 08:09:30.257 UTC [51351][postmaster] LOG: database system is ready to accept connections 2024-03-30 08:09:30.340 UTC [51359][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60148 2024-03-30 08:09:30.341 UTC [51359][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-30 08:09:30.341 UTC [51359][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: Resource temporarily unavailable 2024-03-30 08:09:30.352 UTC [51361][not initialized] [[unknown]][:0] LOG: connection received: host=localhost port=60152 2024-03-30 08:09:30.357 UTC [51361][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-30 08:09:30.357 UTC [51361][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-30 08:09:30.362 UTC [51361][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-30 08:09:30.362 UTC [51361][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=ssltestuser database=trustdb host=localhost port=60152 2024-03-30 08:09:30.367 UTC [51351][postmaster] LOG: received fast shutdown request 2024-03-30 08:09:30.367 UTC [51351][postmaster] LOG: aborting any active transactions 2024-03-30 08:09:30.369 UTC [51351][postmaster] LOG: background worker "logical replication launcher" (PID 51357) exited with exit code 1 2024-03-30 08:09:30.369 UTC [51352][checkpointer] LOG: shutting down 2024-03-30 08:09:30.369 UTC [51352][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-30 08:09:30.370 UTC [51352][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/414D120, redo lsn=0/414D120 2024-03-30 08:09:30.373 UTC [51351][postmaster] LOG: database system is shut down 2024-03-30 08:09:30.481 UTC [51363][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-30 08:09:30.481 UTC [51363][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [08:09:30.569](0.205s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"