[05:18:35.518](0.290s) # setting up data directory # Checking port 56367 # Found port 56367 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=56367 host=C:/Windows/TEMP/WvWF_zFc96 Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log [05:18:35.645](0.127s) # 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 4012 [05:18:38.015](2.370s) 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 4268 [05:18:43.239](5.224s) # 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-28 05:18:37.578 GMT [4012][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:37.579 GMT [4012][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:37.672 GMT [7324][startup] LOG: database system was shut down at 2024-03-28 05:07:39 GMT 2024-03-28 05:18:37.705 GMT [4012][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:37.902 GMT [444][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:37.903 GMT [444][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-28 05:18:37.904 GMT [444][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:37.919 GMT [444][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-28 05:18:37.922 GMT [444][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.078 GMT [6072][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.080 GMT [6072][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-28 05:18:38.080 GMT [6072][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.083 GMT [6072][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-28 05:18:38.084 GMT [6072][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.171 GMT [4180][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.172 GMT [4180][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-28 05:18:38.172 GMT [4180][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.176 GMT [4180][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-28 05:18:38.177 GMT [4180][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.309 GMT [956][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.310 GMT [956][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-28 05:18:38.310 GMT [956][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.313 GMT [956][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-28 05:18:38.314 GMT [956][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.438 GMT [7848][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.440 GMT [7848][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-28 05:18:38.440 GMT [7848][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.444 GMT [7848][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-28 05:18:38.445 GMT [7848][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.559 GMT [2772][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.561 GMT [2772][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-28 05:18:38.561 GMT [2772][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.563 GMT [2772][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-28 05:18:38.922 GMT [2772][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.366 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:39.165 GMT [4432][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:39.168 GMT [4432][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-28 05:18:39.168 GMT [4432][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:39.172 GMT [4432][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-28 05:18:39.610 GMT [4432][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.465 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.039 GMT [5940][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.041 GMT [5940][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-28 05:18:40.041 GMT [5940][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.044 GMT [5940][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-28 05:18:40.375 GMT [5940][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.341 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.460 GMT [5932][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.462 GMT [5932][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-28 05:18:40.462 GMT [5932][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.464 GMT [5932][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-28 05:18:40.816 GMT [5932][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.358 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.888 GMT [3268][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.890 GMT [3268][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-28 05:18:40.890 GMT [3268][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.894 GMT [3268][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-28 05:18:41.406 GMT [3268][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.522 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:41.657 GMT [6468][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:41.658 GMT [6468][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-28 05:18:41.658 GMT [6468][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:41.662 GMT [6468][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-28 05:18:42.043 GMT [6468][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.389 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:42.432 GMT [4012][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:42.432 GMT [4012][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:42.446 GMT [4012][postmaster] LOG: background worker "logical replication launcher" (PID 868) exited with exit code 1 2024-03-28 05:18:42.451 GMT [1760][checkpointer] LOG: shutting down 2024-03-28 05:18:42.451 GMT [1760][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:42.664 GMT [1760][checkpointer] LOG: checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.209 s, sync=0.001 s, total=0.214 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407DC60, redo lsn=0/407DC60 2024-03-28 05:18:42.781 GMT [4012][postmaster] LOG: database system is shut down 2024-03-28 05:18:43.081 GMT [4268][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:43.085 GMT [4268][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:43.099 GMT [4268][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:43.132 GMT [988][startup] LOG: database system was shut down at 2024-03-28 05:18:42 GMT 2024-03-28 05:18:43.188 GMT [4268][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:43.266 GMT [4268][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:43.267 GMT [4268][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:43.292 GMT [4268][postmaster] LOG: background worker "logical replication launcher" (PID 6464) exited with exit code 1 2024-03-28 05:18:43.300 GMT [3948][checkpointer] LOG: shutting down 2024-03-28 05:18:43.301 GMT [3948][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:43.318 GMT [3948][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.018 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407DCD8, redo lsn=0/407DCD8 2024-03-28 05:18:43.334 GMT [4268][postmaster] LOG: database system is shut down 2024-03-28 05:18:44.102 GMT [1744][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-28 05:18:44.103 GMT [1744][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:18:44.196](0.957s) 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 5760 [05:18:44.697](0.501s) 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-28 05:18:37.578 GMT [4012][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:37.579 GMT [4012][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:37.672 GMT [7324][startup] LOG: database system was shut down at 2024-03-28 05:07:39 GMT 2024-03-28 05:18:37.705 GMT [4012][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:37.902 GMT [444][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:37.903 GMT [444][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-28 05:18:37.904 GMT [444][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:37.919 GMT [444][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-28 05:18:37.922 GMT [444][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.078 GMT [6072][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.080 GMT [6072][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-28 05:18:38.080 GMT [6072][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.083 GMT [6072][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-28 05:18:38.084 GMT [6072][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.171 GMT [4180][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.172 GMT [4180][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-28 05:18:38.172 GMT [4180][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.176 GMT [4180][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-28 05:18:38.177 GMT [4180][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.309 GMT [956][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.310 GMT [956][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-28 05:18:38.310 GMT [956][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.313 GMT [956][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-28 05:18:38.314 GMT [956][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.438 GMT [7848][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.440 GMT [7848][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-28 05:18:38.440 GMT [7848][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.444 GMT [7848][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-28 05:18:38.445 GMT [7848][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.559 GMT [2772][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.561 GMT [2772][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-28 05:18:38.561 GMT [2772][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.563 GMT [2772][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-28 05:18:38.922 GMT [2772][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.366 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:39.165 GMT [4432][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:39.168 GMT [4432][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-28 05:18:39.168 GMT [4432][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:39.172 GMT [4432][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-28 05:18:39.610 GMT [4432][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.465 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.039 GMT [5940][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.041 GMT [5940][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-28 05:18:40.041 GMT [5940][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.044 GMT [5940][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-28 05:18:40.375 GMT [5940][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.341 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.460 GMT [5932][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.462 GMT [5932][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-28 05:18:40.462 GMT [5932][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.464 GMT [5932][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-28 05:18:40.816 GMT [5932][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.358 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.888 GMT [3268][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.890 GMT [3268][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-28 05:18:40.890 GMT [3268][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.894 GMT [3268][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-28 05:18:41.406 GMT [3268][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.522 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:41.657 GMT [6468][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:41.658 GMT [6468][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-28 05:18:41.658 GMT [6468][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:41.662 GMT [6468][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-28 05:18:42.043 GMT [6468][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.389 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:42.432 GMT [4012][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:42.432 GMT [4012][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:42.446 GMT [4012][postmaster] LOG: background worker "logical replication launcher" (PID 868) exited with exit code 1 2024-03-28 05:18:42.451 GMT [1760][checkpointer] LOG: shutting down 2024-03-28 05:18:42.451 GMT [1760][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:42.664 GMT [1760][checkpointer] LOG: checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.209 s, sync=0.001 s, total=0.214 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407DC60, redo lsn=0/407DC60 2024-03-28 05:18:42.781 GMT [4012][postmaster] LOG: database system is shut down 2024-03-28 05:18:43.081 GMT [4268][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:43.085 GMT [4268][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:43.099 GMT [4268][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:43.132 GMT [988][startup] LOG: database system was shut down at 2024-03-28 05:18:42 GMT 2024-03-28 05:18:43.188 GMT [4268][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:43.266 GMT [4268][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:43.267 GMT [4268][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:43.292 GMT [4268][postmaster] LOG: background worker "logical replication launcher" (PID 6464) exited with exit code 1 2024-03-28 05:18:43.300 GMT [3948][checkpointer] LOG: shutting down 2024-03-28 05:18:43.301 GMT [3948][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:43.318 GMT [3948][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.018 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407DCD8, redo lsn=0/407DCD8 2024-03-28 05:18:43.334 GMT [4268][postmaster] LOG: database system is shut down 2024-03-28 05:18:44.102 GMT [1744][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-28 05:18:44.103 GMT [1744][postmaster] LOG: database system is shut down 2024-03-28 05:18:44.542 GMT [5760][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:44.542 GMT [5760][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:44.544 GMT [5760][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:44.607 GMT [4340][startup] LOG: database system was shut down at 2024-03-28 05:18:43 GMT 2024-03-28 05:18:44.618 GMT [5760][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:44.732 GMT [5760][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:44.732 GMT [5760][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:44.743 GMT [5760][postmaster] LOG: background worker "logical replication launcher" (PID 4156) exited with exit code 1 2024-03-28 05:18:44.748 GMT [8156][checkpointer] LOG: shutting down 2024-03-28 05:18:44.749 GMT [8156][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:44.752 GMT [8156][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/407DD50, redo lsn=0/407DD50 2024-03-28 05:18:44.759 GMT [5760][postmaster] LOG: database system is shut down 2024-03-28 05:18:44.945 GMT [7696][postmaster] FATAL: could not set SSL protocol version range 2024-03-28 05:18:44.945 GMT [7696][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-28 05:18:44.945 GMT [7696][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:18:45.049](0.352s) 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 4152 [05:18:45.292](0.244s) ok 5 - restart succeeds with correct SSL protocol bounds [05:18:45.293](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 7720 [05:18:45.730](0.437s) ok 6 - server doesn't accept non-SSL connections [05:18:45.730](0.000s) ok 7 - server doesn't accept non-SSL connections: matches [05:18:45.855](0.125s) ok 8 - connect without server root cert sslmode=require [05:18:45.855](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr [05:18:45.962](0.107s) ok 10 - connect without server root cert sslmode=verify-ca [05:18:45.962](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches [05:18:46.072](0.110s) ok 12 - connect without server root cert sslmode=verify-full [05:18:46.072](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches [05:18:46.180](0.108s) ok 14 - connect with wrong server root cert sslmode=require [05:18:46.180](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches [05:18:46.266](0.086s) ok 16 - connect with wrong server root cert sslmode=verify-ca [05:18:46.266](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [05:18:46.354](0.087s) ok 18 - connect with wrong server root cert sslmode=verify-full [05:18:46.354](0.001s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [05:18:46.433](0.079s) ok 20 - connect with server CA cert, without root CA [05:18:46.433](0.000s) ok 21 - connect with server CA cert, without root CA: matches [05:18:46.528](0.095s) ok 22 - connect with correct server CA cert file sslmode=require [05:18:46.528](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [05:18:46.604](0.076s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [05:18:46.604](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [05:18:46.736](0.132s) ok 26 - connect with correct server CA cert file sslmode=verify-full [05:18:46.737](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [05:18:46.830](0.093s) ok 28 - cert root file that contains two certificates, order 1 [05:18:46.830](0.001s) ok 29 - cert root file that contains two certificates, order 1: no stderr [05:18:47.011](0.181s) ok 30 - cert root file that contains two certificates, order 2 [05:18:47.012](0.001s) ok 31 - cert root file that contains two certificates, order 2: no stderr [05:18:47.135](0.123s) ok 32 - connect with sslcertmode=disable [05:18:47.135](0.001s) ok 33 - connect with sslcertmode=disable: no stderr [05:18:47.235](0.099s) ok 34 - connect with sslcertmode=allow [05:18:47.235](0.000s) ok 35 - connect with sslcertmode=allow: no stderr [05:18:47.343](0.108s) ok 36 - connect with sslcertmode=require fails without a client certificate [05:18:47.343](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [05:18:47.511](0.168s) ok 38 - sslcrl option with invalid file name [05:18:47.512](0.001s) ok 39 - sslcrl option with invalid file name: no stderr [05:18:47.643](0.132s) ok 40 - CRL belonging to a different CA [05:18:47.644](0.000s) ok 41 - CRL belonging to a different CA: matches [05:18:47.777](0.134s) ok 42 - directory CRL belonging to a different CA [05:18:47.778](0.000s) ok 43 - directory CRL belonging to a different CA: matches [05:18:47.938](0.160s) ok 44 - CRL with a non-revoked cert [05:18:47.938](0.000s) ok 45 - CRL with a non-revoked cert: no stderr [05:18:48.075](0.136s) ok 46 - directory CRL with a non-revoked cert [05:18:48.075](0.001s) ok 47 - directory CRL with a non-revoked cert: no stderr [05:18:48.154](0.079s) ok 48 - mismatch between host name and server certificate sslmode=require [05:18:48.154](0.001s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [05:18:48.261](0.107s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [05:18:48.262](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [05:18:48.412](0.150s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [05:18:48.415](0.003s) 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 4984 [05:18:48.765](0.350s) ok 54 - IP address in the Common Name [05:18:48.765](0.000s) ok 55 - IP address in the Common Name: no stderr [05:18:48.874](0.109s) ok 56 - mismatch between host name and server certificate IP address [05:18:48.874](0.000s) ok 57 - mismatch between host name and server certificate IP address: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart waiting for server to shut down.... done server stopped waiting for server to start.... done server started # Postmaster PID for node "primary" is 4892 [05:18:49.218](0.343s) ok 58 - IP address in a dNSName [05:18:49.218](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 6940 [05:18:49.564](0.346s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [05:18:49.565](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [05:18:49.673](0.108s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [05:18:49.673](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [05:18:49.783](0.109s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [05:18:49.783](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [05:18:49.893](0.110s) ok 66 - host name not matching with X.509 Subject Alternative Names [05:18:49.893](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [05:18:50.001](0.108s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [05:18:50.001](0.000s) ok 69 - host name not matching with X.509 Subject Alternative Names wildcard: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart waiting for server to shut down.... done server stopped waiting for server to start.... done server started # Postmaster PID for node "primary" is 6480 [05:18:50.346](0.344s) ok 70 - host name matching with a single X.509 Subject Alternative Name [05:18:50.346](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [05:18:50.407](0.061s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [05:18:50.408](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [05:18:50.470](0.062s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [05:18:50.470](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches [05:18:50.500](0.030s) 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 5940 [05:18:50.845](0.345s) ok 77 - certificate with both a CN and SANs 1 [05:18:50.846](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr [05:18:50.965](0.120s) ok 79 - certificate with both a CN and SANs 2 [05:18:50.966](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr [05:18:51.032](0.066s) ok 81 - certificate with both a CN and SANs ignores CN [05:18:51.032](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches [05:18:51.069](0.036s) 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 7016 [05:18:51.408](0.339s) ok 84 - certificate with both an IP CN and DNS SANs matches CN [05:18:51.408](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr [05:18:51.471](0.063s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1 [05:18:51.471](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [05:18:51.582](0.111s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2 [05:18:51.583](0.001s) ok 89 - certificate with both an IP CN and DNS SANs matches SAN 2: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart waiting for server to shut down.... done server stopped waiting for server to start.... done server started # Postmaster PID for node "primary" is 8056 [05:18:51.924](0.341s) ok 90 - server certificate without CN or SANs sslmode=verify-ca [05:18:51.924](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr [05:18:52.032](0.108s) ok 92 - server certificate without CN or SANs sslmode=verify-full [05:18:52.032](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 2300 [05:18:52.376](0.344s) ok 94 - sslrootcert=system does not connect with private CA [05:18:52.376](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches [05:18:52.439](0.063s) ok 96 - sslrootcert=system only accepts sslmode=verify-full [05:18:52.440](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches [05:18:52.550](0.111s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE [05:18:52.551](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [05:18:52.658](0.107s) ok 100 - sslrootcert=system defaults to sslmode=verify-full [05:18:52.658](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 7504 [05:18:53.127](0.468s) ok 102 - connects without client-side CRL [05:18:53.127](0.000s) ok 103 - connects without client-side CRL: no stderr [05:18:53.236](0.109s) ok 104 - does not connect with client-side CRL file [05:18:53.237](0.001s) ok 105 - does not connect with client-side CRL file: matches [05:18:53.346](0.110s) ok 106 - does not connect with client-side CRL directory [05:18:53.347](0.001s) 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:18:53.409](0.062s) ok 108 - pg_stat_ssl view without client certificate: exit code 0 [05:18:53.409](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr [05:18:53.409](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches [05:18:53.519](0.109s) ok 111 - connection success with correct range of TLS protocol versions [05:18:53.519](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr [05:18:53.581](0.062s) ok 113 - connection failure with incorrect range of TLS protocol versions [05:18:53.581](0.001s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches [05:18:53.644](0.063s) ok 115 - connection failure with an incorrect SSL protocol minimum bound [05:18:53.645](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches [05:18:53.708](0.063s) ok 117 - connection failure with an incorrect SSL protocol maximum bound [05:18:53.708](0.001s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches [05:18:53.709](0.000s) # running server tests [05:18:53.771](0.063s) ok 119 - certificate authorization fails without client cert [05:18:53.771](0.000s) ok 120 - certificate authorization fails without client cert: matches [05:18:53.895](0.124s) ok 121 - certificate authorization succeeds with correct client cert in PEM format [05:18:53.896](0.001s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr [05:18:54.004](0.108s) ok 123 - certificate authorization succeeds with correct client cert in DER format [05:18:54.004](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr [05:18:54.067](0.062s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format [05:18:54.067](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [05:18:54.129](0.062s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format [05:18:54.130](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [05:18:54.238](0.109s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require [05:18:54.238](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [05:18:54.304](0.066s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow [05:18:54.304](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [05:18:54.412](0.108s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable [05:18:54.413](0.001s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [05:18:54.476](0.063s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [05:18:54.476](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [05:18:54.583](0.107s) ok 137 - certificate authorization succeeds with DN mapping [05:18:54.583](0.000s) ok 138 - certificate authorization succeeds with DN mapping: no stderr [05:18:54.584](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches [05:18:54.709](0.125s) ok 140 - certificate authorization succeeds with DN regex mapping [05:18:54.709](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr [05:18:54.817](0.108s) ok 142 - certificate authorization succeeds with CN mapping [05:18:54.818](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr [05:18:54.818](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches [05:18:54.818](0.000s) not ok 145 # TODO & SKIP Need Pty support [05:18:54.819](0.000s) not ok 146 # TODO & SKIP Need Pty support [05:18:54.819](0.000s) not ok 147 # TODO & SKIP Need Pty support [05:18:54.819](0.001s) 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_U38K/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [05:18:54.894](0.075s) ok 149 - pg_stat_ssl with client certificate: exit code 0 [05:18:54.895](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr [05:18:54.895](0.001s) ok 151 - pg_stat_ssl with client certificate: matches [05:18:54.896](0.000s) ok 152 # skip Permissions check not enforced on Windows [05:18:54.896](0.001s) ok 153 # skip Permissions check not enforced on Windows [05:18:55.006](0.110s) ok 154 - certificate authorization fails with client cert belonging to another user [05:18:55.006](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches [05:18:55.113](0.107s) ok 156 - certificate authorization fails with revoked client cert [05:18:55.114](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches [05:18:55.114](0.000s) ok 158 - certificate authorization fails with revoked client cert: log does not match [05:18:55.234](0.120s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name [05:18:55.234](0.000s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [05:18:55.234](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [05:18:55.302](0.067s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name [05:18:55.302](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [05:18:55.302](0.000s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [05:18:55.381](0.078s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [05:18:55.381](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [05:18:55.382](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 1292 [05:18:55.725](0.344s) ok 168 - intermediate client certificate is provided by client [05:18:55.726](0.001s) ok 169 - intermediate client certificate is provided by client: no stderr [05:18:55.834](0.109s) ok 170 - intermediate client certificate is missing [05:18:55.835](0.000s) ok 171 - intermediate client certificate is missing: matches [05:18:55.943](0.109s) ok 172 - logged client certificate Subjects are truncated if they're too long [05:18:55.943](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 5948 [05:18:56.288](0.344s) ok 174 - intermediate client certificate is untrusted [05:18:56.288](0.001s) 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 7236 [05:18:56.631](0.342s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory [05:18:56.631](0.001s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [05:18:56.758](0.127s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [05:18:56.758](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 6184 [05:18:57.113](0.355s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1 [05:18:57.114](0.001s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923. [05:18:57.114](0.000s) # got: '2' # expected: '0' [05:18:57.115](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [05:18:57.115](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:18:57.115](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 56367 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:18:57.225](0.110s) ok 182 - connect without requesting ocsp response when sslocspstapling=0 [05:18:57.226](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 6068 [05:18:57.571](0.346s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1 [05:18:57.680](0.108s) ok 185 - connect without requesting ocsp response when sslocspstapling=0 [05:18:57.680](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 1748 [05:18:57.975](0.296s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1 [05:18:58.085](0.109s) ok 188 - connect without requesting ocsp response when sslocspstapling=0 [05:18:58.085](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 2852 [05:18:58.382](0.297s) ok 190 - failed with an expired ocsp response when sslocspstapling=1 [05:18:58.491](0.109s) ok 191 - connect without requesting ocsp response when sslocspstapling=0 [05:18:58.491](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 4552 [05:18:58.836](0.345s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1 [05:18:58.836](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001. [05:18:58.836](0.000s) # got: '2' # expected: '0' [05:18:58.837](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [05:18:58.837](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:18:58.837](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 56367 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:18:58.947](0.110s) ok 195 - connect without requesting ocsp response when sslocspstapling=0 [05:18:58.947](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 5292 [05:18:59.245](0.298s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1 [05:18:59.356](0.112s) ok 198 - connect without requesting ocsp response when sslocspstapling=0 [05:18:59.357](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 5348 [05:18:59.702](0.345s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1 [05:18:59.809](0.107s) ok 201 - connect without requesting ocsp response when sslocspstapling=0 [05:18:59.809](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 1240 [05:19:00.152](0.343s) ok 203 - failed with an expired ocsp response when sslocspstapling=1 [05:19:00.261](0.110s) ok 204 - connect without requesting ocsp response when sslocspstapling=0 [05:19:00.262](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 6328 [05:19:00.606](0.344s) ok 206 - failed with an expired ocsp response when sslocspstapling=1 [05:19:00.715](0.109s) ok 207 - connect without requesting ocsp response when sslocspstapling=0 [05:19:00.715](0.000s) ok 208 - connect without requesting ocsp response when sslocspstapling=0: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart waiting for server to shut down.... done server stopped waiting for server to start.... stopped waiting pg_ctl: could not start server Examine the log output. # pg_ctl restart failed; logfile: 2024-03-28 05:18:37.578 GMT [4012][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:37.579 GMT [4012][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:37.672 GMT [7324][startup] LOG: database system was shut down at 2024-03-28 05:07:39 GMT 2024-03-28 05:18:37.705 GMT [4012][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:37.902 GMT [444][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:37.903 GMT [444][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-28 05:18:37.904 GMT [444][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:37.919 GMT [444][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-28 05:18:37.922 GMT [444][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.078 GMT [6072][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.080 GMT [6072][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-28 05:18:38.080 GMT [6072][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.083 GMT [6072][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-28 05:18:38.084 GMT [6072][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.010 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.171 GMT [4180][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.172 GMT [4180][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-28 05:18:38.172 GMT [4180][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.176 GMT [4180][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-28 05:18:38.177 GMT [4180][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.309 GMT [956][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.310 GMT [956][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-28 05:18:38.310 GMT [956][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.313 GMT [956][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-28 05:18:38.314 GMT [956][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.438 GMT [7848][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.440 GMT [7848][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-28 05:18:38.440 GMT [7848][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.444 GMT [7848][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-28 05:18:38.445 GMT [7848][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.009 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:38.559 GMT [2772][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:38.561 GMT [2772][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-28 05:18:38.561 GMT [2772][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:38.563 GMT [2772][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-28 05:18:38.922 GMT [2772][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.366 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:39.165 GMT [4432][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:39.168 GMT [4432][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-28 05:18:39.168 GMT [4432][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:39.172 GMT [4432][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-28 05:18:39.610 GMT [4432][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.465 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.039 GMT [5940][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.041 GMT [5940][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-28 05:18:40.041 GMT [5940][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.044 GMT [5940][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-28 05:18:40.375 GMT [5940][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.341 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.460 GMT [5932][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.462 GMT [5932][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-28 05:18:40.462 GMT [5932][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.464 GMT [5932][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-28 05:18:40.816 GMT [5932][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.358 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:40.888 GMT [3268][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:40.890 GMT [3268][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-28 05:18:40.890 GMT [3268][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:40.894 GMT [3268][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-28 05:18:41.406 GMT [3268][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.522 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:41.657 GMT [6468][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-28 05:18:41.658 GMT [6468][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-28 05:18:41.658 GMT [6468][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-28 05:18:41.662 GMT [6468][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-28 05:18:42.043 GMT [6468][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.389 user=SYSTEM database=postgres host=[local] 2024-03-28 05:18:42.432 GMT [4012][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:42.432 GMT [4012][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:42.446 GMT [4012][postmaster] LOG: background worker "logical replication launcher" (PID 868) exited with exit code 1 2024-03-28 05:18:42.451 GMT [1760][checkpointer] LOG: shutting down 2024-03-28 05:18:42.451 GMT [1760][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:42.664 GMT [1760][checkpointer] LOG: checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.209 s, sync=0.001 s, total=0.214 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407DC60, redo lsn=0/407DC60 2024-03-28 05:18:42.781 GMT [4012][postmaster] LOG: database system is shut down 2024-03-28 05:18:43.081 GMT [4268][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:43.085 GMT [4268][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:43.099 GMT [4268][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:43.132 GMT [988][startup] LOG: database system was shut down at 2024-03-28 05:18:42 GMT 2024-03-28 05:18:43.188 GMT [4268][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:43.266 GMT [4268][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:43.267 GMT [4268][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:43.292 GMT [4268][postmaster] LOG: background worker "logical replication launcher" (PID 6464) exited with exit code 1 2024-03-28 05:18:43.300 GMT [3948][checkpointer] LOG: shutting down 2024-03-28 05:18:43.301 GMT [3948][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:43.318 GMT [3948][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.018 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407DCD8, redo lsn=0/407DCD8 2024-03-28 05:18:43.334 GMT [4268][postmaster] LOG: database system is shut down 2024-03-28 05:18:44.102 GMT [1744][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-28 05:18:44.103 GMT [1744][postmaster] LOG: database system is shut down 2024-03-28 05:18:44.542 GMT [5760][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:44.542 GMT [5760][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:44.544 GMT [5760][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:44.607 GMT [4340][startup] LOG: database system was shut down at 2024-03-28 05:18:43 GMT 2024-03-28 05:18:44.618 GMT [5760][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:44.732 GMT [5760][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:44.732 GMT [5760][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:44.743 GMT [5760][postmaster] LOG: background worker "logical replication launcher" (PID 4156) exited with exit code 1 2024-03-28 05:18:44.748 GMT [8156][checkpointer] LOG: shutting down 2024-03-28 05:18:44.749 GMT [8156][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:44.752 GMT [8156][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/407DD50, redo lsn=0/407DD50 2024-03-28 05:18:44.759 GMT [5760][postmaster] LOG: database system is shut down 2024-03-28 05:18:44.945 GMT [7696][postmaster] FATAL: could not set SSL protocol version range 2024-03-28 05:18:44.945 GMT [7696][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-28 05:18:44.945 GMT [7696][postmaster] LOG: database system is shut down 2024-03-28 05:18:45.148 GMT [4152][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:45.149 GMT [4152][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:45.150 GMT [4152][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:45.177 GMT [3408][startup] LOG: database system was shut down at 2024-03-28 05:18:44 GMT 2024-03-28 05:18:45.188 GMT [4152][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:45.312 GMT [4152][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:45.312 GMT [4152][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:45.320 GMT [4152][postmaster] LOG: background worker "logical replication launcher" (PID 4860) exited with exit code 1 2024-03-28 05:18:45.320 GMT [5676][checkpointer] LOG: shutting down 2024-03-28 05:18:45.320 GMT [5676][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:45.323 GMT [5676][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/407DDC8, redo lsn=0/407DDC8 2024-03-28 05:18:45.331 GMT [4152][postmaster] LOG: database system is shut down 2024-03-28 05:18:45.490 GMT [7720][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:45.492 GMT [7720][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:45.495 GMT [7720][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:45.529 GMT [5360][startup] LOG: database system was shut down at 2024-03-28 05:18:45 GMT 2024-03-28 05:18:45.559 GMT [7720][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:45.705 GMT [2328][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50404 2024-03-28 05:18:45.706 GMT [2328][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-28 05:18:45.706 GMT [2328][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "pg-loadbalancetest", forward lookup not checked. 2024-03-28 05:18:45.779 GMT [5424][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50406 2024-03-28 05:18:45.786 GMT [5424][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-28 05:18:45.786 GMT [5424][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-28 05:18:45.801 GMT [5424][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-28 05:18:45.803 GMT [5424][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50406 2024-03-28 05:18:45.913 GMT [4780][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50409 2024-03-28 05:18:45.929 GMT [4780][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:18:46.012 GMT [2936][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50412 2024-03-28 05:18:46.026 GMT [2936][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:18:46.127 GMT [7416][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50415 2024-03-28 05:18:46.133 GMT [7416][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:18:46.229 GMT [7300][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50416 2024-03-28 05:18:46.235 GMT [7300][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:18:46.334 GMT [3204][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50418 2024-03-28 05:18:46.340 GMT [3204][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:18:46.406 GMT [6188][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50420 2024-03-28 05:18:46.412 GMT [6188][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:18:46.494 GMT [6160][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50423 2024-03-28 05:18:46.502 GMT [6160][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-28 05:18:46.502 GMT [6160][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-28 05:18:46.505 GMT [6160][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-28 05:18:46.508 GMT [6160][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50423 2024-03-28 05:18:46.586 GMT [1932][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50424 2024-03-28 05:18:46.593 GMT [1932][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-28 05:18:46.593 GMT [1932][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-28 05:18:46.597 GMT [1932][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-28 05:18:46.600 GMT [1932][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50424 2024-03-28 05:18:46.657 GMT [3000][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50426 2024-03-28 05:18:46.664 GMT [3000][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-28 05:18:46.664 GMT [3000][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-28 05:18:46.667 GMT [3000][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-28 05:18:46.673 GMT [3000][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50426 2024-03-28 05:18:46.788 GMT [1728][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50428 2024-03-28 05:18:46.796 GMT [1728][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-28 05:18:46.796 GMT [1728][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-28 05:18:46.799 GMT [1728][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-28 05:18:46.804 GMT [1728][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50428 2024-03-28 05:18:46.914 GMT [6860][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50430 2024-03-28 05:18:46.922 GMT [6860][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-28 05:18:46.922 GMT [6860][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-28 05:18:46.925 GMT [6860][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-28 05:18:46.930 GMT [6860][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50430 2024-03-28 05:18:47.073 GMT [4296][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50432 2024-03-28 05:18:47.080 GMT [4296][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-28 05:18:47.080 GMT [4296][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-28 05:18:47.083 GMT [4296][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-28 05:18:47.128 GMT [4296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.063 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50432 2024-03-28 05:18:47.188 GMT [3592][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50433 2024-03-28 05:18:47.196 GMT [3592][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-28 05:18:47.196 GMT [3592][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-28 05:18:47.200 GMT [3592][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-28 05:18:47.206 GMT [3592][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50433 2024-03-28 05:18:47.287 GMT [7252][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50434 2024-03-28 05:18:47.295 GMT [7252][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-28 05:18:47.295 GMT [7252][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-28 05:18:47.315 GMT [7252][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50434 2024-03-28 05:18:47.472 GMT [5916][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50435 2024-03-28 05:18:47.480 GMT [5916][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-28 05:18:47.480 GMT [5916][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-28 05:18:47.482 GMT [5916][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-28 05:18:47.487 GMT [5916][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50435 2024-03-28 05:18:47.580 GMT [5820][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50436 2024-03-28 05:18:47.587 GMT [5820][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:18:47.725 GMT [4352][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50437 2024-03-28 05:18:47.732 GMT [4352][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:18:47.866 GMT [872][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50438 2024-03-28 05:18:47.875 GMT [872][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-28 05:18:47.875 GMT [872][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-28 05:18:47.878 GMT [872][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-28 05:18:47.881 GMT [872][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50438 2024-03-28 05:18:48.018 GMT [5776][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50439 2024-03-28 05:18:48.025 GMT [5776][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-28 05:18:48.025 GMT [5776][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-28 05:18:48.030 GMT [5776][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-28 05:18:48.035 GMT [5776][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50439 2024-03-28 05:18:48.128 GMT [8068][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50440 2024-03-28 05:18:48.135 GMT [8068][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-28 05:18:48.135 GMT [8068][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-28 05:18:48.137 GMT [8068][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-28 05:18:48.141 GMT [8068][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50440 2024-03-28 05:18:48.205 GMT [5952][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50441 2024-03-28 05:18:48.212 GMT [5952][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-28 05:18:48.212 GMT [5952][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-28 05:18:48.215 GMT [5952][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-28 05:18:48.220 GMT [5952][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50441 2024-03-28 05:18:48.317 GMT [4456][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50442 2024-03-28 05:18:48.441 GMT [7720][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:48.442 GMT [7720][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:48.450 GMT [7720][postmaster] LOG: background worker "logical replication launcher" (PID 4200) exited with exit code 1 2024-03-28 05:18:48.451 GMT [7984][checkpointer] LOG: shutting down 2024-03-28 05:18:48.451 GMT [7984][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:48.455 GMT [7984][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/407DE40, redo lsn=0/407DE40 2024-03-28 05:18:48.461 GMT [7720][postmaster] LOG: database system is shut down 2024-03-28 05:18:48.601 GMT [4984][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:48.602 GMT [4984][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:48.603 GMT [4984][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:48.628 GMT [6168][startup] LOG: database system was shut down at 2024-03-28 05:18:48 GMT 2024-03-28 05:18:48.637 GMT [4984][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:48.704 GMT [4436][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50443 2024-03-28 05:18:48.714 GMT [4436][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-28 05:18:48.714 GMT [4436][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-28 05:18:48.728 GMT [4436][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-28 05:18:48.732 GMT [4436][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50443 2024-03-28 05:18:48.812 GMT [5808][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50444 2024-03-28 05:18:48.893 GMT [4984][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:48.894 GMT [4984][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:48.899 GMT [4984][postmaster] LOG: background worker "logical replication launcher" (PID 1972) exited with exit code 1 2024-03-28 05:18:48.900 GMT [6696][checkpointer] LOG: shutting down 2024-03-28 05:18:48.900 GMT [6696][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:48.903 GMT [6696][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/407DEB8, redo lsn=0/407DEB8 2024-03-28 05:18:48.909 GMT [4984][postmaster] LOG: database system is shut down 2024-03-28 05:18:49.058 GMT [4892][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:49.058 GMT [4892][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:49.059 GMT [4892][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:49.081 GMT [7784][startup] LOG: database system was shut down at 2024-03-28 05:18:48 GMT 2024-03-28 05:18:49.089 GMT [4892][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:49.155 GMT [8064][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50445 2024-03-28 05:18:49.163 GMT [8064][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-28 05:18:49.163 GMT [8064][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-28 05:18:49.177 GMT [8064][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-28 05:18:49.181 GMT [8064][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50445 2024-03-28 05:18:49.235 GMT [4892][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:49.235 GMT [4892][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:49.239 GMT [4892][postmaster] LOG: background worker "logical replication launcher" (PID 8184) exited with exit code 1 2024-03-28 05:18:49.240 GMT [4040][checkpointer] LOG: shutting down 2024-03-28 05:18:49.240 GMT [4040][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:49.243 GMT [4040][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/407DF30, redo lsn=0/407DF30 2024-03-28 05:18:49.247 GMT [4892][postmaster] LOG: database system is shut down 2024-03-28 05:18:49.400 GMT [6940][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:49.400 GMT [6940][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:49.401 GMT [6940][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:49.422 GMT [7752][startup] LOG: database system was shut down at 2024-03-28 05:18:49 GMT 2024-03-28 05:18:49.430 GMT [6940][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:49.502 GMT [1448][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50446 2024-03-28 05:18:49.511 GMT [1448][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-28 05:18:49.511 GMT [1448][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-28 05:18:49.525 GMT [1448][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-28 05:18:49.528 GMT [1448][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50446 2024-03-28 05:18:49.610 GMT [7956][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50447 2024-03-28 05:18:49.619 GMT [7956][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-28 05:18:49.619 GMT [7956][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-28 05:18:49.622 GMT [7956][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-28 05:18:49.624 GMT [7956][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50447 2024-03-28 05:18:49.727 GMT [7236][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50448 2024-03-28 05:18:49.737 GMT [7236][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-28 05:18:49.737 GMT [7236][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-28 05:18:49.741 GMT [7236][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-28 05:18:49.748 GMT [7236][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50448 2024-03-28 05:18:49.831 GMT [5848][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50449 2024-03-28 05:18:49.939 GMT [1572][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50450 2024-03-28 05:18:50.020 GMT [6940][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:50.020 GMT [6940][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:50.025 GMT [6940][postmaster] LOG: background worker "logical replication launcher" (PID 5204) exited with exit code 1 2024-03-28 05:18:50.025 GMT [3520][checkpointer] LOG: shutting down 2024-03-28 05:18:50.026 GMT [3520][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:50.029 GMT [3520][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/407DFA8, redo lsn=0/407DFA8 2024-03-28 05:18:50.034 GMT [6940][postmaster] LOG: database system is shut down 2024-03-28 05:18:50.184 GMT [6480][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:50.185 GMT [6480][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:50.186 GMT [6480][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:50.209 GMT [8112][startup] LOG: database system was shut down at 2024-03-28 05:18:50 GMT 2024-03-28 05:18:50.219 GMT [6480][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:50.285 GMT [6128][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50451 2024-03-28 05:18:50.293 GMT [6128][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-28 05:18:50.293 GMT [6128][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-28 05:18:50.307 GMT [6128][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-28 05:18:50.311 GMT [6128][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50451 2024-03-28 05:18:50.389 GMT [7112][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50452 2024-03-28 05:18:50.450 GMT [4540][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50453 2024-03-28 05:18:50.518 GMT [6480][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:50.519 GMT [6480][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:50.525 GMT [6480][postmaster] LOG: background worker "logical replication launcher" (PID 568) exited with exit code 1 2024-03-28 05:18:50.526 GMT [6620][checkpointer] LOG: shutting down 2024-03-28 05:18:50.526 GMT [6620][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:50.530 GMT [6620][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/407E038, redo lsn=0/407E038 2024-03-28 05:18:50.535 GMT [6480][postmaster] LOG: database system is shut down 2024-03-28 05:18:50.687 GMT [5940][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:50.688 GMT [5940][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:50.689 GMT [5940][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:50.712 GMT [1528][startup] LOG: database system was shut down at 2024-03-28 05:18:50 GMT 2024-03-28 05:18:50.721 GMT [5940][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:50.785 GMT [7256][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50454 2024-03-28 05:18:50.793 GMT [7256][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-28 05:18:50.793 GMT [7256][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-28 05:18:50.806 GMT [7256][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-28 05:18:50.808 GMT [7256][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50454 2024-03-28 05:18:50.896 GMT [1804][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50455 2024-03-28 05:18:50.905 GMT [1804][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-28 05:18:50.905 GMT [1804][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-28 05:18:50.909 GMT [1804][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-28 05:18:50.913 GMT [1804][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50455 2024-03-28 05:18:51.010 GMT [5672][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50456 2024-03-28 05:18:51.088 GMT [5940][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:51.088 GMT [5940][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:51.093 GMT [5940][postmaster] LOG: background worker "logical replication launcher" (PID 2944) exited with exit code 1 2024-03-28 05:18:51.093 GMT [7364][checkpointer] LOG: shutting down 2024-03-28 05:18:51.093 GMT [7364][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:51.096 GMT [7364][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/407E0B0, redo lsn=0/407E0B0 2024-03-28 05:18:51.101 GMT [5940][postmaster] LOG: database system is shut down 2024-03-28 05:18:51.246 GMT [7016][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:51.247 GMT [7016][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:51.249 GMT [7016][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:51.278 GMT [1992][startup] LOG: database system was shut down at 2024-03-28 05:18:51 GMT 2024-03-28 05:18:51.286 GMT [7016][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:51.351 GMT [4780][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50457 2024-03-28 05:18:51.359 GMT [4780][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-28 05:18:51.359 GMT [4780][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-28 05:18:51.372 GMT [4780][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-28 05:18:51.374 GMT [4780][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50457 2024-03-28 05:18:51.451 GMT [7944][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50458 2024-03-28 05:18:51.459 GMT [7944][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-28 05:18:51.459 GMT [7944][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-28 05:18:51.462 GMT [7944][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-28 05:18:51.464 GMT [7944][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50458 2024-03-28 05:18:51.518 GMT [2932][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50459 2024-03-28 05:18:51.525 GMT [2932][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-28 05:18:51.525 GMT [2932][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-28 05:18:51.529 GMT [2932][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-28 05:18:51.531 GMT [2932][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50459 2024-03-28 05:18:51.602 GMT [7016][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:51.603 GMT [7016][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:51.610 GMT [7016][postmaster] LOG: background worker "logical replication launcher" (PID 7620) exited with exit code 1 2024-03-28 05:18:51.610 GMT [5424][checkpointer] LOG: shutting down 2024-03-28 05:18:51.610 GMT [5424][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:51.613 GMT [5424][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/407E128, redo lsn=0/407E128 2024-03-28 05:18:51.619 GMT [7016][postmaster] LOG: database system is shut down 2024-03-28 05:18:51.764 GMT [8056][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:51.765 GMT [8056][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:51.767 GMT [8056][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:51.792 GMT [988][startup] LOG: database system was shut down at 2024-03-28 05:18:51 GMT 2024-03-28 05:18:51.801 GMT [8056][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:51.867 GMT [3472][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50460 2024-03-28 05:18:51.874 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-28 05:18:51.874 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-28 05:18:51.888 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 sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-ca host=common-name.pg-ssltest.test$$ 2024-03-28 05:18:51.891 GMT [3472][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50460 2024-03-28 05:18:51.972 GMT [6112][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50461 2024-03-28 05:18:52.053 GMT [8056][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:52.053 GMT [8056][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:52.058 GMT [8056][postmaster] LOG: background worker "logical replication launcher" (PID 4964) exited with exit code 1 2024-03-28 05:18:52.059 GMT [6000][checkpointer] LOG: shutting down 2024-03-28 05:18:52.059 GMT [6000][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:52.063 GMT [6000][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/407E1A0, redo lsn=0/407E1A0 2024-03-28 05:18:52.068 GMT [8056][postmaster] LOG: database system is shut down 2024-03-28 05:18:52.219 GMT [2300][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:52.220 GMT [2300][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:52.221 GMT [2300][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:52.243 GMT [1164][startup] LOG: database system was shut down at 2024-03-28 05:18:52 GMT 2024-03-28 05:18:52.252 GMT [2300][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:52.316 GMT [6160][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50463 2024-03-28 05:18:52.322 GMT [6160][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-28 05:18:52.488 GMT [6740][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50465 2024-03-28 05:18:52.495 GMT [6740][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-28 05:18:52.495 GMT [6740][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-28 05:18:52.508 GMT [6740][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-28 05:18:52.512 GMT [6740][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50465 2024-03-28 05:18:52.597 GMT [1856][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50467 2024-03-28 05:18:52.676 GMT [2300][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:52.676 GMT [2300][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:52.681 GMT [2300][postmaster] LOG: background worker "logical replication launcher" (PID 5384) exited with exit code 1 2024-03-28 05:18:52.681 GMT [7304][checkpointer] LOG: shutting down 2024-03-28 05:18:52.681 GMT [7304][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:52.685 GMT [7304][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/407E218, redo lsn=0/407E218 2024-03-28 05:18:52.689 GMT [2300][postmaster] LOG: database system is shut down 2024-03-28 05:18:52.855 GMT [7504][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:52.855 GMT [7504][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:52.857 GMT [7504][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:52.888 GMT [1868][startup] LOG: database system was shut down at 2024-03-28 05:18:52 GMT 2024-03-28 05:18:52.898 GMT [7504][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:53.062 GMT [2352][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50468 2024-03-28 05:18:53.069 GMT [2352][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-28 05:18:53.069 GMT [2352][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-28 05:18:53.082 GMT [2352][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-28 05:18:53.086 GMT [2352][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50468 2024-03-28 05:18:53.171 GMT [5692][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50470 2024-03-28 05:18:53.176 GMT [5692][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-28 05:18:53.283 GMT [1056][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50471 2024-03-28 05:18:53.291 GMT [1056][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-28 05:18:53.390 GMT [2276][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50472 2024-03-28 05:18:53.397 GMT [2276][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-28 05:18:53.397 GMT [2276][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-28 05:18:53.400 GMT [2276][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-28 05:18:53.406 GMT [2276][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50472 2024-03-28 05:18:53.458 GMT [4296][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50473 2024-03-28 05:18:53.465 GMT [4296][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-28 05:18:53.465 GMT [4296][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-28 05:18:53.468 GMT [4296][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-28 05:18:53.471 GMT [4296][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50473 2024-03-28 05:18:53.752 GMT [5864][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50474 2024-03-28 05:18:53.759 GMT [5864][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-28 05:18:53.815 GMT [2844][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50475 2024-03-28 05:18:53.824 GMT [2844][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-28 05:18:53.824 GMT [2844][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-28 05:18:53.854 GMT [2844][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_U38K/client.key$$ 2024-03-28 05:18:53.857 GMT [2844][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.049 user=ssltestuser database=certdb host=pg-loadbalancetest port=50475 2024-03-28 05:18:53.946 GMT [6984][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50476 2024-03-28 05:18:53.955 GMT [6984][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-28 05:18:53.955 GMT [6984][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-28 05:18:53.958 GMT [6984][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_U38K/client-der.key$$ 2024-03-28 05:18:53.962 GMT [6984][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50476 2024-03-28 05:18:54.049 GMT [7328][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50477 2024-03-28 05:18:54.058 GMT [7328][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-28 05:18:54.058 GMT [7328][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-28 05:18:54.061 GMT [7328][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_U38K/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-28 05:18:54.063 GMT [7328][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50477 2024-03-28 05:18:54.111 GMT [6308][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50478 2024-03-28 05:18:54.119 GMT [6308][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-28 05:18:54.120 GMT [6308][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-28 05:18:54.122 GMT [6308][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_U38K/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-28 05:18:54.126 GMT [6308][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50478 2024-03-28 05:18:54.173 GMT [7764][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50479 2024-03-28 05:18:54.182 GMT [7764][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-28 05:18:54.182 GMT [7764][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-28 05:18:54.185 GMT [7764][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_U38K/client.key$$ 2024-03-28 05:18:54.188 GMT [7764][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50479 2024-03-28 05:18:54.284 GMT [8136][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50480 2024-03-28 05:18:54.293 GMT [8136][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-28 05:18:54.293 GMT [8136][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-28 05:18:54.297 GMT [8136][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_U38K/client.key$$ 2024-03-28 05:18:54.299 GMT [8136][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50480 2024-03-28 05:18:54.352 GMT [872][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50481 2024-03-28 05:18:54.359 GMT [872][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-28 05:18:54.461 GMT [5420][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50482 2024-03-28 05:18:54.471 GMT [5420][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-28 05:18:54.522 GMT [972][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50483 2024-03-28 05:18:54.531 GMT [972][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-28 05:18:54.531 GMT [972][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-28 05:18:54.544 GMT [972][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_U38K/client-dn.key$$ 2024-03-28 05:18:54.547 GMT [972][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50483 2024-03-28 05:18:54.646 GMT [6336][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50484 2024-03-28 05:18:54.656 GMT [6336][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-28 05:18:54.657 GMT [6336][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-28 05:18:54.670 GMT [6336][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_U38K/client-dn.key$$ 2024-03-28 05:18:54.675 GMT [6336][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.037 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50484 2024-03-28 05:18:54.760 GMT [1540][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50485 2024-03-28 05:18:54.770 GMT [1540][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-28 05:18:54.770 GMT [1540][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-28 05:18:54.785 GMT [1540][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_U38K/client-dn.key$$ 2024-03-28 05:18:54.787 GMT [1540][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50485 2024-03-28 05:18:54.875 GMT [7320][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50486 2024-03-28 05:18:54.885 GMT [7320][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-28 05:18:54.885 GMT [7320][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-28 05:18:54.889 GMT [7320][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-28 05:18:54.894 GMT [7320][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.027 user=ssltestuser database=certdb host=pg-loadbalancetest port=50486 2024-03-28 05:18:54.942 GMT [1480][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50487 2024-03-28 05:18:54.951 GMT [1480][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-28 05:18:54.951 GMT [1480][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-28 05:18:54.951 GMT [1480][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-28 05:18:54.951 GMT [1480][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-28 05:18:55.050 GMT [7720][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50488 2024-03-28 05:18:55.057 GMT [7720][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:18:55.057 GMT [7720][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-28 05:18:55.158 GMT [8156][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50489 2024-03-28 05:18:55.168 GMT [8156][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-28 05:18:55.168 GMT [8156][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-28 05:18:55.180 GMT [8156][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_U38K/client.key$$ 2024-03-28 05:18:55.184 GMT [8156][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50489 2024-03-28 05:18:55.278 GMT [5708][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50490 2024-03-28 05:18:55.288 GMT [5708][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-28 05:18:55.288 GMT [5708][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-28 05:18:55.288 GMT [5708][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-28 05:18:55.288 GMT [5708][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-28 05:18:55.349 GMT [6468][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50491 2024-03-28 05:18:55.359 GMT [6468][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-28 05:18:55.359 GMT [6468][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-28 05:18:55.362 GMT [6468][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_U38K/client.key$$ 2024-03-28 05:18:55.364 GMT [6468][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50491 2024-03-28 05:18:55.400 GMT [7504][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:55.400 GMT [7504][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:55.405 GMT [7504][postmaster] LOG: background worker "logical replication launcher" (PID 3000) exited with exit code 1 2024-03-28 05:18:55.405 GMT [7960][checkpointer] LOG: shutting down 2024-03-28 05:18:55.405 GMT [7960][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:55.408 GMT [7960][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/407E290, redo lsn=0/407E290 2024-03-28 05:18:55.413 GMT [7504][postmaster] LOG: database system is shut down 2024-03-28 05:18:55.568 GMT [1292][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:55.569 GMT [1292][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:55.570 GMT [1292][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:55.592 GMT [5936][startup] LOG: database system was shut down at 2024-03-28 05:18:55 GMT 2024-03-28 05:18:55.601 GMT [1292][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:55.668 GMT [1676][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50492 2024-03-28 05:18:55.677 GMT [1676][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-28 05:18:55.677 GMT [1676][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-28 05:18:55.691 GMT [1676][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_U38K/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-28 05:18:55.694 GMT [1676][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb host=pg-loadbalancetest port=50492 2024-03-28 05:18:55.774 GMT [7472][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50493 2024-03-28 05:18:55.782 GMT [7472][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:18:55.782 GMT [7472][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-28 05:18:55.881 GMT [7060][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50494 2024-03-28 05:18:55.890 GMT [7060][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:18:55.890 GMT [7060][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-28 05:18:55.960 GMT [1292][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:55.960 GMT [1292][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:55.965 GMT [1292][postmaster] LOG: background worker "logical replication launcher" (PID 6088) exited with exit code 1 2024-03-28 05:18:55.966 GMT [1972][checkpointer] LOG: shutting down 2024-03-28 05:18:55.966 GMT [1972][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:55.969 GMT [1972][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/407E308, redo lsn=0/407E308 2024-03-28 05:18:55.975 GMT [1292][postmaster] LOG: database system is shut down 2024-03-28 05:18:56.135 GMT [5948][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:56.136 GMT [5948][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:56.137 GMT [5948][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:56.167 GMT [6732][startup] LOG: database system was shut down at 2024-03-28 05:18:55 GMT 2024-03-28 05:18:56.176 GMT [5948][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:56.251 GMT [7728][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50495 2024-03-28 05:18:56.258 GMT [7728][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:18:56.258 GMT [7728][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-28 05:18:56.306 GMT [5948][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:56.306 GMT [5948][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:56.315 GMT [5948][postmaster] LOG: background worker "logical replication launcher" (PID 6748) exited with exit code 1 2024-03-28 05:18:56.315 GMT [7148][checkpointer] LOG: shutting down 2024-03-28 05:18:56.315 GMT [7148][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:56.318 GMT [7148][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/407E380, redo lsn=0/407E380 2024-03-28 05:18:56.323 GMT [5948][postmaster] LOG: database system is shut down 2024-03-28 05:18:56.473 GMT [7236][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:56.474 GMT [7236][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:56.475 GMT [7236][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:56.497 GMT [4144][startup] LOG: database system was shut down at 2024-03-28 05:18:56 GMT 2024-03-28 05:18:56.505 GMT [7236][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:56.575 GMT [5044][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50496 2024-03-28 05:18:56.583 GMT [5044][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:18:56.583 GMT [5044][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-28 05:18:56.686 GMT [8052][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50497 2024-03-28 05:18:56.695 GMT [8052][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-28 05:18:56.695 GMT [8052][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-28 05:18:56.778 GMT [7236][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:56.779 GMT [7236][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:56.786 GMT [7236][postmaster] LOG: background worker "logical replication launcher" (PID 596) exited with exit code 1 2024-03-28 05:18:56.786 GMT [3316][checkpointer] LOG: shutting down 2024-03-28 05:18:56.786 GMT [3316][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:56.790 GMT [3316][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/407E3F8, redo lsn=0/407E3F8 2024-03-28 05:18:56.795 GMT [7236][postmaster] LOG: database system is shut down 2024-03-28 05:18:56.945 GMT [6184][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:56.946 GMT [6184][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:56.947 GMT [6184][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:56.966 GMT [676][startup] LOG: database system was shut down at 2024-03-28 05:18:56 GMT 2024-03-28 05:18:56.973 GMT [6184][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:57.059 GMT [6480][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50498 2024-03-28 05:18:57.063 GMT [6480][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:18:57.063 GMT [6480][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:18:57.161 GMT [7756][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50499 2024-03-28 05:18:57.169 GMT [7756][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-28 05:18:57.169 GMT [7756][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-28 05:18:57.182 GMT [7756][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-28 05:18:57.186 GMT [7756][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50499 2024-03-28 05:18:57.242 GMT [6184][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:57.242 GMT [6184][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:57.245 GMT [6184][postmaster] LOG: background worker "logical replication launcher" (PID 568) exited with exit code 1 2024-03-28 05:18:57.246 GMT [6380][checkpointer] LOG: shutting down 2024-03-28 05:18:57.246 GMT [6380][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:57.249 GMT [6380][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/407E470, redo lsn=0/407E470 2024-03-28 05:18:57.253 GMT [6184][postmaster] LOG: database system is shut down 2024-03-28 05:18:57.408 GMT [6068][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:57.408 GMT [6068][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:57.409 GMT [6068][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:57.429 GMT [6248][startup] LOG: database system was shut down at 2024-03-28 05:18:57 GMT 2024-03-28 05:18:57.437 GMT [6068][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:57.506 GMT [5744][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50500 2024-03-28 05:18:57.509 GMT [5744][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:18:57.510 GMT [5744][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:18:57.613 GMT [6516][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50501 2024-03-28 05:18:57.621 GMT [6516][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-28 05:18:57.621 GMT [6516][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-28 05:18:57.633 GMT [6516][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-28 05:18:57.636 GMT [6516][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50501 2024-03-28 05:18:57.696 GMT [6068][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:57.696 GMT [6068][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:57.699 GMT [6068][postmaster] LOG: background worker "logical replication launcher" (PID 7920) exited with exit code 1 2024-03-28 05:18:57.699 GMT [1804][checkpointer] LOG: shutting down 2024-03-28 05:18:57.700 GMT [1804][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:57.702 GMT [1804][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/407E4E8, redo lsn=0/407E4E8 2024-03-28 05:18:57.706 GMT [6068][postmaster] LOG: database system is shut down 2024-03-28 05:18:57.858 GMT [1748][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:57.858 GMT [1748][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:57.859 GMT [1748][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:57.879 GMT [6476][startup] LOG: database system was shut down at 2024-03-28 05:18:57 GMT 2024-03-28 05:18:57.887 GMT [1748][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:57.955 GMT [7916][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50502 2024-03-28 05:18:57.959 GMT [7916][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:18:57.959 GMT [7916][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:18:58.020 GMT [7680][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50503 2024-03-28 05:18:58.027 GMT [7680][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-28 05:18:58.027 GMT [7680][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-28 05:18:58.040 GMT [7680][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-28 05:18:58.043 GMT [7680][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50503 2024-03-28 05:18:58.103 GMT [1748][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:58.103 GMT [1748][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:58.107 GMT [1748][postmaster] LOG: background worker "logical replication launcher" (PID 6360) exited with exit code 1 2024-03-28 05:18:58.107 GMT [7652][checkpointer] LOG: shutting down 2024-03-28 05:18:58.107 GMT [7652][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:58.110 GMT [7652][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/407E560, redo lsn=0/407E560 2024-03-28 05:18:58.116 GMT [1748][postmaster] LOG: database system is shut down 2024-03-28 05:18:58.262 GMT [2852][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:58.263 GMT [2852][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:58.264 GMT [2852][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:58.288 GMT [7708][startup] LOG: database system was shut down at 2024-03-28 05:18:58 GMT 2024-03-28 05:18:58.297 GMT [2852][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:58.364 GMT [7416][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50504 2024-03-28 05:18:58.367 GMT [7416][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:18:58.368 GMT [7416][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:18:58.428 GMT [7300][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50505 2024-03-28 05:18:58.435 GMT [7300][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-28 05:18:58.435 GMT [7300][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-28 05:18:58.448 GMT [7300][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-28 05:18:58.453 GMT [7300][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50505 2024-03-28 05:18:58.509 GMT [2852][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:58.509 GMT [2852][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:58.512 GMT [2852][postmaster] LOG: background worker "logical replication launcher" (PID 7556) exited with exit code 1 2024-03-28 05:18:58.513 GMT [2400][checkpointer] LOG: shutting down 2024-03-28 05:18:58.513 GMT [2400][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:58.516 GMT [2400][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/407E5D8, redo lsn=0/407E5D8 2024-03-28 05:18:58.520 GMT [2852][postmaster] LOG: database system is shut down 2024-03-28 05:18:58.671 GMT [4552][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:58.672 GMT [4552][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:58.673 GMT [4552][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:58.695 GMT [2432][startup] LOG: database system was shut down at 2024-03-28 05:18:58 GMT 2024-03-28 05:18:58.703 GMT [4552][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:58.772 GMT [6840][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50506 2024-03-28 05:18:58.776 GMT [6840][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:18:58.777 GMT [6840][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:18:58.883 GMT [2612][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50507 2024-03-28 05:18:58.890 GMT [2612][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-28 05:18:58.890 GMT [2612][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-28 05:18:58.903 GMT [2612][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-28 05:18:58.908 GMT [2612][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50507 2024-03-28 05:18:58.966 GMT [4552][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:58.966 GMT [4552][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:58.970 GMT [4552][postmaster] LOG: background worker "logical replication launcher" (PID 3696) exited with exit code 1 2024-03-28 05:18:58.971 GMT [7736][checkpointer] LOG: shutting down 2024-03-28 05:18:58.971 GMT [7736][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:58.974 GMT [7736][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/407E650, redo lsn=0/407E650 2024-03-28 05:18:58.979 GMT [4552][postmaster] LOG: database system is shut down 2024-03-28 05:18:59.122 GMT [5292][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:59.123 GMT [5292][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:59.124 GMT [5292][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:59.143 GMT [196][startup] LOG: database system was shut down at 2024-03-28 05:18:58 GMT 2024-03-28 05:18:59.150 GMT [5292][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:59.224 GMT [3044][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50508 2024-03-28 05:18:59.228 GMT [3044][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:18:59.229 GMT [3044][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:18:59.290 GMT [6600][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50509 2024-03-28 05:18:59.298 GMT [6600][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-28 05:18:59.298 GMT [6600][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-28 05:18:59.311 GMT [6600][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-28 05:18:59.317 GMT [6600][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50509 2024-03-28 05:18:59.374 GMT [5292][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:59.374 GMT [5292][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:59.379 GMT [5292][postmaster] LOG: background worker "logical replication launcher" (PID 7216) exited with exit code 1 2024-03-28 05:18:59.380 GMT [6920][checkpointer] LOG: shutting down 2024-03-28 05:18:59.380 GMT [6920][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:59.383 GMT [6920][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/407E6C8, redo lsn=0/407E6C8 2024-03-28 05:18:59.388 GMT [5292][postmaster] LOG: database system is shut down 2024-03-28 05:18:59.535 GMT [5348][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:59.535 GMT [5348][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:59.536 GMT [5348][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:18:59.557 GMT [7716][startup] LOG: database system was shut down at 2024-03-28 05:18:59 GMT 2024-03-28 05:18:59.565 GMT [5348][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:18:59.637 GMT [7552][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50510 2024-03-28 05:18:59.640 GMT [7552][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:18:59.641 GMT [7552][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:18:59.746 GMT [7588][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50511 2024-03-28 05:18:59.753 GMT [7588][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-28 05:18:59.753 GMT [7588][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-28 05:18:59.768 GMT [7588][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-28 05:18:59.772 GMT [7588][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50511 2024-03-28 05:18:59.829 GMT [5348][postmaster] LOG: received fast shutdown request 2024-03-28 05:18:59.829 GMT [5348][postmaster] LOG: aborting any active transactions 2024-03-28 05:18:59.835 GMT [5348][postmaster] LOG: background worker "logical replication launcher" (PID 464) exited with exit code 1 2024-03-28 05:18:59.835 GMT [3268][checkpointer] LOG: shutting down 2024-03-28 05:18:59.836 GMT [3268][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:18:59.839 GMT [3268][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/407E740, redo lsn=0/407E740 2024-03-28 05:18:59.844 GMT [5348][postmaster] LOG: database system is shut down 2024-03-28 05:18:59.988 GMT [1240][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:18:59.989 GMT [1240][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:18:59.990 GMT [1240][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:19:00.007 GMT [1988][startup] LOG: database system was shut down at 2024-03-28 05:18:59 GMT 2024-03-28 05:19:00.014 GMT [1240][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:19:00.092 GMT [7764][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50512 2024-03-28 05:19:00.095 GMT [7764][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:19:00.096 GMT [7764][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:19:00.199 GMT [4340][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50513 2024-03-28 05:19:00.207 GMT [4340][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-28 05:19:00.207 GMT [4340][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-28 05:19:00.219 GMT [4340][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-28 05:19:00.223 GMT [4340][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50513 2024-03-28 05:19:00.280 GMT [1240][postmaster] LOG: received fast shutdown request 2024-03-28 05:19:00.280 GMT [1240][postmaster] LOG: aborting any active transactions 2024-03-28 05:19:00.284 GMT [1240][postmaster] LOG: background worker "logical replication launcher" (PID 6052) exited with exit code 1 2024-03-28 05:19:00.284 GMT [4544][checkpointer] LOG: shutting down 2024-03-28 05:19:00.284 GMT [4544][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:19:00.286 GMT [4544][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/407E7B8, redo lsn=0/407E7B8 2024-03-28 05:19:00.290 GMT [1240][postmaster] LOG: database system is shut down 2024-03-28 05:19:00.440 GMT [6328][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-28 05:19:00.441 GMT [6328][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 56367 2024-03-28 05:19:00.442 GMT [6328][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/WvWF_zFc96/.s.PGSQL.56367" 2024-03-28 05:19:00.461 GMT [2128][startup] LOG: database system was shut down at 2024-03-28 05:19:00 GMT 2024-03-28 05:19:00.470 GMT [6328][postmaster] LOG: database system is ready to accept connections 2024-03-28 05:19:00.543 GMT [3156][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50514 2024-03-28 05:19:00.547 GMT [3156][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-28 05:19:00.547 GMT [3156][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-28 05:19:00.652 GMT [5732][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50515 2024-03-28 05:19:00.659 GMT [5732][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-28 05:19:00.659 GMT [5732][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-28 05:19:00.670 GMT [5732][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-28 05:19:00.675 GMT [5732][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50515 2024-03-28 05:19:00.736 GMT [6328][postmaster] LOG: received fast shutdown request 2024-03-28 05:19:00.736 GMT [6328][postmaster] LOG: aborting any active transactions 2024-03-28 05:19:00.740 GMT [6328][postmaster] LOG: background worker "logical replication launcher" (PID 4456) exited with exit code 1 2024-03-28 05:19:00.741 GMT [972][checkpointer] LOG: shutting down 2024-03-28 05:19:00.742 GMT [972][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-28 05:19:00.744 GMT [972][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/407E830, redo lsn=0/407E830 2024-03-28 05:19:00.748 GMT [6328][postmaster] LOG: database system is shut down 2024-03-28 05:19:00.885 GMT [1788][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-28 05:19:00.886 GMT [1788][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [05:19:00.948](0.233s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"