[05:50:01.620](0.274s) # setting up data directory # Checking port 53182 # Found port 53182 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=53182 host=C:/Windows/TEMP/sU9hyzVm_r Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log [05:50:01.742](0.122s) # 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 7288 [05:50:03.883](2.140s) 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 5560 [05:50:08.832](4.949s) # 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-10 05:50:03.424 GMT [7288][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:03.426 GMT [7288][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:03.512 GMT [5152][startup] LOG: database system was shut down at 2024-03-10 05:39:33 GMT 2024-03-10 05:50:03.562 GMT [7288][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:03.824 GMT [1796][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:03.826 GMT [1796][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-10 05:50:03.826 GMT [1796][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:03.840 GMT [1796][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-10 05:50:03.844 GMT [1796][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:03.975 GMT [3100][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:03.977 GMT [3100][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-10 05:50:03.977 GMT [3100][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:03.982 GMT [3100][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-10 05:50:03.983 GMT [3100][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.246 GMT [4420][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.247 GMT [4420][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-10 05:50:04.247 GMT [4420][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.250 GMT [4420][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-10 05:50:04.251 GMT [4420][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.685 GMT [3896][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.687 GMT [3896][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-10 05:50:04.687 GMT [3896][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.690 GMT [3896][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-10 05:50:04.691 GMT [3896][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.798 GMT [2648][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.799 GMT [2648][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-10 05:50:04.799 GMT [2648][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.802 GMT [2648][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-10 05:50:04.803 GMT [2648][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.971 GMT [5032][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.973 GMT [5032][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-10 05:50:04.973 GMT [5032][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.975 GMT [5032][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-10 05:50:05.220 GMT [5032][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.252 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:05.347 GMT [6196][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:05.349 GMT [6196][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-10 05:50:05.349 GMT [6196][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:05.351 GMT [6196][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-10 05:50:05.620 GMT [6196][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.276 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:05.828 GMT [7732][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:05.829 GMT [7732][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-10 05:50:05.829 GMT [7732][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:05.832 GMT [7732][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-10 05:50:06.491 GMT [7732][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.666 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:06.570 GMT [7988][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:06.572 GMT [7988][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-10 05:50:06.572 GMT [7988][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:06.575 GMT [7988][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-10 05:50:06.794 GMT [7988][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.228 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:07.027 GMT [6296][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:07.029 GMT [6296][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-10 05:50:07.029 GMT [6296][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:07.065 GMT [6296][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-10 05:50:07.327 GMT [6296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.303 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:07.563 GMT [5900][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:07.564 GMT [5900][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-10 05:50:07.564 GMT [5900][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:07.567 GMT [5900][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-10 05:50:07.905 GMT [5900][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.346 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:08.099 GMT [7288][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:08.099 GMT [7288][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:08.115 GMT [7288][postmaster] LOG: background worker "logical replication launcher" (PID 2728) exited with exit code 1 2024-03-10 05:50:08.116 GMT [4940][checkpointer] LOG: shutting down 2024-03-10 05:50:08.119 GMT [4940][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:08.426 GMT [4940][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.301 s, sync=0.001 s, total=0.310 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C79E0, redo lsn=0/40C79E0 2024-03-10 05:50:08.500 GMT [7288][postmaster] LOG: database system is shut down 2024-03-10 05:50:08.682 GMT [5560][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:08.683 GMT [5560][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:08.693 GMT [5560][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:08.753 GMT [3676][startup] LOG: database system was shut down at 2024-03-10 05:50:08 GMT 2024-03-10 05:50:08.773 GMT [5560][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:08.859 GMT [5560][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:08.859 GMT [5560][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:08.896 GMT [5560][postmaster] LOG: background worker "logical replication launcher" (PID 6532) exited with exit code 1 2024-03-10 05:50:08.896 GMT [7500][checkpointer] LOG: shutting down 2024-03-10 05:50:08.897 GMT [7500][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:08.900 GMT [7500][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.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7A58, redo lsn=0/40C7A58 2024-03-10 05:50:08.908 GMT [5560][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.085 GMT [5688][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-10 05:50:09.085 GMT [5688][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:50:09.223](0.391s) 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 6208 [05:50:09.488](0.265s) 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-10 05:50:03.424 GMT [7288][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:03.426 GMT [7288][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:03.512 GMT [5152][startup] LOG: database system was shut down at 2024-03-10 05:39:33 GMT 2024-03-10 05:50:03.562 GMT [7288][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:03.824 GMT [1796][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:03.826 GMT [1796][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-10 05:50:03.826 GMT [1796][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:03.840 GMT [1796][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-10 05:50:03.844 GMT [1796][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:03.975 GMT [3100][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:03.977 GMT [3100][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-10 05:50:03.977 GMT [3100][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:03.982 GMT [3100][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-10 05:50:03.983 GMT [3100][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.246 GMT [4420][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.247 GMT [4420][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-10 05:50:04.247 GMT [4420][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.250 GMT [4420][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-10 05:50:04.251 GMT [4420][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.685 GMT [3896][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.687 GMT [3896][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-10 05:50:04.687 GMT [3896][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.690 GMT [3896][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-10 05:50:04.691 GMT [3896][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.798 GMT [2648][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.799 GMT [2648][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-10 05:50:04.799 GMT [2648][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.802 GMT [2648][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-10 05:50:04.803 GMT [2648][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.971 GMT [5032][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.973 GMT [5032][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-10 05:50:04.973 GMT [5032][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.975 GMT [5032][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-10 05:50:05.220 GMT [5032][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.252 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:05.347 GMT [6196][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:05.349 GMT [6196][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-10 05:50:05.349 GMT [6196][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:05.351 GMT [6196][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-10 05:50:05.620 GMT [6196][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.276 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:05.828 GMT [7732][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:05.829 GMT [7732][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-10 05:50:05.829 GMT [7732][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:05.832 GMT [7732][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-10 05:50:06.491 GMT [7732][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.666 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:06.570 GMT [7988][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:06.572 GMT [7988][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-10 05:50:06.572 GMT [7988][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:06.575 GMT [7988][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-10 05:50:06.794 GMT [7988][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.228 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:07.027 GMT [6296][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:07.029 GMT [6296][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-10 05:50:07.029 GMT [6296][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:07.065 GMT [6296][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-10 05:50:07.327 GMT [6296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.303 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:07.563 GMT [5900][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:07.564 GMT [5900][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-10 05:50:07.564 GMT [5900][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:07.567 GMT [5900][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-10 05:50:07.905 GMT [5900][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.346 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:08.099 GMT [7288][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:08.099 GMT [7288][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:08.115 GMT [7288][postmaster] LOG: background worker "logical replication launcher" (PID 2728) exited with exit code 1 2024-03-10 05:50:08.116 GMT [4940][checkpointer] LOG: shutting down 2024-03-10 05:50:08.119 GMT [4940][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:08.426 GMT [4940][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.301 s, sync=0.001 s, total=0.310 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C79E0, redo lsn=0/40C79E0 2024-03-10 05:50:08.500 GMT [7288][postmaster] LOG: database system is shut down 2024-03-10 05:50:08.682 GMT [5560][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:08.683 GMT [5560][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:08.693 GMT [5560][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:08.753 GMT [3676][startup] LOG: database system was shut down at 2024-03-10 05:50:08 GMT 2024-03-10 05:50:08.773 GMT [5560][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:08.859 GMT [5560][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:08.859 GMT [5560][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:08.896 GMT [5560][postmaster] LOG: background worker "logical replication launcher" (PID 6532) exited with exit code 1 2024-03-10 05:50:08.896 GMT [7500][checkpointer] LOG: shutting down 2024-03-10 05:50:08.897 GMT [7500][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:08.900 GMT [7500][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.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7A58, redo lsn=0/40C7A58 2024-03-10 05:50:08.908 GMT [5560][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.085 GMT [5688][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-10 05:50:09.085 GMT [5688][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.375 GMT [6208][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:09.376 GMT [6208][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:09.377 GMT [6208][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:09.416 GMT [4144][startup] LOG: database system was shut down at 2024-03-10 05:50:08 GMT 2024-03-10 05:50:09.431 GMT [6208][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:09.528 GMT [6208][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:09.528 GMT [6208][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:09.555 GMT [6208][postmaster] LOG: background worker "logical replication launcher" (PID 2896) exited with exit code 1 2024-03-10 05:50:09.555 GMT [5580][checkpointer] LOG: shutting down 2024-03-10 05:50:09.556 GMT [5580][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:09.559 GMT [5580][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/40C7AD0, redo lsn=0/40C7AD0 2024-03-10 05:50:09.580 GMT [6208][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.703 GMT [4632][postmaster] FATAL: could not set SSL protocol version range 2024-03-10 05:50:09.703 GMT [4632][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-10 05:50:09.704 GMT [4632][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:50:09.750](0.262s) 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 7844 [05:50:10.176](0.426s) ok 5 - restart succeeds with correct SSL protocol bounds [05:50:10.176](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 7900 [05:50:10.707](0.531s) ok 6 - server doesn't accept non-SSL connections [05:50:10.707](0.000s) ok 7 - server doesn't accept non-SSL connections: matches [05:50:10.816](0.109s) ok 8 - connect without server root cert sslmode=require [05:50:10.816](0.001s) ok 9 - connect without server root cert sslmode=require: no stderr [05:50:10.954](0.138s) ok 10 - connect without server root cert sslmode=verify-ca [05:50:10.954](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches [05:50:11.087](0.133s) ok 12 - connect without server root cert sslmode=verify-full [05:50:11.087](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches [05:50:11.223](0.136s) ok 14 - connect with wrong server root cert sslmode=require [05:50:11.223](0.001s) ok 15 - connect with wrong server root cert sslmode=require: matches [05:50:11.363](0.140s) ok 16 - connect with wrong server root cert sslmode=verify-ca [05:50:11.363](0.001s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [05:50:11.465](0.102s) ok 18 - connect with wrong server root cert sslmode=verify-full [05:50:11.466](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [05:50:11.587](0.121s) ok 20 - connect with server CA cert, without root CA [05:50:11.588](0.001s) ok 21 - connect with server CA cert, without root CA: matches [05:50:11.689](0.101s) ok 22 - connect with correct server CA cert file sslmode=require [05:50:11.689](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [05:50:11.863](0.174s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [05:50:11.863](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [05:50:11.954](0.091s) ok 26 - connect with correct server CA cert file sslmode=verify-full [05:50:11.955](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [05:50:12.120](0.165s) ok 28 - cert root file that contains two certificates, order 1 [05:50:12.120](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr [05:50:12.206](0.086s) ok 30 - cert root file that contains two certificates, order 2 [05:50:12.207](0.001s) ok 31 - cert root file that contains two certificates, order 2: no stderr [05:50:12.315](0.109s) ok 32 - connect with sslcertmode=disable [05:50:12.316](0.001s) ok 33 - connect with sslcertmode=disable: no stderr [05:50:12.427](0.111s) ok 34 - connect with sslcertmode=allow [05:50:12.427](0.001s) ok 35 - connect with sslcertmode=allow: no stderr [05:50:12.566](0.139s) ok 36 - connect with sslcertmode=require fails without a client certificate [05:50:12.567](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [05:50:12.760](0.194s) ok 38 - sslcrl option with invalid file name [05:50:12.761](0.001s) ok 39 - sslcrl option with invalid file name: no stderr [05:50:12.927](0.166s) ok 40 - CRL belonging to a different CA [05:50:12.927](0.000s) ok 41 - CRL belonging to a different CA: matches [05:50:13.045](0.118s) ok 42 - directory CRL belonging to a different CA [05:50:13.046](0.000s) ok 43 - directory CRL belonging to a different CA: matches [05:50:13.215](0.169s) ok 44 - CRL with a non-revoked cert [05:50:13.216](0.001s) ok 45 - CRL with a non-revoked cert: no stderr [05:50:13.359](0.144s) ok 46 - directory CRL with a non-revoked cert [05:50:13.359](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr [05:50:13.458](0.098s) ok 48 - mismatch between host name and server certificate sslmode=require [05:50:13.458](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [05:50:13.534](0.076s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [05:50:13.535](0.001s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [05:50:13.613](0.077s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [05:50:13.613](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 2556 [05:50:14.100](0.486s) ok 54 - IP address in the Common Name [05:50:14.100](0.000s) ok 55 - IP address in the Common Name: no stderr [05:50:14.255](0.155s) ok 56 - mismatch between host name and server certificate IP address [05:50:14.256](0.001s) 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 1300 [05:50:14.726](0.471s) ok 58 - IP address in a dNSName [05:50:14.727](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 6432 [05:50:15.195](0.469s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [05:50:15.196](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [05:50:15.915](0.720s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [05:50:15.916](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [05:50:16.025](0.109s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [05:50:16.026](0.001s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [05:50:16.134](0.108s) ok 66 - host name not matching with X.509 Subject Alternative Names [05:50:16.134](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [05:50:16.243](0.109s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [05:50:16.244](0.001s) 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 4028 [05:50:16.604](0.360s) ok 70 - host name matching with a single X.509 Subject Alternative Name [05:50:16.604](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [05:50:16.714](0.110s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [05:50:16.715](0.001s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [05:50:17.120](0.405s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [05:50:17.120](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches [05:50:17.149](0.029s) 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 5632 [05:50:17.512](0.363s) ok 77 - certificate with both a CN and SANs 1 [05:50:17.512](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr [05:50:17.623](0.111s) ok 79 - certificate with both a CN and SANs 2 [05:50:17.623](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr [05:50:17.733](0.110s) ok 81 - certificate with both a CN and SANs ignores CN [05:50:17.733](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches [05:50:17.763](0.029s) 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 5960 [05:50:18.110](0.347s) ok 84 - certificate with both an IP CN and DNS SANs matches CN [05:50:18.110](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr [05:50:18.218](0.108s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1 [05:50:18.218](0.001s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [05:50:18.327](0.108s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2 [05:50:18.327](0.000s) 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 6304 [05:50:18.688](0.361s) ok 90 - server certificate without CN or SANs sslmode=verify-ca [05:50:18.688](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr [05:50:18.798](0.110s) ok 92 - server certificate without CN or SANs sslmode=verify-full [05:50:18.798](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 7684 [05:50:19.141](0.343s) ok 94 - sslrootcert=system does not connect with private CA [05:50:19.141](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches [05:50:19.203](0.062s) ok 96 - sslrootcert=system only accepts sslmode=verify-full [05:50:19.203](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches [05:50:19.313](0.110s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE [05:50:19.314](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [05:50:19.422](0.108s) ok 100 - sslrootcert=system defaults to sslmode=verify-full [05:50:19.422](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 1256 [05:50:19.766](0.344s) ok 102 - connects without client-side CRL [05:50:19.766](0.000s) ok 103 - connects without client-side CRL: no stderr [05:50:19.876](0.109s) ok 104 - does not connect with client-side CRL file [05:50:19.876](0.000s) ok 105 - does not connect with client-side CRL file: matches [05:50:19.987](0.111s) ok 106 - does not connect with client-side CRL directory [05:50:19.987](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() [05:50:20.063](0.076s) ok 108 - pg_stat_ssl view without client certificate: exit code 0 [05:50:20.063](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr [05:50:20.063](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches [05:50:20.174](0.110s) ok 111 - connection success with correct range of TLS protocol versions [05:50:20.174](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr [05:50:20.236](0.062s) ok 113 - connection failure with incorrect range of TLS protocol versions [05:50:20.236](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches [05:50:20.299](0.062s) ok 115 - connection failure with an incorrect SSL protocol minimum bound [05:50:20.299](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches [05:50:20.361](0.062s) ok 117 - connection failure with an incorrect SSL protocol maximum bound [05:50:20.361](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches [05:50:20.361](0.000s) # running server tests [05:50:20.470](0.108s) ok 119 - certificate authorization fails without client cert [05:50:20.470](0.000s) ok 120 - certificate authorization fails without client cert: matches [05:50:20.580](0.110s) ok 121 - certificate authorization succeeds with correct client cert in PEM format [05:50:20.580](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr [05:50:20.688](0.108s) ok 123 - certificate authorization succeeds with correct client cert in DER format [05:50:20.689](0.001s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr [05:50:20.767](0.078s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format [05:50:20.767](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [05:50:20.876](0.109s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format [05:50:20.876](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [05:50:20.985](0.109s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require [05:50:20.986](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [05:50:21.095](0.109s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow [05:50:21.095](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [05:50:21.157](0.062s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable [05:50:21.157](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [05:50:21.219](0.062s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [05:50:21.219](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [05:50:21.329](0.110s) ok 137 - certificate authorization succeeds with DN mapping [05:50:21.329](0.000s) ok 138 - certificate authorization succeeds with DN mapping: no stderr [05:50:21.330](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches [05:50:21.423](0.093s) ok 140 - certificate authorization succeeds with DN regex mapping [05:50:21.423](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr [05:50:21.532](0.109s) ok 142 - certificate authorization succeeds with CN mapping [05:50:21.532](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr [05:50:21.533](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches [05:50:21.533](0.000s) not ok 145 # TODO & SKIP Need Pty support [05:50:21.534](0.000s) not ok 146 # TODO & SKIP Need Pty support [05:50:21.534](0.000s) not ok 147 # TODO & SKIP Need Pty support [05:50:21.534](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_60AN/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [05:50:21.639](0.105s) ok 149 - pg_stat_ssl with client certificate: exit code 0 [05:50:21.640](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr [05:50:21.640](0.000s) ok 151 - pg_stat_ssl with client certificate: matches [05:50:21.640](0.000s) ok 152 # skip Permissions check not enforced on Windows [05:50:21.640](0.000s) ok 153 # skip Permissions check not enforced on Windows [05:50:21.751](0.111s) ok 154 - certificate authorization fails with client cert belonging to another user [05:50:21.751](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches [05:50:21.860](0.108s) ok 156 - certificate authorization fails with revoked client cert [05:50:21.860](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches [05:50:21.861](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match [05:50:21.969](0.109s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name [05:50:21.969](0.000s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [05:50:21.970](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [05:50:22.079](0.109s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name [05:50:22.080](0.001s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [05:50:22.080](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [05:50:22.173](0.093s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [05:50:22.174](0.001s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [05:50:22.175](0.001s) 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 6556 [05:50:22.517](0.343s) ok 168 - intermediate client certificate is provided by client [05:50:22.518](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr [05:50:22.642](0.125s) ok 170 - intermediate client certificate is missing [05:50:22.643](0.000s) ok 171 - intermediate client certificate is missing: matches [05:50:22.752](0.109s) ok 172 - logged client certificate Subjects are truncated if they're too long [05:50:22.752](0.000s) 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 2408 [05:50:23.097](0.345s) ok 174 - intermediate client certificate is untrusted [05:50:23.098](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 6196 [05:50:23.439](0.342s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory [05:50:23.440](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [05:50:23.548](0.109s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [05:50:23.549](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 3480 [05:50:23.893](0.344s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1 [05:50:23.893](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923. [05:50:23.893](0.000s) # got: '2' # expected: '0' [05:50:23.893](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [05:50:23.894](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. [05:50:23.894](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 53182 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: '' [05:50:24.005](0.111s) ok 182 - connect without requesting ocsp response when sslocspstapling=0 [05:50:24.005](0.000s) 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 6160 [05:50:24.302](0.297s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1 [05:50:24.412](0.110s) ok 185 - connect without requesting ocsp response when sslocspstapling=0 [05:50:24.412](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 3840 [05:50:24.757](0.345s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1 [05:50:24.866](0.109s) ok 188 - connect without requesting ocsp response when sslocspstapling=0 [05:50:24.867](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 1016 [05:50:25.210](0.344s) ok 190 - failed with an expired ocsp response when sslocspstapling=1 [05:50:25.320](0.110s) ok 191 - connect without requesting ocsp response when sslocspstapling=0 [05:50:25.320](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 7328 [05:50:25.673](0.352s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1 [05:50:25.673](0.001s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001. [05:50:25.674](0.000s) # got: '2' # expected: '0' [05:50:25.674](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [05:50:25.674](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. [05:50:25.675](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 53182 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: '' [05:50:25.767](0.093s) ok 195 - connect without requesting ocsp response when sslocspstapling=0 [05:50:25.767](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 7988 [05:50:26.118](0.350s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1 [05:50:26.227](0.109s) ok 198 - connect without requesting ocsp response when sslocspstapling=0 [05:50:26.227](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 8120 [05:50:26.539](0.312s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1 [05:50:26.649](0.110s) ok 201 - connect without requesting ocsp response when sslocspstapling=0 [05:50:26.649](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 7216 [05:50:26.993](0.344s) ok 203 - failed with an expired ocsp response when sslocspstapling=1 [05:50:27.102](0.109s) ok 204 - connect without requesting ocsp response when sslocspstapling=0 [05:50:27.102](0.000s) 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 5604 [05:50:27.431](0.329s) ok 206 - failed with an expired ocsp response when sslocspstapling=1 [05:50:27.525](0.094s) ok 207 - connect without requesting ocsp response when sslocspstapling=0 [05:50:27.526](0.001s) 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-10 05:50:03.424 GMT [7288][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:03.426 GMT [7288][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:03.512 GMT [5152][startup] LOG: database system was shut down at 2024-03-10 05:39:33 GMT 2024-03-10 05:50:03.562 GMT [7288][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:03.824 GMT [1796][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:03.826 GMT [1796][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-10 05:50:03.826 GMT [1796][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:03.840 GMT [1796][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-10 05:50:03.844 GMT [1796][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:03.975 GMT [3100][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:03.977 GMT [3100][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-10 05:50:03.977 GMT [3100][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:03.982 GMT [3100][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-10 05:50:03.983 GMT [3100][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.011 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.246 GMT [4420][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.247 GMT [4420][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-10 05:50:04.247 GMT [4420][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.250 GMT [4420][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-10 05:50:04.251 GMT [4420][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.685 GMT [3896][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.687 GMT [3896][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-10 05:50:04.687 GMT [3896][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.690 GMT [3896][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-10 05:50:04.691 GMT [3896][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.798 GMT [2648][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.799 GMT [2648][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-10 05:50:04.799 GMT [2648][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.802 GMT [2648][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-10 05:50:04.803 GMT [2648][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:04.971 GMT [5032][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:04.973 GMT [5032][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-10 05:50:04.973 GMT [5032][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:04.975 GMT [5032][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-10 05:50:05.220 GMT [5032][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.252 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:05.347 GMT [6196][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:05.349 GMT [6196][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-10 05:50:05.349 GMT [6196][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:05.351 GMT [6196][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-10 05:50:05.620 GMT [6196][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.276 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:05.828 GMT [7732][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:05.829 GMT [7732][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-10 05:50:05.829 GMT [7732][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:05.832 GMT [7732][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-10 05:50:06.491 GMT [7732][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.666 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:06.570 GMT [7988][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:06.572 GMT [7988][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-10 05:50:06.572 GMT [7988][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:06.575 GMT [7988][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-10 05:50:06.794 GMT [7988][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.228 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:07.027 GMT [6296][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:07.029 GMT [6296][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-10 05:50:07.029 GMT [6296][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:07.065 GMT [6296][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-10 05:50:07.327 GMT [6296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.303 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:07.563 GMT [5900][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-10 05:50:07.564 GMT [5900][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-10 05:50:07.564 GMT [5900][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-10 05:50:07.567 GMT [5900][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-10 05:50:07.905 GMT [5900][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.346 user=SYSTEM database=postgres host=[local] 2024-03-10 05:50:08.099 GMT [7288][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:08.099 GMT [7288][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:08.115 GMT [7288][postmaster] LOG: background worker "logical replication launcher" (PID 2728) exited with exit code 1 2024-03-10 05:50:08.116 GMT [4940][checkpointer] LOG: shutting down 2024-03-10 05:50:08.119 GMT [4940][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:08.426 GMT [4940][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.301 s, sync=0.001 s, total=0.310 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C79E0, redo lsn=0/40C79E0 2024-03-10 05:50:08.500 GMT [7288][postmaster] LOG: database system is shut down 2024-03-10 05:50:08.682 GMT [5560][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:08.683 GMT [5560][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:08.693 GMT [5560][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:08.753 GMT [3676][startup] LOG: database system was shut down at 2024-03-10 05:50:08 GMT 2024-03-10 05:50:08.773 GMT [5560][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:08.859 GMT [5560][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:08.859 GMT [5560][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:08.896 GMT [5560][postmaster] LOG: background worker "logical replication launcher" (PID 6532) exited with exit code 1 2024-03-10 05:50:08.896 GMT [7500][checkpointer] LOG: shutting down 2024-03-10 05:50:08.897 GMT [7500][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:08.900 GMT [7500][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.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7A58, redo lsn=0/40C7A58 2024-03-10 05:50:08.908 GMT [5560][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.085 GMT [5688][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-10 05:50:09.085 GMT [5688][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.375 GMT [6208][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:09.376 GMT [6208][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:09.377 GMT [6208][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:09.416 GMT [4144][startup] LOG: database system was shut down at 2024-03-10 05:50:08 GMT 2024-03-10 05:50:09.431 GMT [6208][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:09.528 GMT [6208][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:09.528 GMT [6208][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:09.555 GMT [6208][postmaster] LOG: background worker "logical replication launcher" (PID 2896) exited with exit code 1 2024-03-10 05:50:09.555 GMT [5580][checkpointer] LOG: shutting down 2024-03-10 05:50:09.556 GMT [5580][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:09.559 GMT [5580][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/40C7AD0, redo lsn=0/40C7AD0 2024-03-10 05:50:09.580 GMT [6208][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.703 GMT [4632][postmaster] FATAL: could not set SSL protocol version range 2024-03-10 05:50:09.703 GMT [4632][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-10 05:50:09.704 GMT [4632][postmaster] LOG: database system is shut down 2024-03-10 05:50:09.993 GMT [7844][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:09.995 GMT [7844][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:10.067 GMT [7844][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:10.116 GMT [8100][startup] LOG: database system was shut down at 2024-03-10 05:50:09 GMT 2024-03-10 05:50:10.136 GMT [7844][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:10.226 GMT [7844][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:10.226 GMT [7844][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:10.250 GMT [7844][postmaster] LOG: background worker "logical replication launcher" (PID 272) exited with exit code 1 2024-03-10 05:50:10.250 GMT [5824][checkpointer] LOG: shutting down 2024-03-10 05:50:10.250 GMT [5824][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:10.253 GMT [5824][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/40C7B48, redo lsn=0/40C7B48 2024-03-10 05:50:10.277 GMT [7844][postmaster] LOG: database system is shut down 2024-03-10 05:50:10.457 GMT [7900][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:10.458 GMT [7900][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:10.459 GMT [7900][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:10.500 GMT [4976][startup] LOG: database system was shut down at 2024-03-10 05:50:10 GMT 2024-03-10 05:50:10.535 GMT [7900][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:10.673 GMT [7940][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50307 2024-03-10 05:50:10.675 GMT [7940][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-10 05:50:10.675 GMT [7940][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "pg-loadbalancetest", forward lookup not checked. 2024-03-10 05:50:10.777 GMT [3292][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50309 2024-03-10 05:50:10.784 GMT [3292][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-10 05:50:10.784 GMT [3292][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-10 05:50:10.798 GMT [3292][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-10 05:50:10.802 GMT [3292][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50309 2024-03-10 05:50:10.886 GMT [7376][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50310 2024-03-10 05:50:10.897 GMT [7376][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-10 05:50:11.028 GMT [1616][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50313 2024-03-10 05:50:11.039 GMT [1616][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-10 05:50:11.173 GMT [7568][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50314 2024-03-10 05:50:11.180 GMT [7568][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-10 05:50:11.307 GMT [7664][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50316 2024-03-10 05:50:11.313 GMT [7664][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-10 05:50:11.437 GMT [8096][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50318 2024-03-10 05:50:11.443 GMT [8096][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-10 05:50:11.524 GMT [2664][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50319 2024-03-10 05:50:11.531 GMT [2664][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-10 05:50:11.659 GMT [7024][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50320 2024-03-10 05:50:11.667 GMT [7024][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-10 05:50:11.667 GMT [7024][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-10 05:50:11.670 GMT [7024][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-10 05:50:11.673 GMT [7024][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50320 2024-03-10 05:50:11.760 GMT [7232][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50321 2024-03-10 05:50:11.768 GMT [7232][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-10 05:50:11.768 GMT [7232][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-10 05:50:11.781 GMT [7232][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-10 05:50:11.783 GMT [7232][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50321 2024-03-10 05:50:11.934 GMT [3664][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50324 2024-03-10 05:50:11.942 GMT [3664][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-10 05:50:11.942 GMT [3664][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-10 05:50:11.946 GMT [3664][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-10 05:50:11.948 GMT [3664][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50324 2024-03-10 05:50:12.032 GMT [7856][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50326 2024-03-10 05:50:12.054 GMT [7856][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-10 05:50:12.054 GMT [7856][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-10 05:50:12.057 GMT [7856][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-10 05:50:12.059 GMT [7856][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50326 2024-03-10 05:50:12.187 GMT [6524][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50328 2024-03-10 05:50:12.195 GMT [6524][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-10 05:50:12.195 GMT [6524][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-10 05:50:12.198 GMT [6524][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-10 05:50:12.200 GMT [6524][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50328 2024-03-10 05:50:12.275 GMT [6196][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50330 2024-03-10 05:50:12.283 GMT [6196][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-10 05:50:12.283 GMT [6196][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-10 05:50:12.285 GMT [6196][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-10 05:50:12.289 GMT [6196][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50330 2024-03-10 05:50:12.395 GMT [6532][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50332 2024-03-10 05:50:12.403 GMT [6532][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-10 05:50:12.403 GMT [6532][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-10 05:50:12.406 GMT [6532][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-10 05:50:12.409 GMT [6532][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50332 2024-03-10 05:50:12.497 GMT [1112][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50333 2024-03-10 05:50:12.505 GMT [1112][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-10 05:50:12.505 GMT [1112][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-10 05:50:12.521 GMT [1112][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.040 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50333 2024-03-10 05:50:12.635 GMT [1332][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50335 2024-03-10 05:50:12.643 GMT [1332][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-10 05:50:12.643 GMT [1332][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-10 05:50:12.646 GMT [1332][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-10 05:50:12.650 GMT [1332][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50335 2024-03-10 05:50:12.870 GMT [5948][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50337 2024-03-10 05:50:12.877 GMT [5948][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-10 05:50:13.014 GMT [1772][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50339 2024-03-10 05:50:13.019 GMT [1772][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-10 05:50:13.153 GMT [6652][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50341 2024-03-10 05:50:13.161 GMT [6652][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-10 05:50:13.161 GMT [6652][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-10 05:50:13.166 GMT [6652][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-10 05:50:13.169 GMT [6652][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50341 2024-03-10 05:50:13.329 GMT [6968][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50343 2024-03-10 05:50:13.337 GMT [6968][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-10 05:50:13.337 GMT [6968][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-10 05:50:13.340 GMT [6968][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-10 05:50:13.343 GMT [6968][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50343 2024-03-10 05:50:13.436 GMT [6536][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50345 2024-03-10 05:50:13.444 GMT [6536][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-10 05:50:13.444 GMT [6536][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-10 05:50:13.447 GMT [6536][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-10 05:50:13.450 GMT [6536][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50345 2024-03-10 05:50:13.514 GMT [7260][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50346 2024-03-10 05:50:13.522 GMT [7260][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-10 05:50:13.522 GMT [7260][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-10 05:50:13.526 GMT [7260][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-10 05:50:13.528 GMT [7260][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50346 2024-03-10 05:50:13.591 GMT [5900][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50348 2024-03-10 05:50:13.636 GMT [7900][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:13.636 GMT [7900][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:13.641 GMT [7900][postmaster] LOG: background worker "logical replication launcher" (PID 7440) exited with exit code 1 2024-03-10 05:50:13.648 GMT [5608][checkpointer] LOG: shutting down 2024-03-10 05:50:13.648 GMT [5608][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:13.652 GMT [5608][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.003 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/40C7BC0, redo lsn=0/40C7BC0 2024-03-10 05:50:13.661 GMT [7900][postmaster] LOG: database system is shut down 2024-03-10 05:50:13.818 GMT [2556][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:13.819 GMT [2556][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:13.821 GMT [2556][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:13.845 GMT [3780][startup] LOG: database system was shut down at 2024-03-10 05:50:13 GMT 2024-03-10 05:50:13.856 GMT [2556][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:14.028 GMT [3376][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50353 2024-03-10 05:50:14.035 GMT [3376][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-10 05:50:14.035 GMT [3376][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-10 05:50:14.050 GMT [3376][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-10 05:50:14.054 GMT [3376][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.039 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50353 2024-03-10 05:50:14.198 GMT [5680][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50356 2024-03-10 05:50:14.278 GMT [2556][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:14.278 GMT [2556][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:14.289 GMT [2556][postmaster] LOG: background worker "logical replication launcher" (PID 5520) exited with exit code 1 2024-03-10 05:50:14.291 GMT [7240][checkpointer] LOG: shutting down 2024-03-10 05:50:14.291 GMT [7240][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:14.295 GMT [7240][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/40C7C38, redo lsn=0/40C7C38 2024-03-10 05:50:14.303 GMT [2556][postmaster] LOG: database system is shut down 2024-03-10 05:50:14.490 GMT [1300][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:14.491 GMT [1300][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:14.492 GMT [1300][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:14.532 GMT [6576][startup] LOG: database system was shut down at 2024-03-10 05:50:14 GMT 2024-03-10 05:50:14.545 GMT [1300][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:14.653 GMT [2104][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50357 2024-03-10 05:50:14.661 GMT [2104][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-10 05:50:14.661 GMT [2104][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-10 05:50:14.676 GMT [2104][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-10 05:50:14.682 GMT [2104][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50357 2024-03-10 05:50:14.750 GMT [1300][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:14.750 GMT [1300][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:14.762 GMT [1300][postmaster] LOG: background worker "logical replication launcher" (PID 7856) exited with exit code 1 2024-03-10 05:50:14.762 GMT [2644][checkpointer] LOG: shutting down 2024-03-10 05:50:14.763 GMT [2644][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:14.767 GMT [2644][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/40C7CB0, redo lsn=0/40C7CB0 2024-03-10 05:50:14.774 GMT [1300][postmaster] LOG: database system is shut down 2024-03-10 05:50:14.924 GMT [6432][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:14.925 GMT [6432][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:14.927 GMT [6432][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:14.976 GMT [5228][startup] LOG: database system was shut down at 2024-03-10 05:50:14 GMT 2024-03-10 05:50:14.988 GMT [6432][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:15.138 GMT [5340][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50358 2024-03-10 05:50:15.146 GMT [5340][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-10 05:50:15.146 GMT [5340][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-10 05:50:15.160 GMT [5340][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-10 05:50:15.164 GMT [5340][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50358 2024-03-10 05:50:15.703 GMT [7004][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50359 2024-03-10 05:50:15.711 GMT [7004][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-10 05:50:15.711 GMT [7004][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-10 05:50:15.714 GMT [7004][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-10 05:50:15.718 GMT [7004][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50359 2024-03-10 05:50:15.968 GMT [804][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50360 2024-03-10 05:50:15.976 GMT [804][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-10 05:50:15.976 GMT [804][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-10 05:50:15.979 GMT [804][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-10 05:50:15.983 GMT [804][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50360 2024-03-10 05:50:16.077 GMT [6500][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50361 2024-03-10 05:50:16.181 GMT [5204][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50362 2024-03-10 05:50:16.264 GMT [6432][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:16.265 GMT [6432][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:16.273 GMT [6432][postmaster] LOG: background worker "logical replication launcher" (PID 4620) exited with exit code 1 2024-03-10 05:50:16.273 GMT [1776][checkpointer] LOG: shutting down 2024-03-10 05:50:16.273 GMT [1776][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:16.276 GMT [1776][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/40C7D28, redo lsn=0/40C7D28 2024-03-10 05:50:16.282 GMT [6432][postmaster] LOG: database system is shut down 2024-03-10 05:50:16.435 GMT [4028][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:16.436 GMT [4028][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:16.437 GMT [4028][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:16.459 GMT [6528][startup] LOG: database system was shut down at 2024-03-10 05:50:16 GMT 2024-03-10 05:50:16.470 GMT [4028][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:16.540 GMT [5928][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50363 2024-03-10 05:50:16.548 GMT [5928][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-10 05:50:16.548 GMT [5928][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-10 05:50:16.563 GMT [5928][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-10 05:50:16.568 GMT [5928][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50363 2024-03-10 05:50:16.653 GMT [5516][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50364 2024-03-10 05:50:16.896 GMT [3216][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50365 2024-03-10 05:50:17.170 GMT [4028][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:17.170 GMT [4028][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:17.176 GMT [4028][postmaster] LOG: background worker "logical replication launcher" (PID 6580) exited with exit code 1 2024-03-10 05:50:17.177 GMT [5084][checkpointer] LOG: shutting down 2024-03-10 05:50:17.178 GMT [5084][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:17.183 GMT [5084][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.006 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7DA0, redo lsn=0/40C7DA0 2024-03-10 05:50:17.189 GMT [4028][postmaster] LOG: database system is shut down 2024-03-10 05:50:17.343 GMT [5632][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:17.344 GMT [5632][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:17.345 GMT [5632][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:17.379 GMT [6276][startup] LOG: database system was shut down at 2024-03-10 05:50:17 GMT 2024-03-10 05:50:17.389 GMT [5632][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:17.461 GMT [6464][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50366 2024-03-10 05:50:17.469 GMT [6464][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-10 05:50:17.469 GMT [6464][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-10 05:50:17.482 GMT [6464][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-10 05:50:17.485 GMT [6464][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50366 2024-03-10 05:50:17.559 GMT [6972][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50367 2024-03-10 05:50:17.568 GMT [6972][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-10 05:50:17.568 GMT [6972][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-10 05:50:17.571 GMT [6972][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-10 05:50:17.574 GMT [6972][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50367 2024-03-10 05:50:17.668 GMT [7160][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50368 2024-03-10 05:50:17.783 GMT [5632][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:17.783 GMT [5632][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:17.788 GMT [5632][postmaster] LOG: background worker "logical replication launcher" (PID 6632) exited with exit code 1 2024-03-10 05:50:17.788 GMT [2360][checkpointer] LOG: shutting down 2024-03-10 05:50:17.788 GMT [2360][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:17.791 GMT [2360][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/40C7E18, redo lsn=0/40C7E18 2024-03-10 05:50:17.796 GMT [5632][postmaster] LOG: database system is shut down 2024-03-10 05:50:17.944 GMT [5960][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:17.945 GMT [5960][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:17.946 GMT [5960][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:17.968 GMT [6652][startup] LOG: database system was shut down at 2024-03-10 05:50:17 GMT 2024-03-10 05:50:17.976 GMT [5960][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:18.046 GMT [5504][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50369 2024-03-10 05:50:18.053 GMT [5504][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-10 05:50:18.053 GMT [5504][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-10 05:50:18.065 GMT [5504][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-10 05:50:18.068 GMT [5504][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50369 2024-03-10 05:50:18.159 GMT [1600][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50370 2024-03-10 05:50:18.167 GMT [1600][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-10 05:50:18.167 GMT [1600][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-10 05:50:18.170 GMT [1600][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-10 05:50:18.173 GMT [1600][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50370 2024-03-10 05:50:18.268 GMT [6968][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50371 2024-03-10 05:50:18.275 GMT [6968][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-10 05:50:18.275 GMT [6968][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-10 05:50:18.279 GMT [6968][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-10 05:50:18.283 GMT [6968][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50371 2024-03-10 05:50:18.346 GMT [5960][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:18.346 GMT [5960][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:18.352 GMT [5960][postmaster] LOG: background worker "logical replication launcher" (PID 1160) exited with exit code 1 2024-03-10 05:50:18.353 GMT [6388][checkpointer] LOG: shutting down 2024-03-10 05:50:18.353 GMT [6388][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:18.356 GMT [6388][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/40C7E90, redo lsn=0/40C7E90 2024-03-10 05:50:18.362 GMT [5960][postmaster] LOG: database system is shut down 2024-03-10 05:50:18.522 GMT [6304][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:18.522 GMT [6304][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:18.524 GMT [6304][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:18.544 GMT [940][startup] LOG: database system was shut down at 2024-03-10 05:50:18 GMT 2024-03-10 05:50:18.553 GMT [6304][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:18.628 GMT [2160][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50372 2024-03-10 05:50:18.636 GMT [2160][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-10 05:50:18.636 GMT [2160][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-10 05:50:18.649 GMT [2160][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-10 05:50:18.652 GMT [2160][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50372 2024-03-10 05:50:18.738 GMT [6964][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50373 2024-03-10 05:50:18.816 GMT [6304][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:18.817 GMT [6304][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:18.823 GMT [6304][postmaster] LOG: background worker "logical replication launcher" (PID 7176) exited with exit code 1 2024-03-10 05:50:18.823 GMT [4452][checkpointer] LOG: shutting down 2024-03-10 05:50:18.823 GMT [4452][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:18.826 GMT [4452][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/40C7F08, redo lsn=0/40C7F08 2024-03-10 05:50:18.831 GMT [6304][postmaster] LOG: database system is shut down 2024-03-10 05:50:18.979 GMT [7684][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:18.980 GMT [7684][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:18.981 GMT [7684][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:19.013 GMT [576][startup] LOG: database system was shut down at 2024-03-10 05:50:18 GMT 2024-03-10 05:50:19.022 GMT [7684][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:19.087 GMT [2352][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50374 2024-03-10 05:50:19.093 GMT [2352][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-10 05:50:19.256 GMT [7308][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50375 2024-03-10 05:50:19.264 GMT [7308][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-10 05:50:19.264 GMT [7308][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-10 05:50:19.277 GMT [7308][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-10 05:50:19.280 GMT [7308][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50375 2024-03-10 05:50:19.361 GMT [7696][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50376 2024-03-10 05:50:19.441 GMT [7684][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:19.442 GMT [7684][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:19.447 GMT [7684][postmaster] LOG: background worker "logical replication launcher" (PID 4240) exited with exit code 1 2024-03-10 05:50:19.448 GMT [6120][checkpointer] LOG: shutting down 2024-03-10 05:50:19.448 GMT [6120][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:19.451 GMT [6120][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/40C7F80, redo lsn=0/40C7F80 2024-03-10 05:50:19.457 GMT [7684][postmaster] LOG: database system is shut down 2024-03-10 05:50:19.602 GMT [1256][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:19.603 GMT [1256][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:19.604 GMT [1256][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:19.623 GMT [2272][startup] LOG: database system was shut down at 2024-03-10 05:50:19 GMT 2024-03-10 05:50:19.631 GMT [1256][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:19.709 GMT [6352][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50377 2024-03-10 05:50:19.716 GMT [6352][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-10 05:50:19.716 GMT [6352][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-10 05:50:19.729 GMT [6352][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-10 05:50:19.732 GMT [6352][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50377 2024-03-10 05:50:19.811 GMT [1268][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50378 2024-03-10 05:50:19.821 GMT [1268][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-10 05:50:19.929 GMT [2732][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50379 2024-03-10 05:50:19.937 GMT [2732][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-10 05:50:20.026 GMT [3744][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50380 2024-03-10 05:50:20.033 GMT [3744][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-10 05:50:20.033 GMT [3744][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-10 05:50:20.036 GMT [3744][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-10 05:50:20.042 GMT [3744][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50380 2024-03-10 05:50:20.109 GMT [2480][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50381 2024-03-10 05:50:20.117 GMT [2480][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-10 05:50:20.117 GMT [2480][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-10 05:50:20.120 GMT [2480][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-10 05:50:20.123 GMT [2480][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50381 2024-03-10 05:50:20.408 GMT [2560][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50382 2024-03-10 05:50:20.417 GMT [2560][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-10 05:50:20.520 GMT [2392][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50383 2024-03-10 05:50:20.530 GMT [2392][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-10 05:50:20.530 GMT [2392][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-10 05:50:20.545 GMT [2392][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_60AN/client.key$$ 2024-03-10 05:50:20.548 GMT [2392][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=ssltestuser database=certdb host=pg-loadbalancetest port=50383 2024-03-10 05:50:20.627 GMT [6856][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50384 2024-03-10 05:50:20.638 GMT [6856][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-10 05:50:20.638 GMT [6856][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-10 05:50:20.641 GMT [6856][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_60AN/client-der.key$$ 2024-03-10 05:50:20.644 GMT [6856][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=certdb host=pg-loadbalancetest port=50384 2024-03-10 05:50:20.739 GMT [5984][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50385 2024-03-10 05:50:20.750 GMT [5984][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-10 05:50:20.750 GMT [5984][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-10 05:50:20.753 GMT [5984][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_60AN/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-10 05:50:20.757 GMT [5984][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.026 user=ssltestuser database=certdb host=pg-loadbalancetest port=50385 2024-03-10 05:50:20.812 GMT [7836][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50386 2024-03-10 05:50:20.822 GMT [7836][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-10 05:50:20.822 GMT [7836][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-10 05:50:20.825 GMT [7836][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_60AN/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-10 05:50:20.828 GMT [7836][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50386 2024-03-10 05:50:20.927 GMT [5068][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50387 2024-03-10 05:50:20.937 GMT [5068][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-10 05:50:20.937 GMT [5068][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-10 05:50:20.941 GMT [5068][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_60AN/client.key$$ 2024-03-10 05:50:20.944 GMT [5068][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=ssltestuser database=certdb host=pg-loadbalancetest port=50387 2024-03-10 05:50:21.035 GMT [2388][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50388 2024-03-10 05:50:21.045 GMT [2388][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-10 05:50:21.045 GMT [2388][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-10 05:50:21.049 GMT [2388][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_60AN/client.key$$ 2024-03-10 05:50:21.052 GMT [2388][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=ssltestuser database=certdb host=pg-loadbalancetest port=50388 2024-03-10 05:50:21.136 GMT [5448][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50389 2024-03-10 05:50:21.143 GMT [5448][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-10 05:50:21.205 GMT [6336][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50390 2024-03-10 05:50:21.216 GMT [6336][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-10 05:50:21.277 GMT [6920][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50391 2024-03-10 05:50:21.287 GMT [6920][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-10 05:50:21.287 GMT [6920][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-10 05:50:21.301 GMT [6920][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_60AN/client-dn.key$$ 2024-03-10 05:50:21.304 GMT [6920][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50391 2024-03-10 05:50:21.379 GMT [8076][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50392 2024-03-10 05:50:21.389 GMT [8076][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-10 05:50:21.390 GMT [8076][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-10 05:50:21.403 GMT [8076][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_60AN/client-dn.key$$ 2024-03-10 05:50:21.406 GMT [8076][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50392 2024-03-10 05:50:21.471 GMT [5904][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50393 2024-03-10 05:50:21.482 GMT [5904][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-10 05:50:21.482 GMT [5904][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-10 05:50:21.496 GMT [5904][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_60AN/client-dn.key$$ 2024-03-10 05:50:21.499 GMT [5904][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.037 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50393 2024-03-10 05:50:21.590 GMT [4048][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50394 2024-03-10 05:50:21.600 GMT [4048][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-10 05:50:21.600 GMT [4048][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-10 05:50:21.603 GMT [4048][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-10 05:50:21.609 GMT [4048][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=certdb host=pg-loadbalancetest port=50394 2024-03-10 05:50:21.687 GMT [7984][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50395 2024-03-10 05:50:21.698 GMT [7984][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-10 05:50:21.698 GMT [7984][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-10 05:50:21.698 GMT [7984][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-10 05:50:21.698 GMT [7984][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-10 05:50:21.801 GMT [1896][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50396 2024-03-10 05:50:21.809 GMT [1896][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-10 05:50:21.809 GMT [1896][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-10 05:50:21.912 GMT [5020][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50397 2024-03-10 05:50:21.923 GMT [5020][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-10 05:50:21.923 GMT [5020][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-10 05:50:21.937 GMT [5020][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_60AN/client.key$$ 2024-03-10 05:50:21.941 GMT [5020][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.039 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50397 2024-03-10 05:50:22.017 GMT [7616][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50398 2024-03-10 05:50:22.027 GMT [7616][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-10 05:50:22.028 GMT [7616][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-10 05:50:22.028 GMT [7616][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-10 05:50:22.028 GMT [7616][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-10 05:50:22.127 GMT [8][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50399 2024-03-10 05:50:22.137 GMT [8][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-10 05:50:22.137 GMT [8][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-10 05:50:22.140 GMT [8][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_60AN/client.key$$ 2024-03-10 05:50:22.142 GMT [8][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50399 2024-03-10 05:50:22.194 GMT [1256][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:22.194 GMT [1256][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:22.199 GMT [1256][postmaster] LOG: background worker "logical replication launcher" (PID 824) exited with exit code 1 2024-03-10 05:50:22.200 GMT [4632][checkpointer] LOG: shutting down 2024-03-10 05:50:22.200 GMT [4632][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:22.204 GMT [4632][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/40C7FF8, redo lsn=0/40C7FF8 2024-03-10 05:50:22.209 GMT [1256][postmaster] LOG: database system is shut down 2024-03-10 05:50:22.360 GMT [6556][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:22.360 GMT [6556][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:22.362 GMT [6556][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:22.388 GMT [5672][startup] LOG: database system was shut down at 2024-03-10 05:50:22 GMT 2024-03-10 05:50:22.398 GMT [6556][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:22.461 GMT [2104][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50400 2024-03-10 05:50:22.471 GMT [2104][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-10 05:50:22.471 GMT [2104][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-10 05:50:22.484 GMT [2104][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_60AN/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-10 05:50:22.487 GMT [2104][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb host=pg-loadbalancetest port=50400 2024-03-10 05:50:22.564 GMT [3044][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50401 2024-03-10 05:50:22.573 GMT [3044][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-10 05:50:22.573 GMT [3044][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-10 05:50:22.692 GMT [4120][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50402 2024-03-10 05:50:22.701 GMT [4120][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-10 05:50:22.701 GMT [4120][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-10 05:50:22.770 GMT [6556][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:22.770 GMT [6556][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:22.776 GMT [6556][postmaster] LOG: background worker "logical replication launcher" (PID 7908) exited with exit code 1 2024-03-10 05:50:22.776 GMT [2556][checkpointer] LOG: shutting down 2024-03-10 05:50:22.776 GMT [2556][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:22.779 GMT [2556][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/40C8088, redo lsn=0/40C8088 2024-03-10 05:50:22.785 GMT [6556][postmaster] LOG: database system is shut down 2024-03-10 05:50:22.938 GMT [2408][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:22.939 GMT [2408][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:22.940 GMT [2408][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:22.962 GMT [6264][startup] LOG: database system was shut down at 2024-03-10 05:50:22 GMT 2024-03-10 05:50:22.972 GMT [2408][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:23.037 GMT [5932][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50403 2024-03-10 05:50:23.045 GMT [5932][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-10 05:50:23.045 GMT [5932][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-10 05:50:23.117 GMT [2408][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:23.117 GMT [2408][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:23.124 GMT [2408][postmaster] LOG: background worker "logical replication launcher" (PID 5776) exited with exit code 1 2024-03-10 05:50:23.125 GMT [5864][checkpointer] LOG: shutting down 2024-03-10 05:50:23.125 GMT [5864][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:23.128 GMT [5864][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/40C8100, redo lsn=0/40C8100 2024-03-10 05:50:23.134 GMT [2408][postmaster] LOG: database system is shut down 2024-03-10 05:50:23.279 GMT [6196][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:23.279 GMT [6196][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:23.280 GMT [6196][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:23.305 GMT [4684][startup] LOG: database system was shut down at 2024-03-10 05:50:23 GMT 2024-03-10 05:50:23.313 GMT [6196][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:23.379 GMT [5332][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50404 2024-03-10 05:50:23.388 GMT [5332][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-10 05:50:23.388 GMT [5332][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-10 05:50:23.484 GMT [5696][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50405 2024-03-10 05:50:23.492 GMT [5696][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-10 05:50:23.492 GMT [5696][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-10 05:50:23.568 GMT [6196][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:23.568 GMT [6196][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:23.574 GMT [6196][postmaster] LOG: background worker "logical replication launcher" (PID 3800) exited with exit code 1 2024-03-10 05:50:23.574 GMT [4376][checkpointer] LOG: shutting down 2024-03-10 05:50:23.574 GMT [4376][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:23.577 GMT [4376][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/40C8178, redo lsn=0/40C8178 2024-03-10 05:50:23.582 GMT [6196][postmaster] LOG: database system is shut down 2024-03-10 05:50:23.733 GMT [3480][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:23.734 GMT [3480][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:23.735 GMT [3480][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:23.757 GMT [4568][startup] LOG: database system was shut down at 2024-03-10 05:50:23 GMT 2024-03-10 05:50:23.765 GMT [3480][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:23.835 GMT [7444][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50406 2024-03-10 05:50:23.838 GMT [7444][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:23.839 GMT [7444][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:23.944 GMT [3472][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50407 2024-03-10 05:50:23.952 GMT [3472][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-10 05:50:23.952 GMT [3472][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-10 05:50:23.970 GMT [3472][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-10 05:50:23.973 GMT [3472][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.037 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50407 2024-03-10 05:50:24.025 GMT [3480][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:24.025 GMT [3480][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:24.031 GMT [3480][postmaster] LOG: background worker "logical replication launcher" (PID 2456) exited with exit code 1 2024-03-10 05:50:24.031 GMT [5336][checkpointer] LOG: shutting down 2024-03-10 05:50:24.031 GMT [5336][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:24.034 GMT [5336][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/40C81F0, redo lsn=0/40C81F0 2024-03-10 05:50:24.040 GMT [3480][postmaster] LOG: database system is shut down 2024-03-10 05:50:24.186 GMT [6160][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:24.186 GMT [6160][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:24.188 GMT [6160][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:24.208 GMT [5892][startup] LOG: database system was shut down at 2024-03-10 05:50:24 GMT 2024-03-10 05:50:24.216 GMT [6160][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:24.283 GMT [1660][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50409 2024-03-10 05:50:24.288 GMT [1660][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:24.288 GMT [1660][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:24.352 GMT [1036][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50410 2024-03-10 05:50:24.360 GMT [1036][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-10 05:50:24.360 GMT [1036][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-10 05:50:24.374 GMT [1036][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-10 05:50:24.378 GMT [1036][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50410 2024-03-10 05:50:24.431 GMT [6160][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:24.432 GMT [6160][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:24.437 GMT [6160][postmaster] LOG: background worker "logical replication launcher" (PID 5400) exited with exit code 1 2024-03-10 05:50:24.438 GMT [6684][checkpointer] LOG: shutting down 2024-03-10 05:50:24.438 GMT [6684][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:24.441 GMT [6684][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/40C8268, redo lsn=0/40C8268 2024-03-10 05:50:24.446 GMT [6160][postmaster] LOG: database system is shut down 2024-03-10 05:50:24.598 GMT [3840][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:24.598 GMT [3840][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:24.600 GMT [3840][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:24.625 GMT [7480][startup] LOG: database system was shut down at 2024-03-10 05:50:24 GMT 2024-03-10 05:50:24.634 GMT [3840][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:24.694 GMT [6864][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50411 2024-03-10 05:50:24.699 GMT [6864][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:24.699 GMT [6864][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:24.806 GMT [2828][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50412 2024-03-10 05:50:24.814 GMT [2828][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-10 05:50:24.814 GMT [2828][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-10 05:50:24.827 GMT [2828][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-10 05:50:24.831 GMT [2828][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50412 2024-03-10 05:50:24.887 GMT [3840][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:24.887 GMT [3840][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:24.892 GMT [3840][postmaster] LOG: background worker "logical replication launcher" (PID 5784) exited with exit code 1 2024-03-10 05:50:24.893 GMT [4052][checkpointer] LOG: shutting down 2024-03-10 05:50:24.893 GMT [4052][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:24.896 GMT [4052][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/40C82E0, redo lsn=0/40C82E0 2024-03-10 05:50:24.901 GMT [3840][postmaster] LOG: database system is shut down 2024-03-10 05:50:25.052 GMT [1016][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:25.053 GMT [1016][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:25.054 GMT [1016][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:25.075 GMT [4988][startup] LOG: database system was shut down at 2024-03-10 05:50:24 GMT 2024-03-10 05:50:25.084 GMT [1016][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:25.152 GMT [6040][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50413 2024-03-10 05:50:25.156 GMT [6040][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:25.156 GMT [6040][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:25.261 GMT [1072][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50414 2024-03-10 05:50:25.269 GMT [1072][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-10 05:50:25.269 GMT [1072][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-10 05:50:25.281 GMT [1072][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-10 05:50:25.285 GMT [1072][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50414 2024-03-10 05:50:25.348 GMT [1016][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:25.348 GMT [1016][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:25.354 GMT [1016][postmaster] LOG: background worker "logical replication launcher" (PID 4612) exited with exit code 1 2024-03-10 05:50:25.355 GMT [2428][checkpointer] LOG: shutting down 2024-03-10 05:50:25.355 GMT [2428][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:25.358 GMT [2428][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/40C8358, redo lsn=0/40C8358 2024-03-10 05:50:25.363 GMT [1016][postmaster] LOG: database system is shut down 2024-03-10 05:50:25.516 GMT [7328][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:25.516 GMT [7328][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:25.518 GMT [7328][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:25.548 GMT [5856][startup] LOG: database system was shut down at 2024-03-10 05:50:25 GMT 2024-03-10 05:50:25.557 GMT [7328][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:25.626 GMT [5432][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50415 2024-03-10 05:50:25.630 GMT [5432][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:25.630 GMT [5432][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:25.730 GMT [1524][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50416 2024-03-10 05:50:25.738 GMT [1524][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-10 05:50:25.738 GMT [1524][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-10 05:50:25.753 GMT [1524][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-10 05:50:25.757 GMT [1524][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50416 2024-03-10 05:50:25.793 GMT [7328][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:25.793 GMT [7328][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:25.798 GMT [7328][postmaster] LOG: background worker "logical replication launcher" (PID 1180) exited with exit code 1 2024-03-10 05:50:25.799 GMT [7560][checkpointer] LOG: shutting down 2024-03-10 05:50:25.799 GMT [7560][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:25.802 GMT [7560][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/40C83D0, redo lsn=0/40C83D0 2024-03-10 05:50:25.808 GMT [7328][postmaster] LOG: database system is shut down 2024-03-10 05:50:25.958 GMT [7988][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:25.958 GMT [7988][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:25.960 GMT [7988][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:25.987 GMT [6208][startup] LOG: database system was shut down at 2024-03-10 05:50:25 GMT 2024-03-10 05:50:25.997 GMT [7988][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:26.065 GMT [6960][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50417 2024-03-10 05:50:26.069 GMT [6960][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:26.070 GMT [6960][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:26.164 GMT [6712][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50418 2024-03-10 05:50:26.171 GMT [6712][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-10 05:50:26.171 GMT [6712][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-10 05:50:26.184 GMT [6712][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-10 05:50:26.188 GMT [6712][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50418 2024-03-10 05:50:26.244 GMT [7988][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:26.245 GMT [7988][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:26.250 GMT [7988][postmaster] LOG: background worker "logical replication launcher" (PID 4156) exited with exit code 1 2024-03-10 05:50:26.250 GMT [7520][checkpointer] LOG: shutting down 2024-03-10 05:50:26.251 GMT [7520][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:26.253 GMT [7520][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/40C8448, redo lsn=0/40C8448 2024-03-10 05:50:26.258 GMT [7988][postmaster] LOG: database system is shut down 2024-03-10 05:50:26.411 GMT [8120][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:26.412 GMT [8120][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:26.413 GMT [8120][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:26.453 GMT [3432][startup] LOG: database system was shut down at 2024-03-10 05:50:26 GMT 2024-03-10 05:50:26.461 GMT [8120][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:26.524 GMT [2740][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50419 2024-03-10 05:50:26.528 GMT [2740][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:26.528 GMT [2740][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:26.584 GMT [7272][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50420 2024-03-10 05:50:26.592 GMT [7272][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-10 05:50:26.592 GMT [7272][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-10 05:50:26.604 GMT [7272][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-10 05:50:26.607 GMT [7272][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50420 2024-03-10 05:50:26.668 GMT [8120][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:26.669 GMT [8120][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:26.673 GMT [8120][postmaster] LOG: background worker "logical replication launcher" (PID 7880) exited with exit code 1 2024-03-10 05:50:26.674 GMT [2876][checkpointer] LOG: shutting down 2024-03-10 05:50:26.674 GMT [2876][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:26.677 GMT [2876][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/40C84C0, redo lsn=0/40C84C0 2024-03-10 05:50:26.682 GMT [8120][postmaster] LOG: database system is shut down 2024-03-10 05:50:26.834 GMT [7216][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:26.834 GMT [7216][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:26.836 GMT [7216][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:26.861 GMT [7428][startup] LOG: database system was shut down at 2024-03-10 05:50:26 GMT 2024-03-10 05:50:26.870 GMT [7216][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:26.938 GMT [4084][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50421 2024-03-10 05:50:26.942 GMT [4084][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:26.942 GMT [4084][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:27.044 GMT [6744][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50422 2024-03-10 05:50:27.052 GMT [6744][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-10 05:50:27.052 GMT [6744][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-10 05:50:27.065 GMT [6744][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-10 05:50:27.068 GMT [6744][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50422 2024-03-10 05:50:27.118 GMT [7216][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:27.119 GMT [7216][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:27.123 GMT [7216][postmaster] LOG: background worker "logical replication launcher" (PID 4388) exited with exit code 1 2024-03-10 05:50:27.124 GMT [3564][checkpointer] LOG: shutting down 2024-03-10 05:50:27.124 GMT [3564][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:27.126 GMT [3564][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/40C8538, redo lsn=0/40C8538 2024-03-10 05:50:27.131 GMT [7216][postmaster] LOG: database system is shut down 2024-03-10 05:50:27.288 GMT [5604][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-10 05:50:27.289 GMT [5604][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 53182 2024-03-10 05:50:27.290 GMT [5604][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/sU9hyzVm_r/.s.PGSQL.53182" 2024-03-10 05:50:27.314 GMT [1620][startup] LOG: database system was shut down at 2024-03-10 05:50:27 GMT 2024-03-10 05:50:27.323 GMT [5604][postmaster] LOG: database system is ready to accept connections 2024-03-10 05:50:27.406 GMT [5360][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50423 2024-03-10 05:50:27.410 GMT [5360][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-10 05:50:27.411 GMT [5360][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-10 05:50:27.479 GMT [3068][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50424 2024-03-10 05:50:27.486 GMT [3068][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-10 05:50:27.486 GMT [3068][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-10 05:50:27.499 GMT [3068][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-10 05:50:27.502 GMT [3068][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50424 2024-03-10 05:50:27.542 GMT [5604][postmaster] LOG: received fast shutdown request 2024-03-10 05:50:27.543 GMT [5604][postmaster] LOG: aborting any active transactions 2024-03-10 05:50:27.555 GMT [5604][postmaster] LOG: background worker "logical replication launcher" (PID 5396) exited with exit code 1 2024-03-10 05:50:27.555 GMT [5544][checkpointer] LOG: shutting down 2024-03-10 05:50:27.555 GMT [5544][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-10 05:50:27.558 GMT [5544][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/40C85B0, redo lsn=0/40C85B0 2024-03-10 05:50:27.566 GMT [5604][postmaster] LOG: database system is shut down 2024-03-10 05:50:27.710 GMT [3004][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-10 05:50:27.710 GMT [3004][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:50:27.759](0.233s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"