[14:18:15.249](0.451s) # setting up data directory # Checking port 50079 # Found port 50079 Name: primary Data directory: C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata Backup directory: C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/backup Archive directory: C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/archives Connection string: port=50079 host=C:/Windows/TEMP/ie5lmStKDL Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log [14:18:15.298](0.049s) # initializing database system by copying initdb template # Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata # Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata ### Starting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 7244 [14:18:17.456](2.158s) ok 1 - ssl_library parameter ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 1556 [14:18:22.525](5.069s) # testing password-protected keys ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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-14 14:18:17.125 GMT [7244][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:17.126 GMT [7244][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:17.166 GMT [4860][startup] LOG: database system was shut down at 2024-03-14 14:08:15 GMT 2024-03-14 14:18:17.193 GMT [7244][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:17.402 GMT [4528][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.404 GMT [4528][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.404 GMT [4528][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.416 GMT [4528][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-14 14:18:17.419 GMT [4528][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.560 GMT [2476][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.561 GMT [2476][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.561 GMT [2476][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.564 GMT [2476][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-14 14:18:17.564 GMT [2476][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.694 GMT [5128][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.696 GMT [5128][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.696 GMT [5128][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.704 GMT [5128][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-14 14:18:17.707 GMT [5128][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.857 GMT [7536][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.858 GMT [7536][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.858 GMT [7536][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.885 GMT [7536][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-14 14:18:17.886 GMT [7536][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.025 GMT [632][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.027 GMT [632][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.027 GMT [632][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.046 GMT [632][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-14 14:18:18.047 GMT [632][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.214 GMT [1224][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.216 GMT [1224][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.216 GMT [1224][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.223 GMT [1224][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-14 14:18:18.519 GMT [1224][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.308 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.755 GMT [4124][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.758 GMT [4124][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.758 GMT [4124][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.762 GMT [4124][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-14 14:18:19.056 GMT [4124][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.310 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:19.377 GMT [7352][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:19.379 GMT [7352][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:19.379 GMT [7352][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:19.383 GMT [7352][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-14 14:18:19.751 GMT [7352][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.379 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:19.951 GMT [4908][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:19.952 GMT [4908][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:19.952 GMT [4908][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:19.955 GMT [4908][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-14 14:18:20.287 GMT [4908][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.339 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:20.462 GMT [6716][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:20.463 GMT [6716][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:20.463 GMT [6716][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:20.466 GMT [6716][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-14 14:18:20.676 GMT [6716][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.217 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:20.879 GMT [6592][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:20.880 GMT [6592][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:20.880 GMT [6592][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:20.895 GMT [6592][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-14 14:18:21.127 GMT [6592][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.252 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:21.260 GMT [7244][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:21.261 GMT [7244][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:21.297 GMT [7244][postmaster] LOG: background worker "logical replication launcher" (PID 5716) exited with exit code 1 2024-03-14 14:18:21.297 GMT [6508][checkpointer] LOG: shutting down 2024-03-14 14:18:21.297 GMT [6508][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:21.791 GMT [6508][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.488 s, sync=0.001 s, total=0.494 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C7B58, redo lsn=0/40C7B58 2024-03-14 14:18:21.936 GMT [7244][postmaster] LOG: database system is shut down 2024-03-14 14:18:22.316 GMT [1556][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:22.316 GMT [1556][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:22.318 GMT [1556][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:22.357 GMT [1908][startup] LOG: database system was shut down at 2024-03-14 14:18:21 GMT 2024-03-14 14:18:22.408 GMT [1556][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:22.541 GMT [1556][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:22.541 GMT [1556][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:22.552 GMT [1556][postmaster] LOG: background worker "logical replication launcher" (PID 1052) exited with exit code 1 2024-03-14 14:18:22.552 GMT [5704][checkpointer] LOG: shutting down 2024-03-14 14:18:22.553 GMT [5704][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:22.556 GMT [5704][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7BD0, redo lsn=0/40C7BD0 2024-03-14 14:18:22.576 GMT [1556][postmaster] LOG: database system is shut down 2024-03-14 14:18:22.789 GMT [7020][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-14 14:18:22.789 GMT [7020][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [14:18:22.912](0.387s) ok 2 - restart fails with password-protected key file with wrong password ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart pg_ctl: PID file "C:/cirrus/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 5020 [14:18:23.278](0.367s) ok 3 - restart succeeds with password-protected key file ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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-14 14:18:17.125 GMT [7244][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:17.126 GMT [7244][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:17.166 GMT [4860][startup] LOG: database system was shut down at 2024-03-14 14:08:15 GMT 2024-03-14 14:18:17.193 GMT [7244][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:17.402 GMT [4528][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.404 GMT [4528][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.404 GMT [4528][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.416 GMT [4528][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-14 14:18:17.419 GMT [4528][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.560 GMT [2476][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.561 GMT [2476][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.561 GMT [2476][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.564 GMT [2476][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-14 14:18:17.564 GMT [2476][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.694 GMT [5128][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.696 GMT [5128][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.696 GMT [5128][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.704 GMT [5128][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-14 14:18:17.707 GMT [5128][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.857 GMT [7536][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.858 GMT [7536][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.858 GMT [7536][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.885 GMT [7536][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-14 14:18:17.886 GMT [7536][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.025 GMT [632][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.027 GMT [632][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.027 GMT [632][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.046 GMT [632][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-14 14:18:18.047 GMT [632][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.214 GMT [1224][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.216 GMT [1224][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.216 GMT [1224][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.223 GMT [1224][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-14 14:18:18.519 GMT [1224][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.308 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.755 GMT [4124][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.758 GMT [4124][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.758 GMT [4124][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.762 GMT [4124][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-14 14:18:19.056 GMT [4124][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.310 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:19.377 GMT [7352][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:19.379 GMT [7352][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:19.379 GMT [7352][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:19.383 GMT [7352][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-14 14:18:19.751 GMT [7352][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.379 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:19.951 GMT [4908][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:19.952 GMT [4908][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:19.952 GMT [4908][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:19.955 GMT [4908][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-14 14:18:20.287 GMT [4908][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.339 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:20.462 GMT [6716][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:20.463 GMT [6716][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:20.463 GMT [6716][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:20.466 GMT [6716][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-14 14:18:20.676 GMT [6716][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.217 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:20.879 GMT [6592][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:20.880 GMT [6592][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:20.880 GMT [6592][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:20.895 GMT [6592][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-14 14:18:21.127 GMT [6592][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.252 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:21.260 GMT [7244][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:21.261 GMT [7244][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:21.297 GMT [7244][postmaster] LOG: background worker "logical replication launcher" (PID 5716) exited with exit code 1 2024-03-14 14:18:21.297 GMT [6508][checkpointer] LOG: shutting down 2024-03-14 14:18:21.297 GMT [6508][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:21.791 GMT [6508][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.488 s, sync=0.001 s, total=0.494 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C7B58, redo lsn=0/40C7B58 2024-03-14 14:18:21.936 GMT [7244][postmaster] LOG: database system is shut down 2024-03-14 14:18:22.316 GMT [1556][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:22.316 GMT [1556][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:22.318 GMT [1556][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:22.357 GMT [1908][startup] LOG: database system was shut down at 2024-03-14 14:18:21 GMT 2024-03-14 14:18:22.408 GMT [1556][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:22.541 GMT [1556][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:22.541 GMT [1556][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:22.552 GMT [1556][postmaster] LOG: background worker "logical replication launcher" (PID 1052) exited with exit code 1 2024-03-14 14:18:22.552 GMT [5704][checkpointer] LOG: shutting down 2024-03-14 14:18:22.553 GMT [5704][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:22.556 GMT [5704][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7BD0, redo lsn=0/40C7BD0 2024-03-14 14:18:22.576 GMT [1556][postmaster] LOG: database system is shut down 2024-03-14 14:18:22.789 GMT [7020][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-14 14:18:22.789 GMT [7020][postmaster] LOG: database system is shut down 2024-03-14 14:18:23.162 GMT [5020][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:23.163 GMT [5020][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:23.164 GMT [5020][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:23.212 GMT [1136][startup] LOG: database system was shut down at 2024-03-14 14:18:22 GMT 2024-03-14 14:18:23.240 GMT [5020][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:23.298 GMT [5020][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:23.298 GMT [5020][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:23.317 GMT [5020][postmaster] LOG: background worker "logical replication launcher" (PID 4316) exited with exit code 1 2024-03-14 14:18:23.318 GMT [6584][checkpointer] LOG: shutting down 2024-03-14 14:18:23.318 GMT [6584][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:23.322 GMT [6584][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7C48, redo lsn=0/40C7C48 2024-03-14 14:18:23.331 GMT [5020][postmaster] LOG: database system is shut down 2024-03-14 14:18:23.746 GMT [4200][postmaster] FATAL: could not set SSL protocol version range 2024-03-14 14:18:23.746 GMT [4200][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-14 14:18:23.746 GMT [4200][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [14:18:23.856](0.578s) ok 4 - restart fails with incorrect SSL protocol bounds ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart pg_ctl: PID file "C:/cirrus/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 836 [14:18:24.263](0.407s) ok 5 - restart succeeds with correct SSL protocol bounds [14:18:24.264](0.001s) # running client tests ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 4012 [14:18:25.106](0.843s) ok 6 - server doesn't accept non-SSL connections [14:18:25.107](0.001s) ok 7 - server doesn't accept non-SSL connections: matches [14:18:25.274](0.167s) ok 8 - connect without server root cert sslmode=require [14:18:25.274](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr [14:18:25.419](0.144s) ok 10 - connect without server root cert sslmode=verify-ca [14:18:25.419](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches [14:18:25.522](0.103s) ok 12 - connect without server root cert sslmode=verify-full [14:18:25.523](0.001s) ok 13 - connect without server root cert sslmode=verify-full: matches [14:18:25.654](0.131s) ok 14 - connect with wrong server root cert sslmode=require [14:18:25.654](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches [14:18:25.845](0.191s) ok 16 - connect with wrong server root cert sslmode=verify-ca [14:18:25.847](0.002s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [14:18:26.104](0.257s) ok 18 - connect with wrong server root cert sslmode=verify-full [14:18:26.105](0.001s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [14:18:26.326](0.221s) ok 20 - connect with server CA cert, without root CA [14:18:26.326](0.000s) ok 21 - connect with server CA cert, without root CA: matches [14:18:26.445](0.119s) ok 22 - connect with correct server CA cert file sslmode=require [14:18:26.446](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [14:18:26.590](0.144s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [14:18:26.590](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [14:18:26.664](0.074s) ok 26 - connect with correct server CA cert file sslmode=verify-full [14:18:26.664](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [14:18:26.744](0.080s) ok 28 - cert root file that contains two certificates, order 1 [14:18:26.744](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr [14:18:26.875](0.131s) ok 30 - cert root file that contains two certificates, order 2 [14:18:26.875](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr [14:18:27.013](0.137s) ok 32 - connect with sslcertmode=disable [14:18:27.013](0.000s) ok 33 - connect with sslcertmode=disable: no stderr [14:18:27.108](0.095s) ok 34 - connect with sslcertmode=allow [14:18:27.109](0.001s) ok 35 - connect with sslcertmode=allow: no stderr [14:18:27.201](0.093s) ok 36 - connect with sslcertmode=require fails without a client certificate [14:18:27.202](0.001s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [14:18:27.267](0.065s) ok 38 - sslcrl option with invalid file name [14:18:27.267](0.000s) ok 39 - sslcrl option with invalid file name: no stderr [14:18:27.373](0.106s) ok 40 - CRL belonging to a different CA [14:18:27.373](0.000s) ok 41 - CRL belonging to a different CA: matches [14:18:27.439](0.066s) ok 42 - directory CRL belonging to a different CA [14:18:27.439](0.000s) ok 43 - directory CRL belonging to a different CA: matches [14:18:27.501](0.062s) ok 44 - CRL with a non-revoked cert [14:18:27.501](0.000s) ok 45 - CRL with a non-revoked cert: no stderr [14:18:27.564](0.063s) ok 46 - directory CRL with a non-revoked cert [14:18:27.564](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr [14:18:27.673](0.109s) ok 48 - mismatch between host name and server certificate sslmode=require [14:18:27.674](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [14:18:27.736](0.062s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [14:18:27.736](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [14:18:27.845](0.109s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [14:18:27.845](0.000s) ok 53 - mismatch between host name and server certificate sslmode=verify-full: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 5048 [14:18:28.189](0.344s) ok 54 - IP address in the Common Name [14:18:28.189](0.000s) ok 55 - IP address in the Common Name: no stderr [14:18:28.255](0.066s) ok 56 - mismatch between host name and server certificate IP address [14:18:28.256](0.000s) ok 57 - mismatch between host name and server certificate IP address: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 820 [14:18:28.596](0.340s) ok 58 - IP address in a dNSName [14:18:28.596](0.000s) ok 59 - IP address in a dNSName: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 2388 [14:18:28.939](0.343s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [14:18:28.939](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [14:18:29.049](0.110s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [14:18:29.049](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [14:18:29.111](0.061s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [14:18:29.111](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [14:18:29.174](0.063s) ok 66 - host name not matching with X.509 Subject Alternative Names [14:18:29.174](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [14:18:29.237](0.063s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [14:18:29.237](0.000s) ok 69 - host name not matching with X.509 Subject Alternative Names wildcard: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 8036 [14:18:29.596](0.359s) ok 70 - host name matching with a single X.509 Subject Alternative Name [14:18:29.597](0.001s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [14:18:29.689](0.092s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [14:18:29.689](0.001s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [14:18:29.756](0.066s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [14:18:29.758](0.002s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches [14:18:29.782](0.025s) ok 76 # skip IPv6 addresses in certificates not support on this platform ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 7312 [14:18:30.143](0.361s) ok 77 - certificate with both a CN and SANs 1 [14:18:30.143](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr [14:18:30.252](0.108s) ok 79 - certificate with both a CN and SANs 2 [14:18:30.252](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr [14:18:30.361](0.109s) ok 81 - certificate with both a CN and SANs ignores CN [14:18:30.362](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches [14:18:30.391](0.030s) ok 83 # skip IPv6 addresses in certificates not support on this platform ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 5480 [14:18:30.737](0.346s) ok 84 - certificate with both an IP CN and DNS SANs matches CN [14:18:30.737](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr [14:18:30.827](0.090s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1 [14:18:30.828](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [14:18:30.907](0.079s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2 [14:18:30.908](0.001s) ok 89 - certificate with both an IP CN and DNS SANs matches SAN 2: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 7064 [14:18:31.254](0.346s) ok 90 - server certificate without CN or SANs sslmode=verify-ca [14:18:31.254](0.001s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr [14:18:31.315](0.061s) ok 92 - server certificate without CN or SANs sslmode=verify-full [14:18:31.315](0.000s) ok 93 - server certificate without CN or SANs sslmode=verify-full: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 2476 [14:18:31.612](0.297s) ok 94 - sslrootcert=system does not connect with private CA [14:18:31.613](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches [14:18:31.675](0.062s) ok 96 - sslrootcert=system only accepts sslmode=verify-full [14:18:31.675](0.001s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches [14:18:31.787](0.111s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE [14:18:31.787](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [14:18:31.849](0.062s) ok 100 - sslrootcert=system defaults to sslmode=verify-full [14:18:31.850](0.000s) ok 101 - sslrootcert=system defaults to sslmode=verify-full: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 2548 [14:18:32.194](0.344s) ok 102 - connects without client-side CRL [14:18:32.194](0.001s) ok 103 - connects without client-side CRL: no stderr [14:18:32.256](0.061s) ok 104 - does not connect with client-side CRL file [14:18:32.256](0.000s) ok 105 - does not connect with client-side CRL file: matches [14:18:32.318](0.062s) ok 106 - does not connect with client-side CRL directory [14:18:32.318](0.000s) ok 107 - does not connect with client-side CRL directory: matches # Running: psql -X -A -F , -P null=_null_ -d sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=invalid -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [14:18:32.379](0.061s) ok 108 - pg_stat_ssl view without client certificate: exit code 0 [14:18:32.379](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr [14:18:32.380](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches [14:18:32.443](0.064s) ok 111 - connection success with correct range of TLS protocol versions [14:18:32.444](0.001s) ok 112 - connection success with correct range of TLS protocol versions: no stderr [14:18:32.475](0.031s) ok 113 - connection failure with incorrect range of TLS protocol versions [14:18:32.476](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches [14:18:32.506](0.030s) ok 115 - connection failure with an incorrect SSL protocol minimum bound [14:18:32.506](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches [14:18:32.537](0.031s) ok 117 - connection failure with an incorrect SSL protocol maximum bound [14:18:32.537](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches [14:18:32.537](0.000s) # running server tests [14:18:32.600](0.062s) ok 119 - certificate authorization fails without client cert [14:18:32.600](0.001s) ok 120 - certificate authorization fails without client cert: matches [14:18:32.710](0.110s) ok 121 - certificate authorization succeeds with correct client cert in PEM format [14:18:32.710](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr [14:18:32.773](0.063s) ok 123 - certificate authorization succeeds with correct client cert in DER format [14:18:32.774](0.001s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr [14:18:32.882](0.109s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format [14:18:32.883](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [14:18:32.945](0.062s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format [14:18:32.945](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [14:18:33.007](0.062s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require [14:18:33.008](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [14:18:33.070](0.062s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow [14:18:33.070](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [14:18:33.179](0.109s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable [14:18:33.180](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [14:18:33.243](0.063s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [14:18:33.243](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [14:18:33.351](0.108s) ok 137 - certificate authorization succeeds with DN mapping [14:18:33.352](0.000s) ok 138 - certificate authorization succeeds with DN mapping: no stderr [14:18:33.352](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches [14:18:33.461](0.108s) ok 140 - certificate authorization succeeds with DN regex mapping [14:18:33.461](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr [14:18:33.570](0.109s) ok 142 - certificate authorization succeeds with CN mapping [14:18:33.570](0.001s) ok 143 - certificate authorization succeeds with CN mapping: no stderr [14:18:33.571](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches [14:18:33.572](0.001s) not ok 145 # TODO & SKIP Need Pty support [14:18:33.572](0.000s) not ok 146 # TODO & SKIP Need Pty support [14:18:33.572](0.000s) not ok 147 # TODO & SKIP Need Pty support [14:18:33.572](0.000s) not ok 148 # TODO & SKIP Need Pty support 'C:\Program' is not recognized as an internal or external command, operable program or batch file. couldn't run "C:\Program Files\Git\usr\bin\openssl.EXE x509" to get client cert serialno at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 726. # 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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [14:18:33.647](0.074s) ok 149 - pg_stat_ssl with client certificate: exit code 0 [14:18:33.647](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr [14:18:33.647](0.000s) ok 151 - pg_stat_ssl with client certificate: matches [14:18:33.648](0.000s) ok 152 # skip Permissions check not enforced on Windows [14:18:33.648](0.000s) ok 153 # skip Permissions check not enforced on Windows [14:18:33.711](0.063s) ok 154 - certificate authorization fails with client cert belonging to another user [14:18:33.712](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches [14:18:33.773](0.061s) ok 156 - certificate authorization fails with revoked client cert [14:18:33.773](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches [14:18:33.774](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match [14:18:33.883](0.109s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name [14:18:33.883](0.000s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [14:18:33.883](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [14:18:33.945](0.061s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name [14:18:33.945](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [14:18:33.946](0.000s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [14:18:34.007](0.062s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [14:18:34.008](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [14:18:34.008](0.000s) ok 167 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: log matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 2724 [14:18:34.351](0.343s) ok 168 - intermediate client certificate is provided by client [14:18:34.352](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr [14:18:34.414](0.062s) ok 170 - intermediate client certificate is missing [14:18:34.414](0.000s) ok 171 - intermediate client certificate is missing: matches [14:18:34.523](0.109s) ok 172 - logged client certificate Subjects are truncated if they're too long [14:18:34.524](0.001s) ok 173 - logged client certificate Subjects are truncated if they're too long: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 660 [14:18:34.866](0.343s) ok 174 - intermediate client certificate is untrusted [14:18:34.867](0.000s) ok 175 - intermediate client certificate is untrusted: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 3676 [14:18:35.164](0.297s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory [14:18:35.164](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [14:18:35.226](0.062s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [14:18:35.227](0.000s) ok 179 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 4816 [14:18:35.523](0.297s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1 [14:18:35.524](0.001s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923. [14:18:35.525](0.000s) # got: '2' # expected: '0' [14:18:35.525](0.001s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [14:18:35.526](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923. [14:18:35.526](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 50079 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 (0x00002746/10054)' # expected: '' [14:18:35.633](0.107s) ok 182 - connect without requesting ocsp response when sslocspstapling=0 [14:18:35.634](0.001s) ok 183 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 5772 [14:18:35.945](0.311s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1 [14:18:36.054](0.108s) ok 185 - connect without requesting ocsp response when sslocspstapling=0 [14:18:36.054](0.000s) ok 186 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 5396 [14:18:36.350](0.296s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1 [14:18:36.461](0.111s) ok 188 - connect without requesting ocsp response when sslocspstapling=0 [14:18:36.461](0.000s) ok 189 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 5760 [14:18:36.761](0.299s) ok 190 - failed with an expired ocsp response when sslocspstapling=1 [14:18:36.839](0.078s) ok 191 - connect without requesting ocsp response when sslocspstapling=0 [14:18:36.839](0.000s) ok 192 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 1260 [14:18:37.136](0.297s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1 [14:18:37.136](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001. [14:18:37.136](0.000s) # got: '2' # expected: '0' [14:18:37.136](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [14:18:37.137](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001. [14:18:37.137](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 50079 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 (0x00002746/10054)' # expected: '' [14:18:37.280](0.143s) ok 195 - connect without requesting ocsp response when sslocspstapling=0 [14:18:37.280](0.000s) ok 196 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 6764 [14:18:37.575](0.294s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1 [14:18:37.683](0.108s) ok 198 - connect without requesting ocsp response when sslocspstapling=0 [14:18:37.683](0.000s) ok 199 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 980 [14:18:37.980](0.296s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1 [14:18:38.089](0.109s) ok 201 - connect without requesting ocsp response when sslocspstapling=0 [14:18:38.089](0.000s) ok 202 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 7848 [14:18:38.386](0.297s) ok 203 - failed with an expired ocsp response when sslocspstapling=1 [14:18:38.495](0.109s) ok 204 - connect without requesting ocsp response when sslocspstapling=0 [14:18:38.495](0.001s) ok 205 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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 1016 [14:18:38.792](0.297s) ok 206 - failed with an expired ocsp response when sslocspstapling=1 [14:18:38.901](0.110s) ok 207 - connect without requesting ocsp response when sslocspstapling=0 [14:18:38.902](0.000s) ok 208 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\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-14 14:18:17.125 GMT [7244][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:17.126 GMT [7244][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:17.166 GMT [4860][startup] LOG: database system was shut down at 2024-03-14 14:08:15 GMT 2024-03-14 14:18:17.193 GMT [7244][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:17.402 GMT [4528][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.404 GMT [4528][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.404 GMT [4528][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.416 GMT [4528][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-14 14:18:17.419 GMT [4528][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.560 GMT [2476][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.561 GMT [2476][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.561 GMT [2476][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.564 GMT [2476][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-14 14:18:17.564 GMT [2476][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.694 GMT [5128][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.696 GMT [5128][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.696 GMT [5128][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.704 GMT [5128][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-14 14:18:17.707 GMT [5128][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.016 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:17.857 GMT [7536][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:17.858 GMT [7536][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:17.858 GMT [7536][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:17.885 GMT [7536][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-14 14:18:17.886 GMT [7536][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.025 GMT [632][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.027 GMT [632][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.027 GMT [632][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.046 GMT [632][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-14 14:18:18.047 GMT [632][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.214 GMT [1224][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.216 GMT [1224][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.216 GMT [1224][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.223 GMT [1224][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-14 14:18:18.519 GMT [1224][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.308 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:18.755 GMT [4124][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:18.758 GMT [4124][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:18.758 GMT [4124][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:18.762 GMT [4124][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-14 14:18:19.056 GMT [4124][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.310 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:19.377 GMT [7352][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:19.379 GMT [7352][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:19.379 GMT [7352][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:19.383 GMT [7352][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-14 14:18:19.751 GMT [7352][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.379 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:19.951 GMT [4908][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:19.952 GMT [4908][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:19.952 GMT [4908][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:19.955 GMT [4908][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-14 14:18:20.287 GMT [4908][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.339 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:20.462 GMT [6716][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:20.463 GMT [6716][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:20.463 GMT [6716][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:20.466 GMT [6716][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-14 14:18:20.676 GMT [6716][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.217 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:20.879 GMT [6592][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-14 14:18:20.880 GMT [6592][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117) 2024-03-14 14:18:20.880 GMT [6592][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-14 14:18:20.895 GMT [6592][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-14 14:18:21.127 GMT [6592][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.252 user=SYSTEM database=postgres host=[local] 2024-03-14 14:18:21.260 GMT [7244][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:21.261 GMT [7244][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:21.297 GMT [7244][postmaster] LOG: background worker "logical replication launcher" (PID 5716) exited with exit code 1 2024-03-14 14:18:21.297 GMT [6508][checkpointer] LOG: shutting down 2024-03-14 14:18:21.297 GMT [6508][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:21.791 GMT [6508][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.488 s, sync=0.001 s, total=0.494 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C7B58, redo lsn=0/40C7B58 2024-03-14 14:18:21.936 GMT [7244][postmaster] LOG: database system is shut down 2024-03-14 14:18:22.316 GMT [1556][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:22.316 GMT [1556][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:22.318 GMT [1556][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:22.357 GMT [1908][startup] LOG: database system was shut down at 2024-03-14 14:18:21 GMT 2024-03-14 14:18:22.408 GMT [1556][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:22.541 GMT [1556][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:22.541 GMT [1556][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:22.552 GMT [1556][postmaster] LOG: background worker "logical replication launcher" (PID 1052) exited with exit code 1 2024-03-14 14:18:22.552 GMT [5704][checkpointer] LOG: shutting down 2024-03-14 14:18:22.553 GMT [5704][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:22.556 GMT [5704][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7BD0, redo lsn=0/40C7BD0 2024-03-14 14:18:22.576 GMT [1556][postmaster] LOG: database system is shut down 2024-03-14 14:18:22.789 GMT [7020][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-14 14:18:22.789 GMT [7020][postmaster] LOG: database system is shut down 2024-03-14 14:18:23.162 GMT [5020][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:23.163 GMT [5020][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:23.164 GMT [5020][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:23.212 GMT [1136][startup] LOG: database system was shut down at 2024-03-14 14:18:22 GMT 2024-03-14 14:18:23.240 GMT [5020][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:23.298 GMT [5020][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:23.298 GMT [5020][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:23.317 GMT [5020][postmaster] LOG: background worker "logical replication launcher" (PID 4316) exited with exit code 1 2024-03-14 14:18:23.318 GMT [6584][checkpointer] LOG: shutting down 2024-03-14 14:18:23.318 GMT [6584][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:23.322 GMT [6584][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7C48, redo lsn=0/40C7C48 2024-03-14 14:18:23.331 GMT [5020][postmaster] LOG: database system is shut down 2024-03-14 14:18:23.746 GMT [4200][postmaster] FATAL: could not set SSL protocol version range 2024-03-14 14:18:23.746 GMT [4200][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-14 14:18:23.746 GMT [4200][postmaster] LOG: database system is shut down 2024-03-14 14:18:24.052 GMT [836][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:24.053 GMT [836][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:24.057 GMT [836][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:24.096 GMT [5096][startup] LOG: database system was shut down at 2024-03-14 14:18:23 GMT 2024-03-14 14:18:24.131 GMT [836][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:24.288 GMT [836][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:24.288 GMT [836][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:24.295 GMT [836][postmaster] LOG: background worker "logical replication launcher" (PID 4248) exited with exit code 1 2024-03-14 14:18:24.298 GMT [2560][checkpointer] LOG: shutting down 2024-03-14 14:18:24.299 GMT [2560][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:24.305 GMT [2560][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.008 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7CC0, redo lsn=0/40C7CC0 2024-03-14 14:18:24.341 GMT [836][postmaster] LOG: database system is shut down 2024-03-14 14:18:24.719 GMT [4012][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:24.720 GMT [4012][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:24.721 GMT [4012][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:24.768 GMT [7832][startup] LOG: database system was shut down at 2024-03-14 14:18:24 GMT 2024-03-14 14:18:24.824 GMT [4012][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:25.047 GMT [5220][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50366 2024-03-14 14:18:25.048 GMT [5220][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-14 14:18:25.048 GMT [5220][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "pg-loadbalancetest", forward lookup not checked. 2024-03-14 14:18:25.198 GMT [4412][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50368 2024-03-14 14:18:25.206 GMT [4412][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:25.206 GMT [4412][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-14 14:18:25.221 GMT [4412][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-14 14:18:25.225 GMT [4412][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.052 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50368 2024-03-14 14:18:25.350 GMT [4616][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50370 2024-03-14 14:18:25.365 GMT [4616][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-14 14:18:25.481 GMT [5192][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50373 2024-03-14 14:18:25.494 GMT [5192][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-14 14:18:25.581 GMT [7920][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50375 2024-03-14 14:18:25.587 GMT [7920][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-14 14:18:25.755 GMT [7844][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50378 2024-03-14 14:18:25.760 GMT [7844][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-14 14:18:25.969 GMT [6652][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50379 2024-03-14 14:18:25.975 GMT [6652][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-14 14:18:26.198 GMT [2504][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50380 2024-03-14 14:18:26.204 GMT [2504][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-14 14:18:26.420 GMT [7092][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50381 2024-03-14 14:18:26.427 GMT [7092][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:26.427 GMT [7092][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-14 14:18:26.430 GMT [7092][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-14 14:18:26.435 GMT [7092][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50381 2024-03-14 14:18:26.521 GMT [3876][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50382 2024-03-14 14:18:26.529 GMT [3876][client backend] [[unknown]][3/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:26.529 GMT [3876][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-14 14:18:26.536 GMT [3876][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-14 14:18:26.539 GMT [3876][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50382 2024-03-14 14:18:26.650 GMT [964][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50383 2024-03-14 14:18:26.658 GMT [964][client backend] [[unknown]][4/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:26.659 GMT [964][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-14 14:18:26.661 GMT [964][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-14 14:18:26.665 GMT [964][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50383 2024-03-14 14:18:26.724 GMT [7556][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50384 2024-03-14 14:18:26.732 GMT [7556][client backend] [[unknown]][5/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:26.732 GMT [7556][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-14 14:18:26.735 GMT [7556][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-14 14:18:26.740 GMT [7556][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50384 2024-03-14 14:18:26.844 GMT [6772][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50385 2024-03-14 14:18:26.852 GMT [6772][client backend] [[unknown]][6/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:26.852 GMT [6772][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-14 14:18:26.855 GMT [6772][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-14 14:18:26.861 GMT [6772][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50385 2024-03-14 14:18:26.973 GMT [4212][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50386 2024-03-14 14:18:26.981 GMT [4212][client backend] [[unknown]][7/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:26.981 GMT [4212][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-14 14:18:26.984 GMT [4212][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-14 14:18:26.988 GMT [4212][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50386 2024-03-14 14:18:27.065 GMT [8128][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50387 2024-03-14 14:18:27.073 GMT [8128][client backend] [[unknown]][8/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:27.073 GMT [8128][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-14 14:18:27.076 GMT [8128][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-14 14:18:27.080 GMT [8128][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50387 2024-03-14 14:18:27.159 GMT [5616][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50388 2024-03-14 14:18:27.167 GMT [5616][client backend] [[unknown]][9/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:27.167 GMT [5616][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-14 14:18:27.181 GMT [5616][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50388 2024-03-14 14:18:27.253 GMT [3264][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50389 2024-03-14 14:18:27.261 GMT [3264][client backend] [[unknown]][10/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:27.261 GMT [3264][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-14 14:18:27.263 GMT [3264][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-14 14:18:27.265 GMT [3264][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50389 2024-03-14 14:18:27.312 GMT [7100][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50390 2024-03-14 14:18:27.318 GMT [7100][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-14 14:18:27.418 GMT [7752][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50391 2024-03-14 14:18:27.423 GMT [7752][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-14 14:18:27.484 GMT [6388][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50392 2024-03-14 14:18:27.492 GMT [6388][client backend] [[unknown]][11/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:27.492 GMT [6388][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-14 14:18:27.495 GMT [6388][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-14 14:18:27.497 GMT [6388][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50392 2024-03-14 14:18:27.547 GMT [1748][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50393 2024-03-14 14:18:27.555 GMT [1748][client backend] [[unknown]][12/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:27.555 GMT [1748][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-14 14:18:27.558 GMT [1748][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-14 14:18:27.560 GMT [1748][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50393 2024-03-14 14:18:27.607 GMT [7212][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50394 2024-03-14 14:18:27.627 GMT [7212][client backend] [[unknown]][13/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:27.627 GMT [7212][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-14 14:18:27.631 GMT [7212][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-14 14:18:27.635 GMT [7212][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50394 2024-03-14 14:18:27.716 GMT [4896][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50395 2024-03-14 14:18:27.724 GMT [4896][client backend] [[unknown]][14/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:27.724 GMT [4896][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-14 14:18:27.727 GMT [4896][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-14 14:18:27.729 GMT [4896][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50395 2024-03-14 14:18:27.782 GMT [5020][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50396 2024-03-14 14:18:27.863 GMT [4012][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:27.863 GMT [4012][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:27.870 GMT [4012][postmaster] LOG: background worker "logical replication launcher" (PID 5164) exited with exit code 1 2024-03-14 14:18:27.870 GMT [5240][checkpointer] LOG: shutting down 2024-03-14 14:18:27.870 GMT [5240][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:27.874 GMT [5240][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7D38, redo lsn=0/40C7D38 2024-03-14 14:18:27.879 GMT [4012][postmaster] LOG: database system is shut down 2024-03-14 14:18:28.024 GMT [5048][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:28.025 GMT [5048][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:28.026 GMT [5048][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:28.050 GMT [5580][startup] LOG: database system was shut down at 2024-03-14 14:18:27 GMT 2024-03-14 14:18:28.059 GMT [5048][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:28.125 GMT [5568][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50397 2024-03-14 14:18:28.132 GMT [5568][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:28.132 GMT [5568][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-14 14:18:28.144 GMT [5568][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-14 14:18:28.148 GMT [5568][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50397 2024-03-14 14:18:28.231 GMT [4060][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50398 2024-03-14 14:18:28.271 GMT [5048][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:28.272 GMT [5048][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:28.277 GMT [5048][postmaster] LOG: background worker "logical replication launcher" (PID 6828) exited with exit code 1 2024-03-14 14:18:28.277 GMT [6796][checkpointer] LOG: shutting down 2024-03-14 14:18:28.277 GMT [6796][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:28.280 GMT [6796][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7DB0, redo lsn=0/40C7DB0 2024-03-14 14:18:28.285 GMT [5048][postmaster] LOG: database system is shut down 2024-03-14 14:18:28.431 GMT [820][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:28.431 GMT [820][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:28.433 GMT [820][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:28.458 GMT [4920][startup] LOG: database system was shut down at 2024-03-14 14:18:28 GMT 2024-03-14 14:18:28.466 GMT [820][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:28.527 GMT [3668][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50399 2024-03-14 14:18:28.534 GMT [3668][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:28.534 GMT [3668][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-14 14:18:28.547 GMT [3668][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-14 14:18:28.550 GMT [3668][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50399 2024-03-14 14:18:28.612 GMT [820][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:28.612 GMT [820][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:28.618 GMT [820][postmaster] LOG: background worker "logical replication launcher" (PID 5588) exited with exit code 1 2024-03-14 14:18:28.618 GMT [4200][checkpointer] LOG: shutting down 2024-03-14 14:18:28.618 GMT [4200][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:28.621 GMT [4200][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7E28, redo lsn=0/40C7E28 2024-03-14 14:18:28.626 GMT [820][postmaster] LOG: database system is shut down 2024-03-14 14:18:28.777 GMT [2388][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:28.777 GMT [2388][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:28.779 GMT [2388][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:28.799 GMT [7048][startup] LOG: database system was shut down at 2024-03-14 14:18:28 GMT 2024-03-14 14:18:28.808 GMT [2388][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:28.874 GMT [5208][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50400 2024-03-14 14:18:28.881 GMT [5208][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:28.881 GMT [5208][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-14 14:18:28.894 GMT [5208][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-14 14:18:28.896 GMT [5208][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50400 2024-03-14 14:18:28.984 GMT [6148][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50401 2024-03-14 14:18:28.995 GMT [6148][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:28.995 GMT [6148][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-14 14:18:29.000 GMT [6148][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-14 14:18:29.004 GMT [6148][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50401 2024-03-14 14:18:29.090 GMT [6900][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50402 2024-03-14 14:18:29.097 GMT [6900][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:29.097 GMT [6900][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-14 14:18:29.100 GMT [6900][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-14 14:18:29.102 GMT [6900][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50402 2024-03-14 14:18:29.152 GMT [2108][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50403 2024-03-14 14:18:29.216 GMT [3752][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50404 2024-03-14 14:18:29.255 GMT [2388][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:29.255 GMT [2388][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:29.259 GMT [2388][postmaster] LOG: background worker "logical replication launcher" (PID 720) exited with exit code 1 2024-03-14 14:18:29.260 GMT [7320][checkpointer] LOG: shutting down 2024-03-14 14:18:29.260 GMT [7320][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:29.263 GMT [7320][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7EA0, redo lsn=0/40C7EA0 2024-03-14 14:18:29.269 GMT [2388][postmaster] LOG: database system is shut down 2024-03-14 14:18:29.415 GMT [8036][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:29.416 GMT [8036][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:29.417 GMT [8036][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:29.444 GMT [3832][startup] LOG: database system was shut down at 2024-03-14 14:18:29 GMT 2024-03-14 14:18:29.452 GMT [8036][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:29.515 GMT [6820][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50405 2024-03-14 14:18:29.523 GMT [6820][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:29.523 GMT [6820][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-14 14:18:29.535 GMT [6820][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-14 14:18:29.538 GMT [6820][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50405 2024-03-14 14:18:29.657 GMT [6756][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50406 2024-03-14 14:18:29.733 GMT [6940][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50407 2024-03-14 14:18:29.803 GMT [8036][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:29.803 GMT [8036][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:29.807 GMT [8036][postmaster] LOG: background worker "logical replication launcher" (PID 7244) exited with exit code 1 2024-03-14 14:18:29.809 GMT [4784][checkpointer] LOG: shutting down 2024-03-14 14:18:29.809 GMT [4784][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:29.812 GMT [4784][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7F18, redo lsn=0/40C7F18 2024-03-14 14:18:29.818 GMT [8036][postmaster] LOG: database system is shut down 2024-03-14 14:18:29.969 GMT [7312][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:29.969 GMT [7312][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:29.970 GMT [7312][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:29.993 GMT [4000][startup] LOG: database system was shut down at 2024-03-14 14:18:29 GMT 2024-03-14 14:18:30.002 GMT [7312][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:30.076 GMT [7436][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50408 2024-03-14 14:18:30.083 GMT [7436][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:30.083 GMT [7436][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-14 14:18:30.096 GMT [7436][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-14 14:18:30.099 GMT [7436][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50408 2024-03-14 14:18:30.192 GMT [2360][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50409 2024-03-14 14:18:30.199 GMT [2360][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:30.199 GMT [2360][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-14 14:18:30.203 GMT [2360][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-14 14:18:30.205 GMT [2360][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50409 2024-03-14 14:18:30.298 GMT [6916][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50410 2024-03-14 14:18:30.411 GMT [7312][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:30.411 GMT [7312][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:30.421 GMT [7312][postmaster] LOG: background worker "logical replication launcher" (PID 4804) exited with exit code 1 2024-03-14 14:18:30.421 GMT [6408][checkpointer] LOG: shutting down 2024-03-14 14:18:30.421 GMT [6408][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:30.424 GMT [6408][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7F90, redo lsn=0/40C7F90 2024-03-14 14:18:30.430 GMT [7312][postmaster] LOG: database system is shut down 2024-03-14 14:18:30.574 GMT [5480][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:30.575 GMT [5480][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:30.576 GMT [5480][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:30.598 GMT [7184][startup] LOG: database system was shut down at 2024-03-14 14:18:30 GMT 2024-03-14 14:18:30.607 GMT [5480][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:30.678 GMT [4308][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50411 2024-03-14 14:18:30.687 GMT [4308][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:30.687 GMT [4308][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-14 14:18:30.699 GMT [4308][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-14 14:18:30.703 GMT [4308][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50411 2024-03-14 14:18:30.791 GMT [7448][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50412 2024-03-14 14:18:30.799 GMT [7448][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:30.799 GMT [7448][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-14 14:18:30.803 GMT [7448][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-14 14:18:30.805 GMT [7448][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50412 2024-03-14 14:18:30.881 GMT [2700][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50413 2024-03-14 14:18:30.889 GMT [2700][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:30.889 GMT [2700][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-14 14:18:30.894 GMT [2700][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-14 14:18:30.896 GMT [2700][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50413 2024-03-14 14:18:30.932 GMT [5480][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:30.932 GMT [5480][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:30.942 GMT [5480][postmaster] LOG: background worker "logical replication launcher" (PID 4668) exited with exit code 1 2024-03-14 14:18:30.942 GMT [3744][checkpointer] LOG: shutting down 2024-03-14 14:18:30.942 GMT [3744][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:30.945 GMT [3744][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8020, redo lsn=0/40C8020 2024-03-14 14:18:30.951 GMT [5480][postmaster] LOG: database system is shut down 2024-03-14 14:18:31.095 GMT [7064][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:31.096 GMT [7064][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:31.097 GMT [7064][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:31.119 GMT [5300][startup] LOG: database system was shut down at 2024-03-14 14:18:30 GMT 2024-03-14 14:18:31.130 GMT [7064][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:31.200 GMT [7248][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50414 2024-03-14 14:18:31.208 GMT [7248][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:31.208 GMT [7248][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-14 14:18:31.222 GMT [7248][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-14 14:18:31.225 GMT [7248][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50414 2024-03-14 14:18:31.298 GMT [4160][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50416 2024-03-14 14:18:31.333 GMT [7064][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:31.333 GMT [7064][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:31.337 GMT [7064][postmaster] LOG: background worker "logical replication launcher" (PID 5704) exited with exit code 1 2024-03-14 14:18:31.338 GMT [7440][checkpointer] LOG: shutting down 2024-03-14 14:18:31.338 GMT [7440][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:31.341 GMT [7440][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8098, redo lsn=0/40C8098 2024-03-14 14:18:31.346 GMT [7064][postmaster] LOG: database system is shut down 2024-03-14 14:18:31.490 GMT [2476][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:31.491 GMT [2476][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:31.492 GMT [2476][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:31.514 GMT [7820][startup] LOG: database system was shut down at 2024-03-14 14:18:31 GMT 2024-03-14 14:18:31.521 GMT [2476][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:31.596 GMT [2952][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50417 2024-03-14 14:18:31.602 GMT [2952][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-14 14:18:31.719 GMT [5212][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50418 2024-03-14 14:18:31.729 GMT [5212][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:31.729 GMT [5212][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-14 14:18:31.744 GMT [5212][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-14 14:18:31.747 GMT [5212][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50418 2024-03-14 14:18:31.826 GMT [6660][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50419 2024-03-14 14:18:31.865 GMT [2476][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:31.866 GMT [2476][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:31.869 GMT [2476][postmaster] LOG: background worker "logical replication launcher" (PID 5816) exited with exit code 1 2024-03-14 14:18:31.870 GMT [7432][checkpointer] LOG: shutting down 2024-03-14 14:18:31.870 GMT [7432][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:31.873 GMT [7432][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8110, redo lsn=0/40C8110 2024-03-14 14:18:31.877 GMT [2476][postmaster] LOG: database system is shut down 2024-03-14 14:18:32.023 GMT [2548][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:32.024 GMT [2548][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:32.025 GMT [2548][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:32.050 GMT [8100][startup] LOG: database system was shut down at 2024-03-14 14:18:31 GMT 2024-03-14 14:18:32.063 GMT [2548][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:32.128 GMT [3092][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50420 2024-03-14 14:18:32.135 GMT [3092][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:32.135 GMT [3092][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-14 14:18:32.148 GMT [3092][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-14 14:18:32.151 GMT [3092][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50420 2024-03-14 14:18:32.238 GMT [7764][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50421 2024-03-14 14:18:32.244 GMT [7764][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-14 14:18:32.298 GMT [5460][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50422 2024-03-14 14:18:32.304 GMT [5460][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-14 14:18:32.357 GMT [1888][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50423 2024-03-14 14:18:32.364 GMT [1888][client backend] [[unknown]][1/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:32.364 GMT [1888][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-14 14:18:32.367 GMT [1888][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-14 14:18:32.372 GMT [1888][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50423 2024-03-14 14:18:32.420 GMT [6844][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50424 2024-03-14 14:18:32.427 GMT [6844][client backend] [[unknown]][2/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:32.427 GMT [6844][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-14 14:18:32.430 GMT [6844][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-14 14:18:32.432 GMT [6844][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50424 2024-03-14 14:18:32.580 GMT [7128][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50425 2024-03-14 14:18:32.587 GMT [7128][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-14 14:18:32.641 GMT [5692][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50426 2024-03-14 14:18:32.650 GMT [5692][client backend] [[unknown]][4/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:32.650 GMT [5692][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-14 14:18:32.664 GMT [5692][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client.key$$ 2024-03-14 14:18:32.667 GMT [5692][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=certdb host=pg-loadbalancetest port=50426 2024-03-14 14:18:32.752 GMT [3912][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50427 2024-03-14 14:18:32.761 GMT [3912][client backend] [[unknown]][5/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:32.761 GMT [3912][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-14 14:18:32.764 GMT [3912][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client-der.key$$ 2024-03-14 14:18:32.766 GMT [3912][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50427 2024-03-14 14:18:32.817 GMT [6688][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50428 2024-03-14 14:18:32.828 GMT [6688][client backend] [[unknown]][6/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:32.828 GMT [6688][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-14 14:18:32.831 GMT [6688][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-14 14:18:32.833 GMT [6688][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50428 2024-03-14 14:18:32.924 GMT [3220][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50429 2024-03-14 14:18:32.933 GMT [3220][client backend] [[unknown]][7/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:32.933 GMT [3220][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-14 14:18:32.935 GMT [3220][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-14 14:18:32.938 GMT [3220][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50429 2024-03-14 14:18:32.986 GMT [6436][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50430 2024-03-14 14:18:32.996 GMT [6436][client backend] [[unknown]][8/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:32.996 GMT [6436][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-14 14:18:32.999 GMT [6436][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client.key$$ 2024-03-14 14:18:33.001 GMT [6436][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50430 2024-03-14 14:18:33.048 GMT [3844][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50431 2024-03-14 14:18:33.057 GMT [3844][client backend] [[unknown]][9/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:33.057 GMT [3844][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-14 14:18:33.060 GMT [3844][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client.key$$ 2024-03-14 14:18:33.062 GMT [3844][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50431 2024-03-14 14:18:33.117 GMT [5812][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50432 2024-03-14 14:18:33.126 GMT [5812][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-14 14:18:33.219 GMT [2716][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50433 2024-03-14 14:18:33.230 GMT [2716][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-14 14:18:33.288 GMT [5020][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50434 2024-03-14 14:18:33.297 GMT [5020][client backend] [[unknown]][11/1:0] LOG: connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:8) 2024-03-14 14:18:33.297 GMT [5020][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-14 14:18:33.309 GMT [5020][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client-dn.key$$ 2024-03-14 14:18:33.311 GMT [5020][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50434 2024-03-14 14:18:33.393 GMT [6784][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50435 2024-03-14 14:18:33.402 GMT [6784][client backend] [[unknown]][12/1:0] LOG: connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:9) 2024-03-14 14:18:33.402 GMT [6784][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-14 14:18:33.414 GMT [6784][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client-dn.key$$ 2024-03-14 14:18:33.417 GMT [6784][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50435 2024-03-14 14:18:33.503 GMT [7120][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50436 2024-03-14 14:18:33.512 GMT [7120][client backend] [[unknown]][13/1:0] LOG: connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:10) 2024-03-14 14:18:33.512 GMT [7120][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-14 14:18:33.525 GMT [7120][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client-dn.key$$ 2024-03-14 14:18:33.527 GMT [7120][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50436 2024-03-14 14:18:33.623 GMT [6012][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50437 2024-03-14 14:18:33.632 GMT [6012][client backend] [[unknown]][14/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:33.632 GMT [6012][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-14 14:18:33.635 GMT [6012][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-14 14:18:33.639 GMT [6012][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50437 2024-03-14 14:18:33.689 GMT [3980][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50438 2024-03-14 14:18:33.698 GMT [3980][client backend] [[unknown]][15/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:33.698 GMT [3980][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-14 14:18:33.698 GMT [3980][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-14 14:18:33.698 GMT [3980][client backend] [[unknown]][15/1:0] DETAIL: Connection matched file "C:/cirrus/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-14 14:18:33.753 GMT [6840][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50439 2024-03-14 14:18:33.761 GMT [6840][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-14 14:18:33.761 GMT [6840][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-14 14:18:33.815 GMT [5868][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50440 2024-03-14 14:18:33.824 GMT [5868][client backend] [[unknown]][16/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:4) 2024-03-14 14:18:33.824 GMT [5868][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-14 14:18:33.836 GMT [5868][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client.key$$ 2024-03-14 14:18:33.840 GMT [5868][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50440 2024-03-14 14:18:33.922 GMT [1312][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50441 2024-03-14 14:18:33.931 GMT [1312][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-14 14:18:33.931 GMT [1312][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-14 14:18:33.931 GMT [1312][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-14 14:18:33.931 GMT [1312][client backend] [[unknown]][17/1:0] DETAIL: Connection matched file "C:/cirrus/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-14 14:18:33.986 GMT [2280][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50442 2024-03-14 14:18:33.994 GMT [2280][client backend] [[unknown]][18/1:0] LOG: connection authenticated: user="yetanotheruser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:6) 2024-03-14 14:18:33.994 GMT [2280][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-14 14:18:33.997 GMT [2280][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/client.key$$ 2024-03-14 14:18:34.000 GMT [2280][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50442 2024-03-14 14:18:34.024 GMT [2548][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:34.024 GMT [2548][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:34.029 GMT [2548][postmaster] LOG: background worker "logical replication launcher" (PID 6528) exited with exit code 1 2024-03-14 14:18:34.030 GMT [5128][checkpointer] LOG: shutting down 2024-03-14 14:18:34.030 GMT [5128][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:34.033 GMT [5128][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8188, redo lsn=0/40C8188 2024-03-14 14:18:34.038 GMT [2548][postmaster] LOG: database system is shut down 2024-03-14 14:18:34.182 GMT [2724][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:34.183 GMT [2724][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:34.184 GMT [2724][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:34.203 GMT [2960][startup] LOG: database system was shut down at 2024-03-14 14:18:34 GMT 2024-03-14 14:18:34.212 GMT [2724][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:34.285 GMT [3524][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50443 2024-03-14 14:18:34.294 GMT [3524][client backend] [[unknown]][0/1:0] LOG: connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7) 2024-03-14 14:18:34.294 GMT [3524][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-14 14:18:34.307 GMT [3524][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=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_YG7l/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-14 14:18:34.310 GMT [3524][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb host=pg-loadbalancetest port=50443 2024-03-14 14:18:34.396 GMT [820][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50444 2024-03-14 14:18:34.404 GMT [820][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-14 14:18:34.404 GMT [820][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-14 14:18:34.461 GMT [4280][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50445 2024-03-14 14:18:34.468 GMT [4280][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-14 14:18:34.468 GMT [4280][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-14 14:18:34.541 GMT [2724][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:34.541 GMT [2724][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:34.548 GMT [2724][postmaster] LOG: background worker "logical replication launcher" (PID 7756) exited with exit code 1 2024-03-14 14:18:34.552 GMT [4120][checkpointer] LOG: shutting down 2024-03-14 14:18:34.552 GMT [4120][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:34.555 GMT [4120][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8200, redo lsn=0/40C8200 2024-03-14 14:18:34.561 GMT [2724][postmaster] LOG: database system is shut down 2024-03-14 14:18:34.708 GMT [660][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:34.708 GMT [660][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:34.709 GMT [660][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:34.736 GMT [5064][startup] LOG: database system was shut down at 2024-03-14 14:18:34 GMT 2024-03-14 14:18:34.744 GMT [660][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:34.810 GMT [5796][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50446 2024-03-14 14:18:34.817 GMT [5796][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-14 14:18:34.817 GMT [5796][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-14 14:18:34.886 GMT [660][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:34.886 GMT [660][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:34.891 GMT [660][postmaster] LOG: background worker "logical replication launcher" (PID 2364) exited with exit code 1 2024-03-14 14:18:34.893 GMT [5096][checkpointer] LOG: shutting down 2024-03-14 14:18:34.893 GMT [5096][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:34.896 GMT [5096][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8278, redo lsn=0/40C8278 2024-03-14 14:18:34.901 GMT [660][postmaster] LOG: database system is shut down 2024-03-14 14:18:35.044 GMT [3676][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:35.045 GMT [3676][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:35.046 GMT [3676][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:35.068 GMT [7320][startup] LOG: database system was shut down at 2024-03-14 14:18:34 GMT 2024-03-14 14:18:35.076 GMT [3676][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:35.145 GMT [5028][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50447 2024-03-14 14:18:35.153 GMT [5028][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-14 14:18:35.153 GMT [5028][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-14 14:18:35.207 GMT [3096][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50448 2024-03-14 14:18:35.215 GMT [3096][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-14 14:18:35.215 GMT [3096][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-14 14:18:35.244 GMT [3676][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:35.244 GMT [3676][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:35.249 GMT [3676][postmaster] LOG: background worker "logical replication launcher" (PID 6760) exited with exit code 1 2024-03-14 14:18:35.250 GMT [5672][checkpointer] LOG: shutting down 2024-03-14 14:18:35.250 GMT [5672][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:35.253 GMT [5672][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C82F0, redo lsn=0/40C82F0 2024-03-14 14:18:35.258 GMT [3676][postmaster] LOG: database system is shut down 2024-03-14 14:18:35.408 GMT [4816][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:35.408 GMT [4816][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:35.409 GMT [4816][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:35.433 GMT [1892][startup] LOG: database system was shut down at 2024-03-14 14:18:35 GMT 2024-03-14 14:18:35.441 GMT [4816][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:35.506 GMT [6384][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50449 2024-03-14 14:18:35.510 GMT [6384][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:35.510 GMT [6384][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:35.569 GMT [7152][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50450 2024-03-14 14:18:35.577 GMT [7152][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:35.577 GMT [7152][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-14 14:18:35.589 GMT [7152][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-14 14:18:35.592 GMT [7152][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50450 2024-03-14 14:18:35.653 GMT [4816][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:35.653 GMT [4816][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:35.658 GMT [4816][postmaster] LOG: background worker "logical replication launcher" (PID 1048) exited with exit code 1 2024-03-14 14:18:35.659 GMT [5352][checkpointer] LOG: shutting down 2024-03-14 14:18:35.659 GMT [5352][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:35.662 GMT [5352][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8368, redo lsn=0/40C8368 2024-03-14 14:18:35.667 GMT [4816][postmaster] LOG: database system is shut down 2024-03-14 14:18:35.817 GMT [5772][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:35.818 GMT [5772][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:35.819 GMT [5772][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:35.844 GMT [2568][startup] LOG: database system was shut down at 2024-03-14 14:18:35 GMT 2024-03-14 14:18:35.853 GMT [5772][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:35.923 GMT [772][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50451 2024-03-14 14:18:35.926 GMT [772][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:35.927 GMT [772][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:35.994 GMT [8088][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50452 2024-03-14 14:18:36.001 GMT [8088][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:36.002 GMT [8088][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-14 14:18:36.014 GMT [8088][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-14 14:18:36.017 GMT [8088][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50452 2024-03-14 14:18:36.074 GMT [5772][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:36.074 GMT [5772][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:36.080 GMT [5772][postmaster] LOG: background worker "logical replication launcher" (PID 5684) exited with exit code 1 2024-03-14 14:18:36.081 GMT [5168][checkpointer] LOG: shutting down 2024-03-14 14:18:36.081 GMT [5168][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:36.084 GMT [5168][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C83E0, redo lsn=0/40C83E0 2024-03-14 14:18:36.089 GMT [5772][postmaster] LOG: database system is shut down 2024-03-14 14:18:36.240 GMT [5396][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:36.241 GMT [5396][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:36.242 GMT [5396][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:36.267 GMT [7868][startup] LOG: database system was shut down at 2024-03-14 14:18:36 GMT 2024-03-14 14:18:36.275 GMT [5396][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:36.336 GMT [4412][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50453 2024-03-14 14:18:36.340 GMT [4412][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:36.340 GMT [4412][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:36.396 GMT [3632][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50454 2024-03-14 14:18:36.404 GMT [3632][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:36.404 GMT [3632][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-14 14:18:36.416 GMT [3632][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-14 14:18:36.419 GMT [3632][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50454 2024-03-14 14:18:36.479 GMT [5396][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:36.479 GMT [5396][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:36.483 GMT [5396][postmaster] LOG: background worker "logical replication launcher" (PID 3580) exited with exit code 1 2024-03-14 14:18:36.485 GMT [1308][checkpointer] LOG: shutting down 2024-03-14 14:18:36.485 GMT [1308][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:36.488 GMT [1308][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8458, redo lsn=0/40C8458 2024-03-14 14:18:36.493 GMT [5396][postmaster] LOG: database system is shut down 2024-03-14 14:18:36.643 GMT [5760][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:36.644 GMT [5760][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:36.645 GMT [5760][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:36.673 GMT [5668][startup] LOG: database system was shut down at 2024-03-14 14:18:36 GMT 2024-03-14 14:18:36.681 GMT [5760][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:36.744 GMT [3744][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50455 2024-03-14 14:18:36.748 GMT [3744][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:36.748 GMT [3744][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:36.809 GMT [5480][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50456 2024-03-14 14:18:36.817 GMT [5480][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:36.817 GMT [5480][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-14 14:18:36.830 GMT [5480][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-14 14:18:36.833 GMT [5480][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50456 2024-03-14 14:18:36.858 GMT [5760][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:36.858 GMT [5760][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:36.863 GMT [5760][postmaster] LOG: background worker "logical replication launcher" (PID 7620) exited with exit code 1 2024-03-14 14:18:36.864 GMT [4252][checkpointer] LOG: shutting down 2024-03-14 14:18:36.864 GMT [4252][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:36.867 GMT [4252][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C84D0, redo lsn=0/40C84D0 2024-03-14 14:18:36.872 GMT [5760][postmaster] LOG: database system is shut down 2024-03-14 14:18:37.022 GMT [1260][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:37.023 GMT [1260][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:37.024 GMT [1260][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:37.044 GMT [5880][startup] LOG: database system was shut down at 2024-03-14 14:18:36 GMT 2024-03-14 14:18:37.052 GMT [1260][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:37.121 GMT [1244][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50457 2024-03-14 14:18:37.124 GMT [1244][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:37.124 GMT [1244][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:37.180 GMT [1608][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50458 2024-03-14 14:18:37.187 GMT [1608][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:37.187 GMT [1608][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-14 14:18:37.200 GMT [1608][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-14 14:18:37.202 GMT [1608][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50458 2024-03-14 14:18:37.296 GMT [1260][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:37.296 GMT [1260][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:37.299 GMT [1260][postmaster] LOG: background worker "logical replication launcher" (PID 8064) exited with exit code 1 2024-03-14 14:18:37.302 GMT [1788][checkpointer] LOG: shutting down 2024-03-14 14:18:37.302 GMT [1788][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:37.305 GMT [1788][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8548, redo lsn=0/40C8548 2024-03-14 14:18:37.309 GMT [1260][postmaster] LOG: database system is shut down 2024-03-14 14:18:37.451 GMT [6764][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:37.452 GMT [6764][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:37.453 GMT [6764][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:37.473 GMT [7676][startup] LOG: database system was shut down at 2024-03-14 14:18:37 GMT 2024-03-14 14:18:37.480 GMT [6764][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:37.553 GMT [5212][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50459 2024-03-14 14:18:37.556 GMT [5212][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:37.556 GMT [5212][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:37.615 GMT [7948][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50460 2024-03-14 14:18:37.622 GMT [7948][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:37.622 GMT [7948][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-14 14:18:37.634 GMT [7948][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-14 14:18:37.636 GMT [7948][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50460 2024-03-14 14:18:37.700 GMT [6764][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:37.700 GMT [6764][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:37.703 GMT [6764][postmaster] LOG: background worker "logical replication launcher" (PID 5188) exited with exit code 1 2024-03-14 14:18:37.704 GMT [1556][checkpointer] LOG: shutting down 2024-03-14 14:18:37.705 GMT [1556][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:37.708 GMT [1556][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C85C0, redo lsn=0/40C85C0 2024-03-14 14:18:37.713 GMT [6764][postmaster] LOG: database system is shut down 2024-03-14 14:18:37.862 GMT [980][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:37.862 GMT [980][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:37.863 GMT [980][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:37.883 GMT [1824][startup] LOG: database system was shut down at 2024-03-14 14:18:37 GMT 2024-03-14 14:18:37.891 GMT [980][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:37.957 GMT [3680][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50461 2024-03-14 14:18:37.960 GMT [3680][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:37.960 GMT [3680][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:38.022 GMT [6728][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50462 2024-03-14 14:18:38.029 GMT [6728][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:38.029 GMT [6728][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-14 14:18:38.043 GMT [6728][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-14 14:18:38.045 GMT [6728][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50462 2024-03-14 14:18:38.105 GMT [980][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:38.106 GMT [980][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:38.111 GMT [980][postmaster] LOG: background worker "logical replication launcher" (PID 8100) exited with exit code 1 2024-03-14 14:18:38.111 GMT [6340][checkpointer] LOG: shutting down 2024-03-14 14:18:38.111 GMT [6340][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:38.114 GMT [6340][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8638, redo lsn=0/40C8638 2024-03-14 14:18:38.118 GMT [980][postmaster] LOG: database system is shut down 2024-03-14 14:18:38.268 GMT [7848][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:38.269 GMT [7848][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:38.270 GMT [7848][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:38.289 GMT [6772][startup] LOG: database system was shut down at 2024-03-14 14:18:38 GMT 2024-03-14 14:18:38.297 GMT [7848][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:38.369 GMT [4632][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50463 2024-03-14 14:18:38.372 GMT [4632][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:38.372 GMT [4632][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:38.429 GMT [5616][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50464 2024-03-14 14:18:38.436 GMT [5616][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:38.436 GMT [5616][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-14 14:18:38.448 GMT [5616][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-14 14:18:38.451 GMT [5616][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50464 2024-03-14 14:18:38.513 GMT [7848][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:38.513 GMT [7848][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:38.518 GMT [7848][postmaster] LOG: background worker "logical replication launcher" (PID 6488) exited with exit code 1 2024-03-14 14:18:38.518 GMT [3948][checkpointer] LOG: shutting down 2024-03-14 14:18:38.518 GMT [3948][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:38.521 GMT [3948][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C86B0, redo lsn=0/40C86B0 2024-03-14 14:18:38.527 GMT [7848][postmaster] LOG: database system is shut down 2024-03-14 14:18:38.676 GMT [1016][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-14 14:18:38.677 GMT [1016][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 50079 2024-03-14 14:18:38.678 GMT [1016][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/ie5lmStKDL/.s.PGSQL.50079" 2024-03-14 14:18:38.702 GMT [2420][startup] LOG: database system was shut down at 2024-03-14 14:18:38 GMT 2024-03-14 14:18:38.710 GMT [1016][postmaster] LOG: database system is ready to accept connections 2024-03-14 14:18:38.775 GMT [2416][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50465 2024-03-14 14:18:38.779 GMT [2416][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-14 14:18:38.779 GMT [2416][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-14 14:18:38.834 GMT [4476][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50466 2024-03-14 14:18:38.841 GMT [4476][client backend] [[unknown]][0/1:0] LOG: connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3) 2024-03-14 14:18:38.841 GMT [4476][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-14 14:18:38.854 GMT [4476][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-14 14:18:38.857 GMT [4476][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50466 2024-03-14 14:18:38.919 GMT [1016][postmaster] LOG: received fast shutdown request 2024-03-14 14:18:38.919 GMT [1016][postmaster] LOG: aborting any active transactions 2024-03-14 14:18:38.923 GMT [1016][postmaster] LOG: background worker "logical replication launcher" (PID 8124) exited with exit code 1 2024-03-14 14:18:38.923 GMT [4056][checkpointer] LOG: shutting down 2024-03-14 14:18:38.924 GMT [4056][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-14 14:18:38.926 GMT [4056][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8728, redo lsn=0/40C8728 2024-03-14 14:18:38.931 GMT [1016][postmaster] LOG: database system is shut down 2024-03-14 14:18:39.070 GMT [6584][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-14 14:18:39.070 GMT [6584][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [14:18:39.136](0.234s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"