[07:46:49.611](0.179s) # setting up data directory # Checking port 49861 # Found port 49861 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=49861 host=C:/Windows/TEMP/hq3XOnn3DJ Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log [07:46:49.647](0.036s) # 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 3152 [07:46:51.793](2.146s) 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 2340 [07:46:56.883](5.090s) # 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-12 07:46:51.311 GMT [3152][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:51.312 GMT [3152][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:51.348 GMT [6376][startup] LOG: database system was shut down at 2024-03-12 07:37:09 GMT 2024-03-12 07:46:51.411 GMT [3152][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:51.747 GMT [5144][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:51.750 GMT [5144][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-12 07:46:51.750 GMT [5144][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:51.762 GMT [5144][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-12 07:46:51.766 GMT [5144][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:51.922 GMT [2616][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:51.924 GMT [2616][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-12 07:46:51.924 GMT [2616][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:51.926 GMT [2616][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-12 07:46:51.927 GMT [2616][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:52.086 GMT [7524][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:52.088 GMT [7524][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-12 07:46:52.088 GMT [7524][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:52.091 GMT [7524][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-12 07:46:52.585 GMT [7524][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.502 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:52.915 GMT [1648][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:52.917 GMT [1648][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-12 07:46:52.917 GMT [1648][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:52.919 GMT [1648][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-12 07:46:52.919 GMT [1648][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.033 GMT [5348][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.034 GMT [5348][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-12 07:46:53.034 GMT [5348][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.056 GMT [5348][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-12 07:46:53.057 GMT [5348][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.281 GMT [3416][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.283 GMT [3416][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-12 07:46:53.283 GMT [3416][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.285 GMT [3416][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-12 07:46:53.481 GMT [3416][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.202 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.689 GMT [8088][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.690 GMT [8088][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-12 07:46:53.690 GMT [8088][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.693 GMT [8088][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-12 07:46:53.884 GMT [8088][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.198 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:54.084 GMT [3992][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:54.085 GMT [3992][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-12 07:46:54.085 GMT [3992][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:54.088 GMT [3992][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-12 07:46:54.439 GMT [3992][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.358 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:54.561 GMT [3256][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:54.562 GMT [3256][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-12 07:46:54.562 GMT [3256][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:54.564 GMT [3256][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-12 07:46:54.818 GMT [3256][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.260 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:55.054 GMT [2372][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:55.055 GMT [2372][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-12 07:46:55.055 GMT [2372][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:55.058 GMT [2372][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-12 07:46:55.265 GMT [2372][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.214 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:55.562 GMT [4252][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:55.563 GMT [4252][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-12 07:46:55.563 GMT [4252][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:55.569 GMT [4252][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-12 07:46:55.841 GMT [4252][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.283 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:56.034 GMT [3152][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:56.035 GMT [3152][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:56.102 GMT [3152][postmaster] LOG: background worker "logical replication launcher" (PID 4764) exited with exit code 1 2024-03-12 07:46:56.103 GMT [7464][checkpointer] LOG: shutting down 2024-03-12 07:46:56.103 GMT [7464][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:56.457 GMT [7464][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.344 s, sync=0.001 s, total=0.355 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C79E0, redo lsn=0/40C79E0 2024-03-12 07:46:56.556 GMT [3152][postmaster] LOG: database system is shut down 2024-03-12 07:46:56.800 GMT [2340][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:56.800 GMT [2340][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:46:56.802 GMT [2340][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:56.850 GMT [1644][startup] LOG: database system was shut down at 2024-03-12 07:46:56 GMT 2024-03-12 07:46:56.862 GMT [2340][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:56.904 GMT [2340][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:56.904 GMT [2340][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:56.919 GMT [2340][postmaster] LOG: background worker "logical replication launcher" (PID 2524) exited with exit code 1 2024-03-12 07:46:56.921 GMT [6192][checkpointer] LOG: shutting down 2024-03-12 07:46:56.923 GMT [6192][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:56.926 GMT [6192][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7A58, redo lsn=0/40C7A58 2024-03-12 07:46:56.944 GMT [2340][postmaster] LOG: database system is shut down 2024-03-12 07:46:57.091 GMT [7856][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-12 07:46:57.091 GMT [7856][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [07:46:57.123](0.240s) 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 7508 [07:46:57.366](0.243s) 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-12 07:46:51.311 GMT [3152][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:51.312 GMT [3152][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:51.348 GMT [6376][startup] LOG: database system was shut down at 2024-03-12 07:37:09 GMT 2024-03-12 07:46:51.411 GMT [3152][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:51.747 GMT [5144][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:51.750 GMT [5144][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-12 07:46:51.750 GMT [5144][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:51.762 GMT [5144][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-12 07:46:51.766 GMT [5144][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:51.922 GMT [2616][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:51.924 GMT [2616][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-12 07:46:51.924 GMT [2616][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:51.926 GMT [2616][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-12 07:46:51.927 GMT [2616][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:52.086 GMT [7524][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:52.088 GMT [7524][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-12 07:46:52.088 GMT [7524][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:52.091 GMT [7524][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-12 07:46:52.585 GMT [7524][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.502 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:52.915 GMT [1648][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:52.917 GMT [1648][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-12 07:46:52.917 GMT [1648][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:52.919 GMT [1648][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-12 07:46:52.919 GMT [1648][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.033 GMT [5348][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.034 GMT [5348][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-12 07:46:53.034 GMT [5348][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.056 GMT [5348][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-12 07:46:53.057 GMT [5348][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.281 GMT [3416][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.283 GMT [3416][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-12 07:46:53.283 GMT [3416][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.285 GMT [3416][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-12 07:46:53.481 GMT [3416][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.202 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.689 GMT [8088][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.690 GMT [8088][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-12 07:46:53.690 GMT [8088][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.693 GMT [8088][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-12 07:46:53.884 GMT [8088][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.198 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:54.084 GMT [3992][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:54.085 GMT [3992][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-12 07:46:54.085 GMT [3992][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:54.088 GMT [3992][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-12 07:46:54.439 GMT [3992][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.358 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:54.561 GMT [3256][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:54.562 GMT [3256][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-12 07:46:54.562 GMT [3256][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:54.564 GMT [3256][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-12 07:46:54.818 GMT [3256][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.260 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:55.054 GMT [2372][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:55.055 GMT [2372][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-12 07:46:55.055 GMT [2372][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:55.058 GMT [2372][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-12 07:46:55.265 GMT [2372][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.214 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:55.562 GMT [4252][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:55.563 GMT [4252][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-12 07:46:55.563 GMT [4252][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:55.569 GMT [4252][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-12 07:46:55.841 GMT [4252][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.283 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:56.034 GMT [3152][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:56.035 GMT [3152][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:56.102 GMT [3152][postmaster] LOG: background worker "logical replication launcher" (PID 4764) exited with exit code 1 2024-03-12 07:46:56.103 GMT [7464][checkpointer] LOG: shutting down 2024-03-12 07:46:56.103 GMT [7464][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:56.457 GMT [7464][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.344 s, sync=0.001 s, total=0.355 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C79E0, redo lsn=0/40C79E0 2024-03-12 07:46:56.556 GMT [3152][postmaster] LOG: database system is shut down 2024-03-12 07:46:56.800 GMT [2340][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:56.800 GMT [2340][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:46:56.802 GMT [2340][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:56.850 GMT [1644][startup] LOG: database system was shut down at 2024-03-12 07:46:56 GMT 2024-03-12 07:46:56.862 GMT [2340][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:56.904 GMT [2340][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:56.904 GMT [2340][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:56.919 GMT [2340][postmaster] LOG: background worker "logical replication launcher" (PID 2524) exited with exit code 1 2024-03-12 07:46:56.921 GMT [6192][checkpointer] LOG: shutting down 2024-03-12 07:46:56.923 GMT [6192][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:56.926 GMT [6192][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7A58, redo lsn=0/40C7A58 2024-03-12 07:46:56.944 GMT [2340][postmaster] LOG: database system is shut down 2024-03-12 07:46:57.091 GMT [7856][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-12 07:46:57.091 GMT [7856][postmaster] LOG: database system is shut down 2024-03-12 07:46:57.228 GMT [7508][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:57.229 GMT [7508][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:46:57.230 GMT [7508][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:57.268 GMT [7840][startup] LOG: database system was shut down at 2024-03-12 07:46:56 GMT 2024-03-12 07:46:57.286 GMT [7508][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:57.384 GMT [7508][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:57.384 GMT [7508][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:57.395 GMT [7508][postmaster] LOG: background worker "logical replication launcher" (PID 5588) exited with exit code 1 2024-03-12 07:46:57.400 GMT [8004][checkpointer] LOG: shutting down 2024-03-12 07:46:57.400 GMT [8004][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:57.403 GMT [8004][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7AD0, redo lsn=0/40C7AD0 2024-03-12 07:46:57.442 GMT [7508][postmaster] LOG: database system is shut down 2024-03-12 07:46:57.673 GMT [2100][postmaster] FATAL: could not set SSL protocol version range 2024-03-12 07:46:57.673 GMT [2100][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-12 07:46:57.673 GMT [2100][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [07:46:57.869](0.502s) 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 7004 [07:46:58.172](0.303s) ok 5 - restart succeeds with correct SSL protocol bounds [07:46:58.172](0.000s) # 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 5800 [07:46:58.636](0.464s) ok 6 - server doesn't accept non-SSL connections [07:46:58.636](0.000s) ok 7 - server doesn't accept non-SSL connections: matches [07:46:58.715](0.079s) ok 8 - connect without server root cert sslmode=require [07:46:58.715](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr [07:46:58.809](0.094s) ok 10 - connect without server root cert sslmode=verify-ca [07:46:58.810](0.001s) ok 11 - connect without server root cert sslmode=verify-ca: matches [07:46:58.887](0.077s) ok 12 - connect without server root cert sslmode=verify-full [07:46:58.887](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches [07:46:58.976](0.088s) ok 14 - connect with wrong server root cert sslmode=require [07:46:58.976](0.001s) ok 15 - connect with wrong server root cert sslmode=require: matches [07:46:59.152](0.176s) ok 16 - connect with wrong server root cert sslmode=verify-ca [07:46:59.152](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches [07:46:59.301](0.149s) ok 18 - connect with wrong server root cert sslmode=verify-full [07:46:59.301](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches [07:46:59.417](0.116s) ok 20 - connect with server CA cert, without root CA [07:46:59.417](0.000s) ok 21 - connect with server CA cert, without root CA: matches [07:46:59.479](0.061s) ok 22 - connect with correct server CA cert file sslmode=require [07:46:59.479](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr [07:46:59.550](0.071s) ok 24 - connect with correct server CA cert file sslmode=verify-ca [07:46:59.550](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr [07:46:59.645](0.095s) ok 26 - connect with correct server CA cert file sslmode=verify-full [07:46:59.645](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr [07:46:59.730](0.085s) ok 28 - cert root file that contains two certificates, order 1 [07:46:59.730](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr [07:46:59.873](0.142s) ok 30 - cert root file that contains two certificates, order 2 [07:46:59.873](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr [07:46:59.964](0.091s) ok 32 - connect with sslcertmode=disable [07:46:59.964](0.000s) ok 33 - connect with sslcertmode=disable: no stderr [07:47:00.047](0.083s) ok 34 - connect with sslcertmode=allow [07:47:00.048](0.001s) ok 35 - connect with sslcertmode=allow: no stderr [07:47:00.201](0.153s) ok 36 - connect with sslcertmode=require fails without a client certificate [07:47:00.202](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches [07:47:00.324](0.122s) ok 38 - sslcrl option with invalid file name [07:47:00.325](0.001s) ok 39 - sslcrl option with invalid file name: no stderr [07:47:00.500](0.176s) ok 40 - CRL belonging to a different CA [07:47:00.500](0.000s) ok 41 - CRL belonging to a different CA: matches [07:47:00.886](0.386s) ok 42 - directory CRL belonging to a different CA [07:47:00.886](0.000s) ok 43 - directory CRL belonging to a different CA: matches [07:47:01.036](0.150s) ok 44 - CRL with a non-revoked cert [07:47:01.037](0.001s) ok 45 - CRL with a non-revoked cert: no stderr [07:47:01.134](0.097s) ok 46 - directory CRL with a non-revoked cert [07:47:01.134](0.001s) ok 47 - directory CRL with a non-revoked cert: no stderr [07:47:01.248](0.114s) ok 48 - mismatch between host name and server certificate sslmode=require [07:47:01.249](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr [07:47:01.386](0.137s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca [07:47:01.386](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr [07:47:01.465](0.079s) ok 52 - mismatch between host name and server certificate sslmode=verify-full [07:47:01.466](0.001s) 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 2304 [07:47:02.689](1.223s) ok 54 - IP address in the Common Name [07:47:02.689](0.000s) ok 55 - IP address in the Common Name: no stderr [07:47:02.972](0.283s) ok 56 - mismatch between host name and server certificate IP address [07:47:02.972](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 3804 [07:47:03.913](0.941s) ok 58 - IP address in a dNSName [07:47:03.913](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 2468 [07:47:04.259](0.345s) ok 60 - host name matching with X.509 Subject Alternative Names 1 [07:47:04.259](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr [07:47:04.321](0.062s) ok 62 - host name matching with X.509 Subject Alternative Names 2 [07:47:04.321](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr [07:47:04.384](0.062s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard [07:47:04.384](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr [07:47:04.445](0.062s) ok 66 - host name not matching with X.509 Subject Alternative Names [07:47:04.446](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches [07:47:04.508](0.062s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard [07:47:04.508](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 3812 [07:47:04.851](0.344s) ok 70 - host name matching with a single X.509 Subject Alternative Name [07:47:04.852](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr [07:47:04.914](0.063s) ok 72 - host name not matching with a single X.509 Subject Alternative Name [07:47:04.915](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches [07:47:04.976](0.062s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard [07:47:04.977](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches [07:47:05.007](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 4768 [07:47:05.352](0.346s) ok 77 - certificate with both a CN and SANs 1 [07:47:05.352](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr [07:47:05.415](0.062s) ok 79 - certificate with both a CN and SANs 2 [07:47:05.415](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr [07:47:05.479](0.064s) ok 81 - certificate with both a CN and SANs ignores CN [07:47:05.479](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches [07:47:05.510](0.031s) 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 6408 [07:47:05.855](0.345s) ok 84 - certificate with both an IP CN and DNS SANs matches CN [07:47:05.855](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr [07:47:05.918](0.062s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1 [07:47:05.918](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr [07:47:05.979](0.061s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2 [07:47:05.979](0.000s) ok 89 - certificate with both an IP CN and DNS SANs matches SAN 2: no stderr ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart waiting for server to shut down.... done server stopped waiting for server to start.... done server started # Postmaster PID for node "primary" is 5228 [07:47:06.324](0.344s) ok 90 - server certificate without CN or SANs sslmode=verify-ca [07:47:06.324](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr [07:47:06.386](0.062s) ok 92 - server certificate without CN or SANs sslmode=verify-full [07:47:06.386](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 7792 [07:47:06.682](0.296s) ok 94 - sslrootcert=system does not connect with private CA [07:47:06.682](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches [07:47:06.714](0.032s) ok 96 - sslrootcert=system only accepts sslmode=verify-full [07:47:06.714](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches [07:47:06.823](0.109s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE [07:47:06.823](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr [07:47:06.886](0.062s) ok 100 - sslrootcert=system defaults to sslmode=verify-full [07:47:06.886](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 7648 [07:47:07.199](0.313s) ok 102 - connects without client-side CRL [07:47:07.199](0.001s) ok 103 - connects without client-side CRL: no stderr [07:47:07.277](0.078s) ok 104 - does not connect with client-side CRL file [07:47:07.278](0.001s) ok 105 - does not connect with client-side CRL file: matches [07:47:07.397](0.119s) ok 106 - does not connect with client-side CRL directory [07:47:07.397](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() [07:47:07.479](0.082s) ok 108 - pg_stat_ssl view without client certificate: exit code 0 [07:47:07.480](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr [07:47:07.480](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches [07:47:07.544](0.065s) ok 111 - connection success with correct range of TLS protocol versions [07:47:07.545](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr [07:47:07.605](0.060s) ok 113 - connection failure with incorrect range of TLS protocol versions [07:47:07.606](0.001s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches [07:47:07.668](0.062s) ok 115 - connection failure with an incorrect SSL protocol minimum bound [07:47:07.669](0.001s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches [07:47:07.730](0.061s) ok 117 - connection failure with an incorrect SSL protocol maximum bound [07:47:07.730](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches [07:47:07.730](0.000s) # running server tests [07:47:07.792](0.061s) ok 119 - certificate authorization fails without client cert [07:47:07.792](0.001s) ok 120 - certificate authorization fails without client cert: matches [07:47:07.901](0.109s) ok 121 - certificate authorization succeeds with correct client cert in PEM format [07:47:07.902](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr [07:47:07.964](0.062s) ok 123 - certificate authorization succeeds with correct client cert in DER format [07:47:07.964](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr [07:47:08.073](0.109s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format [07:47:08.073](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr [07:47:08.136](0.063s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format [07:47:08.137](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr [07:47:08.199](0.062s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require [07:47:08.199](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr [07:47:08.262](0.063s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow [07:47:08.262](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr [07:47:08.325](0.062s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable [07:47:08.325](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches [07:47:08.387](0.062s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format [07:47:08.388](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches [07:47:08.467](0.079s) ok 137 - certificate authorization succeeds with DN mapping [07:47:08.467](0.001s) ok 138 - certificate authorization succeeds with DN mapping: no stderr [07:47:08.468](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches [07:47:08.544](0.076s) ok 140 - certificate authorization succeeds with DN regex mapping [07:47:08.544](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr [07:47:08.653](0.109s) ok 142 - certificate authorization succeeds with CN mapping [07:47:08.654](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr [07:47:08.654](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches [07:47:08.655](0.000s) not ok 145 # TODO & SKIP Need Pty support [07:47:08.655](0.000s) not ok 146 # TODO & SKIP Need Pty support [07:47:08.655](0.000s) not ok 147 # TODO & SKIP Need Pty support [07:47:08.655](0.000s) not ok 148 # TODO & SKIP Need Pty support 'C:\Program' is not recognized as an internal or external command, operable program or batch file. couldn't run "C:\Program Files\Git\usr\bin\openssl.EXE x509" to get client cert serialno at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 726. # Running: psql -X -A -F , -P null=_null_ -d sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcert=ssl/client.crt sslkey=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_g5O6/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() [07:47:08.761](0.106s) ok 149 - pg_stat_ssl with client certificate: exit code 0 [07:47:08.761](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr [07:47:08.761](0.000s) ok 151 - pg_stat_ssl with client certificate: matches [07:47:08.761](0.000s) ok 152 # skip Permissions check not enforced on Windows [07:47:08.762](0.000s) ok 153 # skip Permissions check not enforced on Windows [07:47:08.825](0.063s) ok 154 - certificate authorization fails with client cert belonging to another user [07:47:08.825](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches [07:47:08.887](0.062s) ok 156 - certificate authorization fails with revoked client cert [07:47:08.887](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches [07:47:08.888](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match [07:47:08.997](0.109s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name [07:47:08.997](0.000s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr [07:47:08.997](0.000s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches [07:47:09.059](0.061s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name [07:47:09.059](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches [07:47:09.060](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match [07:47:09.122](0.062s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name [07:47:09.122](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr [07:47:09.123](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 8108 [07:47:09.465](0.343s) ok 168 - intermediate client certificate is provided by client [07:47:09.465](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr [07:47:09.527](0.061s) ok 170 - intermediate client certificate is missing [07:47:09.527](0.000s) ok 171 - intermediate client certificate is missing: matches [07:47:09.589](0.062s) ok 172 - logged client certificate Subjects are truncated if they're too long [07:47:09.590](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 7940 [07:47:09.933](0.344s) ok 174 - intermediate client certificate is untrusted [07:47:09.934](0.000s) ok 175 - intermediate client certificate is untrusted: matches ### Restarting node "primary" # Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart waiting for server to shut down.... done server stopped waiting for server to start.... done server started # Postmaster PID for node "primary" is 3128 [07:47:10.231](0.297s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory [07:47:10.231](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches [07:47:10.293](0.062s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory [07:47:10.294](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 7072 [07:47:10.590](0.297s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1 [07:47:10.591](0.000s) # Failed test 'connect with valid stapled ocsp response when sslocspstapling=1' # at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923. [07:47:10.591](0.000s) # got: '2' # expected: '0' [07:47:10.591](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [07:47:10.592](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. [07:47:10.592](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 49861 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: '' [07:47:10.701](0.109s) ok 182 - connect without requesting ocsp response when sslocspstapling=0 [07:47:10.701](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 7036 [07:47:10.997](0.297s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1 [07:47:11.107](0.109s) ok 185 - connect without requesting ocsp response when sslocspstapling=0 [07:47:11.107](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 8132 [07:47:11.404](0.297s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1 [07:47:11.513](0.109s) ok 188 - connect without requesting ocsp response when sslocspstapling=0 [07:47:11.513](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 4148 [07:47:11.810](0.296s) ok 190 - failed with an expired ocsp response when sslocspstapling=1 [07:47:11.920](0.111s) ok 191 - connect without requesting ocsp response when sslocspstapling=0 [07:47:11.921](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 5168 [07:47:12.327](0.406s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1 [07:47:12.327](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. [07:47:12.327](0.000s) # got: '2' # expected: '0' [07:47:12.327](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr [07:47:12.327](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. [07:47:12.327](0.000s) # got: 'psql: error: connection to server at "127.0.0.1", port 49861 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: '' [07:47:12.437](0.110s) ok 195 - connect without requesting ocsp response when sslocspstapling=0 [07:47:12.438](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 3736 [07:47:12.734](0.297s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1 [07:47:12.843](0.109s) ok 198 - connect without requesting ocsp response when sslocspstapling=0 [07:47:12.843](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 4568 [07:47:13.143](0.300s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1 [07:47:13.252](0.109s) ok 201 - connect without requesting ocsp response when sslocspstapling=0 [07:47:13.253](0.001s) 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 472 [07:47:13.549](0.296s) ok 203 - failed with an expired ocsp response when sslocspstapling=1 [07:47:13.659](0.110s) ok 204 - connect without requesting ocsp response when sslocspstapling=0 [07:47:13.659](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 1960 [07:47:13.955](0.296s) ok 206 - failed with an expired ocsp response when sslocspstapling=1 [07:47:14.020](0.064s) ok 207 - connect without requesting ocsp response when sslocspstapling=0 [07:47:14.020](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-12 07:46:51.311 GMT [3152][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:51.312 GMT [3152][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:51.348 GMT [6376][startup] LOG: database system was shut down at 2024-03-12 07:37:09 GMT 2024-03-12 07:46:51.411 GMT [3152][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:51.747 GMT [5144][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:51.750 GMT [5144][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-12 07:46:51.750 GMT [5144][client backend] [[unknown]][0/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:51.762 GMT [5144][client backend] [001_ssltests.pl][0/2:0] LOG: statement: SHOW ssl_library 2024-03-12 07:46:51.766 GMT [5144][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.025 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:51.922 GMT [2616][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:51.924 GMT [2616][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-12 07:46:51.924 GMT [2616][client backend] [[unknown]][1/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:51.926 GMT [2616][client backend] [001_ssltests.pl][1/2:0] LOG: statement: CREATE USER ssltestuser 2024-03-12 07:46:51.927 GMT [2616][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:52.086 GMT [7524][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:52.088 GMT [7524][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-12 07:46:52.088 GMT [7524][client backend] [[unknown]][2/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:52.091 GMT [7524][client backend] [001_ssltests.pl][2/2:0] LOG: statement: CREATE USER md5testuser 2024-03-12 07:46:52.585 GMT [7524][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.502 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:52.915 GMT [1648][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:52.917 GMT [1648][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-12 07:46:52.917 GMT [1648][client backend] [[unknown]][3/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:52.919 GMT [1648][client backend] [001_ssltests.pl][3/2:0] LOG: statement: CREATE USER anotheruser 2024-03-12 07:46:52.919 GMT [1648][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.033 GMT [5348][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.034 GMT [5348][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-12 07:46:53.034 GMT [5348][client backend] [[unknown]][4/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.056 GMT [5348][client backend] [001_ssltests.pl][4/2:0] LOG: statement: CREATE USER yetanotheruser 2024-03-12 07:46:53.057 GMT [5348][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.281 GMT [3416][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.283 GMT [3416][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-12 07:46:53.283 GMT [3416][client backend] [[unknown]][5/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.285 GMT [3416][client backend] [001_ssltests.pl][5/2:0] LOG: statement: CREATE DATABASE trustdb 2024-03-12 07:46:53.481 GMT [3416][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.202 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:53.689 GMT [8088][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:53.690 GMT [8088][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-12 07:46:53.690 GMT [8088][client backend] [[unknown]][6/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:53.693 GMT [8088][client backend] [001_ssltests.pl][6/2:0] LOG: statement: CREATE DATABASE certdb 2024-03-12 07:46:53.884 GMT [8088][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.198 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:54.084 GMT [3992][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:54.085 GMT [3992][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-12 07:46:54.085 GMT [3992][client backend] [[unknown]][7/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:54.088 GMT [3992][client backend] [001_ssltests.pl][7/2:0] LOG: statement: CREATE DATABASE certdb_dn 2024-03-12 07:46:54.439 GMT [3992][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.358 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:54.561 GMT [3256][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:54.562 GMT [3256][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-12 07:46:54.562 GMT [3256][client backend] [[unknown]][8/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:54.564 GMT [3256][client backend] [001_ssltests.pl][8/2:0] LOG: statement: CREATE DATABASE certdb_dn_re 2024-03-12 07:46:54.818 GMT [3256][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.260 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:55.054 GMT [2372][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:55.055 GMT [2372][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-12 07:46:55.055 GMT [2372][client backend] [[unknown]][9/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:55.058 GMT [2372][client backend] [001_ssltests.pl][9/2:0] LOG: statement: CREATE DATABASE certdb_cn 2024-03-12 07:46:55.265 GMT [2372][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.214 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:55.562 GMT [4252][not initialized] [[unknown]][:0] LOG: connection received: host=[local] 2024-03-12 07:46:55.563 GMT [4252][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-12 07:46:55.563 GMT [4252][client backend] [[unknown]][10/1:0] LOG: connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl 2024-03-12 07:46:55.569 GMT [4252][client backend] [001_ssltests.pl][10/2:0] LOG: statement: CREATE DATABASE verifydb 2024-03-12 07:46:55.841 GMT [4252][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.283 user=SYSTEM database=postgres host=[local] 2024-03-12 07:46:56.034 GMT [3152][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:56.035 GMT [3152][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:56.102 GMT [3152][postmaster] LOG: background worker "logical replication launcher" (PID 4764) exited with exit code 1 2024-03-12 07:46:56.103 GMT [7464][checkpointer] LOG: shutting down 2024-03-12 07:46:56.103 GMT [7464][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:56.457 GMT [7464][checkpointer] LOG: checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.344 s, sync=0.001 s, total=0.355 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C79E0, redo lsn=0/40C79E0 2024-03-12 07:46:56.556 GMT [3152][postmaster] LOG: database system is shut down 2024-03-12 07:46:56.800 GMT [2340][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:56.800 GMT [2340][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:46:56.802 GMT [2340][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:56.850 GMT [1644][startup] LOG: database system was shut down at 2024-03-12 07:46:56 GMT 2024-03-12 07:46:56.862 GMT [2340][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:56.904 GMT [2340][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:56.904 GMT [2340][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:56.919 GMT [2340][postmaster] LOG: background worker "logical replication launcher" (PID 2524) exited with exit code 1 2024-03-12 07:46:56.921 GMT [6192][checkpointer] LOG: shutting down 2024-03-12 07:46:56.923 GMT [6192][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:56.926 GMT [6192][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7A58, redo lsn=0/40C7A58 2024-03-12 07:46:56.944 GMT [2340][postmaster] LOG: database system is shut down 2024-03-12 07:46:57.091 GMT [7856][postmaster] FATAL: could not load private key file "server-password.key": bad decrypt 2024-03-12 07:46:57.091 GMT [7856][postmaster] LOG: database system is shut down 2024-03-12 07:46:57.228 GMT [7508][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:57.229 GMT [7508][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:46:57.230 GMT [7508][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:57.268 GMT [7840][startup] LOG: database system was shut down at 2024-03-12 07:46:56 GMT 2024-03-12 07:46:57.286 GMT [7508][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:57.384 GMT [7508][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:57.384 GMT [7508][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:57.395 GMT [7508][postmaster] LOG: background worker "logical replication launcher" (PID 5588) exited with exit code 1 2024-03-12 07:46:57.400 GMT [8004][checkpointer] LOG: shutting down 2024-03-12 07:46:57.400 GMT [8004][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:57.403 GMT [8004][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7AD0, redo lsn=0/40C7AD0 2024-03-12 07:46:57.442 GMT [7508][postmaster] LOG: database system is shut down 2024-03-12 07:46:57.673 GMT [2100][postmaster] FATAL: could not set SSL protocol version range 2024-03-12 07:46:57.673 GMT [2100][postmaster] DETAIL: ssl_min_protocol_version cannot be higher than ssl_max_protocol_version 2024-03-12 07:46:57.673 GMT [2100][postmaster] LOG: database system is shut down 2024-03-12 07:46:58.030 GMT [7004][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:58.031 GMT [7004][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:46:58.032 GMT [7004][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:58.061 GMT [7220][startup] LOG: database system was shut down at 2024-03-12 07:46:57 GMT 2024-03-12 07:46:58.080 GMT [7004][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:58.200 GMT [7004][postmaster] LOG: received fast shutdown request 2024-03-12 07:46:58.201 GMT [7004][postmaster] LOG: aborting any active transactions 2024-03-12 07:46:58.223 GMT [7004][postmaster] LOG: background worker "logical replication launcher" (PID 5108) exited with exit code 1 2024-03-12 07:46:58.226 GMT [6372][checkpointer] LOG: shutting down 2024-03-12 07:46:58.227 GMT [6372][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:46:58.231 GMT [6372][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7B48, redo lsn=0/40C7B48 2024-03-12 07:46:58.240 GMT [7004][postmaster] LOG: database system is shut down 2024-03-12 07:46:58.417 GMT [5800][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:46:58.419 GMT [5800][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:46:58.423 GMT [5800][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:46:58.452 GMT [5568][startup] LOG: database system was shut down at 2024-03-12 07:46:58 GMT 2024-03-12 07:46:58.482 GMT [5800][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:46:58.584 GMT [1032][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50314 2024-03-12 07:46:58.585 GMT [1032][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-12 07:46:58.585 GMT [1032][client backend] [[unknown]][0/1:0] DETAIL: Client IP address resolved to "pg-loadbalancetest", forward lookup not checked. 2024-03-12 07:46:58.687 GMT [5396][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50317 2024-03-12 07:46:58.693 GMT [5396][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-12 07:46:58.693 GMT [5396][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-12 07:46:58.707 GMT [5396][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-12 07:46:58.709 GMT [5396][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50317 2024-03-12 07:46:58.783 GMT [7840][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50319 2024-03-12 07:46:58.793 GMT [7840][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-12 07:46:58.856 GMT [1604][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50320 2024-03-12 07:46:58.865 GMT [1604][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-12 07:46:58.932 GMT [2000][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50322 2024-03-12 07:46:58.937 GMT [2000][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-12 07:46:59.037 GMT [4128][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50323 2024-03-12 07:46:59.045 GMT [4128][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-12 07:46:59.254 GMT [1240][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50326 2024-03-12 07:46:59.259 GMT [1240][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-12 07:46:59.385 GMT [7868][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50329 2024-03-12 07:46:59.390 GMT [7868][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-12 07:46:59.465 GMT [6828][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50331 2024-03-12 07:46:59.471 GMT [6828][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-12 07:46:59.471 GMT [6828][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-12 07:46:59.474 GMT [6828][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-12 07:46:59.476 GMT [6828][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50331 2024-03-12 07:46:59.524 GMT [7248][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50332 2024-03-12 07:46:59.532 GMT [7248][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-12 07:46:59.532 GMT [7248][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-12 07:46:59.536 GMT [7248][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-12 07:46:59.539 GMT [7248][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50332 2024-03-12 07:46:59.609 GMT [5484][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50334 2024-03-12 07:46:59.616 GMT [5484][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-12 07:46:59.616 GMT [5484][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-12 07:46:59.620 GMT [5484][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-12 07:46:59.623 GMT [5484][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50334 2024-03-12 07:46:59.707 GMT [5364][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50335 2024-03-12 07:46:59.714 GMT [5364][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-12 07:46:59.714 GMT [5364][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-12 07:46:59.717 GMT [5364][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-12 07:46:59.719 GMT [5364][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50335 2024-03-12 07:46:59.805 GMT [2040][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50338 2024-03-12 07:46:59.812 GMT [2040][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-12 07:46:59.812 GMT [2040][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-12 07:46:59.815 GMT [2040][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-12 07:46:59.817 GMT [2040][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.041 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50338 2024-03-12 07:46:59.948 GMT [5000][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50341 2024-03-12 07:46:59.955 GMT [5000][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-12 07:46:59.955 GMT [5000][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-12 07:46:59.958 GMT [5000][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-12 07:46:59.961 GMT [5000][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50341 2024-03-12 07:47:00.010 GMT [6100][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50342 2024-03-12 07:47:00.017 GMT [6100][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-12 07:47:00.017 GMT [6100][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-12 07:47:00.020 GMT [6100][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-12 07:47:00.023 GMT [6100][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50342 2024-03-12 07:47:00.131 GMT [3564][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50344 2024-03-12 07:47:00.138 GMT [3564][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-12 07:47:00.138 GMT [3564][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-12 07:47:00.151 GMT [3564][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50344 2024-03-12 07:47:00.250 GMT [7332][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50346 2024-03-12 07:47:00.257 GMT [7332][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-12 07:47:00.257 GMT [7332][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-12 07:47:00.260 GMT [7332][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-12 07:47:00.265 GMT [7332][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50346 2024-03-12 07:47:00.408 GMT [4292][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50348 2024-03-12 07:47:00.416 GMT [4292][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-12 07:47:00.731 GMT [5708][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50350 2024-03-12 07:47:00.737 GMT [5708][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-12 07:47:00.993 GMT [4496][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50353 2024-03-12 07:47:01.001 GMT [4496][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-12 07:47:01.001 GMT [4496][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-12 07:47:01.004 GMT [4496][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-12 07:47:01.008 GMT [4496][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.052 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50353 2024-03-12 07:47:01.106 GMT [2276][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50355 2024-03-12 07:47:01.113 GMT [2276][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-12 07:47:01.113 GMT [2276][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-12 07:47:01.115 GMT [2276][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-12 07:47:01.119 GMT [2276][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50355 2024-03-12 07:47:01.204 GMT [4568][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50356 2024-03-12 07:47:01.211 GMT [4568][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-12 07:47:01.211 GMT [4568][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-12 07:47:01.213 GMT [4568][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-12 07:47:01.216 GMT [4568][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50356 2024-03-12 07:47:01.345 GMT [2676][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50359 2024-03-12 07:47:01.352 GMT [2676][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-12 07:47:01.352 GMT [2676][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-12 07:47:01.355 GMT [2676][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-12 07:47:01.358 GMT [2676][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50359 2024-03-12 07:47:01.436 GMT [2372][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50361 2024-03-12 07:47:01.495 GMT [5800][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:01.495 GMT [5800][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:01.501 GMT [5800][postmaster] LOG: background worker "logical replication launcher" (PID 7460) exited with exit code 1 2024-03-12 07:47:01.503 GMT [3140][checkpointer] LOG: shutting down 2024-03-12 07:47:01.503 GMT [3140][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:01.507 GMT [3140][checkpointer] LOG: checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7BC0, redo lsn=0/40C7BC0 2024-03-12 07:47:01.517 GMT [5800][postmaster] LOG: database system is shut down 2024-03-12 07:47:01.758 GMT [2304][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:01.759 GMT [2304][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:01.760 GMT [2304][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:01.903 GMT [632][startup] LOG: database system was shut down at 2024-03-12 07:47:01 GMT 2024-03-12 07:47:02.002 GMT [2304][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:02.160 GMT [3060][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50363 2024-03-12 07:47:02.167 GMT [3060][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-12 07:47:02.167 GMT [3060][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-12 07:47:02.181 GMT [3060][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-12 07:47:02.187 GMT [3060][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50363 2024-03-12 07:47:02.887 GMT [2840][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50364 2024-03-12 07:47:02.998 GMT [2304][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:02.998 GMT [2304][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:03.025 GMT [2304][postmaster] LOG: background worker "logical replication launcher" (PID 3432) exited with exit code 1 2024-03-12 07:47:03.030 GMT [5424][checkpointer] LOG: shutting down 2024-03-12 07:47:03.030 GMT [5424][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:03.034 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/40C7C38, redo lsn=0/40C7C38 2024-03-12 07:47:03.112 GMT [2304][postmaster] LOG: database system is shut down 2024-03-12 07:47:03.385 GMT [3804][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:03.386 GMT [3804][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:03.387 GMT [3804][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:03.670 GMT [7336][startup] LOG: database system was shut down at 2024-03-12 07:47:03 GMT 2024-03-12 07:47:03.716 GMT [3804][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:03.884 GMT [5056][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50365 2024-03-12 07:47:03.891 GMT [5056][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-12 07:47:03.891 GMT [5056][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-12 07:47:03.904 GMT [5056][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-12 07:47:03.907 GMT [5056][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50365 2024-03-12 07:47:03.928 GMT [3804][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:03.928 GMT [3804][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:03.933 GMT [3804][postmaster] LOG: background worker "logical replication launcher" (PID 5832) exited with exit code 1 2024-03-12 07:47:03.933 GMT [6700][checkpointer] LOG: shutting down 2024-03-12 07:47:03.933 GMT [6700][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:03.936 GMT [6700][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/40C7CB0, redo lsn=0/40C7CB0 2024-03-12 07:47:03.941 GMT [3804][postmaster] LOG: database system is shut down 2024-03-12 07:47:04.087 GMT [2468][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:04.088 GMT [2468][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:04.089 GMT [2468][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:04.118 GMT [7980][startup] LOG: database system was shut down at 2024-03-12 07:47:03 GMT 2024-03-12 07:47:04.125 GMT [2468][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:04.189 GMT [5948][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50366 2024-03-12 07:47:04.196 GMT [5948][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-12 07:47:04.196 GMT [5948][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-12 07:47:04.210 GMT [5948][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-12 07:47:04.212 GMT [5948][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50366 2024-03-12 07:47:04.297 GMT [7032][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50367 2024-03-12 07:47:04.304 GMT [7032][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-12 07:47:04.304 GMT [7032][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-12 07:47:04.307 GMT [7032][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-12 07:47:04.309 GMT [7032][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50367 2024-03-12 07:47:04.359 GMT [7012][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50368 2024-03-12 07:47:04.366 GMT [7012][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-12 07:47:04.366 GMT [7012][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-12 07:47:04.369 GMT [7012][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-12 07:47:04.371 GMT [7012][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50368 2024-03-12 07:47:04.421 GMT [7312][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50369 2024-03-12 07:47:04.484 GMT [4484][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50370 2024-03-12 07:47:04.523 GMT [2468][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:04.523 GMT [2468][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:04.527 GMT [2468][postmaster] LOG: background worker "logical replication launcher" (PID 1048) exited with exit code 1 2024-03-12 07:47:04.527 GMT [6072][checkpointer] LOG: shutting down 2024-03-12 07:47:04.527 GMT [6072][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:04.530 GMT [6072][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/40C7D28, redo lsn=0/40C7D28 2024-03-12 07:47:04.534 GMT [2468][postmaster] LOG: database system is shut down 2024-03-12 07:47:04.685 GMT [3812][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:04.686 GMT [3812][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:04.687 GMT [3812][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:04.706 GMT [7764][startup] LOG: database system was shut down at 2024-03-12 07:47:04 GMT 2024-03-12 07:47:04.714 GMT [3812][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:04.783 GMT [3760][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50371 2024-03-12 07:47:04.790 GMT [3760][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-12 07:47:04.790 GMT [3760][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-12 07:47:04.804 GMT [3760][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-12 07:47:04.807 GMT [3760][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50371 2024-03-12 07:47:04.891 GMT [5192][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50372 2024-03-12 07:47:04.954 GMT [7224][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50373 2024-03-12 07:47:05.022 GMT [3812][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:05.022 GMT [3812][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:05.027 GMT [3812][postmaster] LOG: background worker "logical replication launcher" (PID 7096) exited with exit code 1 2024-03-12 07:47:05.027 GMT [7808][checkpointer] LOG: shutting down 2024-03-12 07:47:05.027 GMT [7808][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:05.030 GMT [7808][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/40C7DA0, redo lsn=0/40C7DA0 2024-03-12 07:47:05.034 GMT [3812][postmaster] LOG: database system is shut down 2024-03-12 07:47:05.182 GMT [4768][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:05.183 GMT [4768][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:05.184 GMT [4768][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:05.210 GMT [6348][startup] LOG: database system was shut down at 2024-03-12 07:47:05 GMT 2024-03-12 07:47:05.218 GMT [4768][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:05.283 GMT [8136][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50374 2024-03-12 07:47:05.290 GMT [8136][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-12 07:47:05.290 GMT [8136][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-12 07:47:05.302 GMT [8136][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-12 07:47:05.305 GMT [8136][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50374 2024-03-12 07:47:05.392 GMT [5108][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50375 2024-03-12 07:47:05.399 GMT [5108][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-12 07:47:05.399 GMT [5108][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-12 07:47:05.402 GMT [5108][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-12 07:47:05.404 GMT [5108][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50375 2024-03-12 07:47:05.453 GMT [2128][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50376 2024-03-12 07:47:05.525 GMT [4768][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:05.525 GMT [4768][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:05.529 GMT [4768][postmaster] LOG: background worker "logical replication launcher" (PID 7024) exited with exit code 1 2024-03-12 07:47:05.529 GMT [4756][checkpointer] LOG: shutting down 2024-03-12 07:47:05.529 GMT [4756][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:05.532 GMT [4756][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/40C7E18, redo lsn=0/40C7E18 2024-03-12 07:47:05.536 GMT [4768][postmaster] LOG: database system is shut down 2024-03-12 07:47:05.683 GMT [6408][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:05.684 GMT [6408][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:05.685 GMT [6408][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:05.703 GMT [5692][startup] LOG: database system was shut down at 2024-03-12 07:47:05 GMT 2024-03-12 07:47:05.710 GMT [6408][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:05.784 GMT [2736][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50377 2024-03-12 07:47:05.791 GMT [2736][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-12 07:47:05.791 GMT [2736][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-12 07:47:05.804 GMT [2736][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-12 07:47:05.807 GMT [2736][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50377 2024-03-12 07:47:05.894 GMT [7740][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50378 2024-03-12 07:47:05.901 GMT [7740][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-12 07:47:05.901 GMT [7740][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-12 07:47:05.904 GMT [7740][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-12 07:47:05.906 GMT [7740][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50378 2024-03-12 07:47:05.957 GMT [8032][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50379 2024-03-12 07:47:05.964 GMT [8032][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-12 07:47:05.964 GMT [8032][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-12 07:47:05.967 GMT [8032][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-12 07:47:05.969 GMT [8032][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50379 2024-03-12 07:47:05.994 GMT [6408][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:05.994 GMT [6408][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:06.005 GMT [6408][postmaster] LOG: background worker "logical replication launcher" (PID 5272) exited with exit code 1 2024-03-12 07:47:06.005 GMT [4140][checkpointer] LOG: shutting down 2024-03-12 07:47:06.006 GMT [4140][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:06.008 GMT [4140][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/40C7E90, redo lsn=0/40C7E90 2024-03-12 07:47:06.013 GMT [6408][postmaster] LOG: database system is shut down 2024-03-12 07:47:06.153 GMT [5228][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:06.153 GMT [5228][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:06.154 GMT [5228][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:06.182 GMT [7352][startup] LOG: database system was shut down at 2024-03-12 07:47:05 GMT 2024-03-12 07:47:06.190 GMT [5228][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:06.254 GMT [4452][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50380 2024-03-12 07:47:06.261 GMT [4452][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-12 07:47:06.261 GMT [4452][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-12 07:47:06.274 GMT [4452][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-12 07:47:06.276 GMT [4452][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50380 2024-03-12 07:47:06.363 GMT [5788][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50381 2024-03-12 07:47:06.401 GMT [5228][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:06.401 GMT [5228][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:06.404 GMT [5228][postmaster] LOG: background worker "logical replication launcher" (PID 732) exited with exit code 1 2024-03-12 07:47:06.405 GMT [4640][checkpointer] LOG: shutting down 2024-03-12 07:47:06.405 GMT [4640][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:06.408 GMT [4640][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C7F08, redo lsn=0/40C7F08 2024-03-12 07:47:06.412 GMT [5228][postmaster] LOG: database system is shut down 2024-03-12 07:47:06.558 GMT [7792][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:06.558 GMT [7792][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:06.559 GMT [7792][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:06.577 GMT [7936][startup] LOG: database system was shut down at 2024-03-12 07:47:06 GMT 2024-03-12 07:47:06.584 GMT [7792][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:06.661 GMT [5564][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50382 2024-03-12 07:47:06.666 GMT [5564][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: tlsv1 alert unknown ca 2024-03-12 07:47:06.752 GMT [6436][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50383 2024-03-12 07:47:06.758 GMT [6436][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-12 07:47:06.758 GMT [6436][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-12 07:47:06.771 GMT [6436][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-12 07:47:06.783 GMT [6436][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.038 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50383 2024-03-12 07:47:06.862 GMT [6156][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50384 2024-03-12 07:47:06.902 GMT [7792][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:06.902 GMT [7792][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:06.905 GMT [7792][postmaster] LOG: background worker "logical replication launcher" (PID 4400) exited with exit code 1 2024-03-12 07:47:06.906 GMT [4420][checkpointer] LOG: shutting down 2024-03-12 07:47:06.906 GMT [4420][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:06.909 GMT [4420][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/40C7F80, redo lsn=0/40C7F80 2024-03-12 07:47:06.913 GMT [7792][postmaster] LOG: database system is shut down 2024-03-12 07:47:07.061 GMT [7648][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:07.061 GMT [7648][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:07.063 GMT [7648][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:07.083 GMT [5772][startup] LOG: database system was shut down at 2024-03-12 07:47:06 GMT 2024-03-12 07:47:07.090 GMT [7648][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:07.166 GMT [6232][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50385 2024-03-12 07:47:07.173 GMT [6232][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-12 07:47:07.173 GMT [6232][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-12 07:47:07.185 GMT [6232][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-12 07:47:07.188 GMT [6232][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50385 2024-03-12 07:47:07.241 GMT [5084][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50386 2024-03-12 07:47:07.247 GMT [5084][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-12 07:47:07.327 GMT [7124][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50387 2024-03-12 07:47:07.334 GMT [7124][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: sslv3 alert certificate revoked 2024-03-12 07:47:07.437 GMT [5588][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50388 2024-03-12 07:47:07.444 GMT [5588][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-12 07:47:07.444 GMT [5588][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-12 07:47:07.447 GMT [5588][client backend] [001_ssltests.pl][1/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-12 07:47:07.451 GMT [5588][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50388 2024-03-12 07:47:07.521 GMT [7060][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50389 2024-03-12 07:47:07.528 GMT [7060][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-12 07:47:07.528 GMT [7060][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-12 07:47:07.531 GMT [7060][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-12 07:47:07.533 GMT [7060][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50389 2024-03-12 07:47:07.773 GMT [5452][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50390 2024-03-12 07:47:07.780 GMT [5452][client backend] [[unknown]][3/1:0] FATAL: connection requires a valid client certificate 2024-03-12 07:47:07.836 GMT [2072][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50391 2024-03-12 07:47:07.844 GMT [2072][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-12 07:47:07.844 GMT [2072][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-12 07:47:07.857 GMT [2072][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_g5O6/client.key$$ 2024-03-12 07:47:07.860 GMT [2072][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.032 user=ssltestuser database=certdb host=pg-loadbalancetest port=50391 2024-03-12 07:47:07.943 GMT [5672][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50392 2024-03-12 07:47:07.952 GMT [5672][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-12 07:47:07.952 GMT [5672][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-12 07:47:07.955 GMT [5672][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_g5O6/client-der.key$$ 2024-03-12 07:47:07.957 GMT [5672][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50392 2024-03-12 07:47:08.009 GMT [5800][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50393 2024-03-12 07:47:08.019 GMT [5800][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-12 07:47:08.019 GMT [5800][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-12 07:47:08.022 GMT [5800][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_g5O6/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$ 2024-03-12 07:47:08.025 GMT [5800][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50393 2024-03-12 07:47:08.117 GMT [4936][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50394 2024-03-12 07:47:08.127 GMT [4936][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-12 07:47:08.127 GMT [4936][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-12 07:47:08.129 GMT [4936][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_g5O6/client-encrypted-der.key sslpassword='dUmmyP^#+'$$ 2024-03-12 07:47:08.131 GMT [4936][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50394 2024-03-12 07:47:08.182 GMT [4652][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50395 2024-03-12 07:47:08.191 GMT [4652][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-12 07:47:08.191 GMT [4652][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-12 07:47:08.194 GMT [4652][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_g5O6/client.key$$ 2024-03-12 07:47:08.196 GMT [4652][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50395 2024-03-12 07:47:08.242 GMT [2000][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50396 2024-03-12 07:47:08.251 GMT [2000][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-12 07:47:08.251 GMT [2000][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-12 07:47:08.254 GMT [2000][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_g5O6/client.key$$ 2024-03-12 07:47:08.257 GMT [2000][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50396 2024-03-12 07:47:08.302 GMT [5808][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50397 2024-03-12 07:47:08.308 GMT [5808][client backend] [[unknown]][10/1:0] FATAL: connection requires a valid client certificate 2024-03-12 07:47:08.365 GMT [7136][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50398 2024-03-12 07:47:08.377 GMT [7136][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: EOF detected 2024-03-12 07:47:08.430 GMT [7368][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50399 2024-03-12 07:47:08.439 GMT [7368][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-12 07:47:08.439 GMT [7368][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-12 07:47:08.450 GMT [7368][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_g5O6/client-dn.key$$ 2024-03-12 07:47:08.453 GMT [7368][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50399 2024-03-12 07:47:08.510 GMT [7104][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50400 2024-03-12 07:47:08.519 GMT [7104][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-12 07:47:08.519 GMT [7104][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-12 07:47:08.530 GMT [7104][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_g5O6/client-dn.key$$ 2024-03-12 07:47:08.533 GMT [7104][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50400 2024-03-12 07:47:08.586 GMT [1288][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50401 2024-03-12 07:47:08.595 GMT [1288][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-12 07:47:08.595 GMT [1288][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-12 07:47:08.606 GMT [1288][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_g5O6/client-dn.key$$ 2024-03-12 07:47:08.609 GMT [1288][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50401 2024-03-12 07:47:08.705 GMT [5096][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50402 2024-03-12 07:47:08.713 GMT [5096][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-12 07:47:08.713 GMT [5096][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-12 07:47:08.719 GMT [5096][client backend] [001_ssltests.pl][14/2:0] LOG: statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid() 2024-03-12 07:47:08.724 GMT [5096][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.026 user=ssltestuser database=certdb host=pg-loadbalancetest port=50402 2024-03-12 07:47:08.801 GMT [3776][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50403 2024-03-12 07:47:08.809 GMT [3776][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-12 07:47:08.809 GMT [3776][client backend] [[unknown]][15/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-12 07:47:08.809 GMT [3776][client backend] [[unknown]][15/1:0] FATAL: certificate authentication failed for user "anotheruser" 2024-03-12 07:47:08.809 GMT [3776][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-12 07:47:08.864 GMT [5980][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50404 2024-03-12 07:47:08.871 GMT [5980][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-12 07:47:08.871 GMT [5980][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-12 07:47:08.927 GMT [440][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50406 2024-03-12 07:47:08.936 GMT [440][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-12 07:47:08.936 GMT [440][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-12 07:47:08.947 GMT [440][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_g5O6/client.key$$ 2024-03-12 07:47:08.950 GMT [440][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50406 2024-03-12 07:47:09.038 GMT [5008][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50407 2024-03-12 07:47:09.047 GMT [5008][client backend] [[unknown]][17/1:0] LOG: provided user name (anotheruser) and authenticated user name (ssltestuser) do not match 2024-03-12 07:47:09.047 GMT [5008][client backend] [[unknown]][17/1:0] LOG: certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch 2024-03-12 07:47:09.047 GMT [5008][client backend] [[unknown]][17/1:0] FATAL: "trust" authentication failed for user "anotheruser" 2024-03-12 07:47:09.047 GMT [5008][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-12 07:47:09.100 GMT [6016][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50408 2024-03-12 07:47:09.109 GMT [6016][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-12 07:47:09.109 GMT [6016][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-12 07:47:09.112 GMT [6016][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_g5O6/client.key$$ 2024-03-12 07:47:09.114 GMT [6016][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.020 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50408 2024-03-12 07:47:09.140 GMT [7648][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:09.140 GMT [7648][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:09.145 GMT [7648][postmaster] LOG: background worker "logical replication launcher" (PID 4596) exited with exit code 1 2024-03-12 07:47:09.145 GMT [6868][checkpointer] LOG: shutting down 2024-03-12 07:47:09.145 GMT [6868][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:09.148 GMT [6868][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/40C7FF8, redo lsn=0/40C7FF8 2024-03-12 07:47:09.152 GMT [7648][postmaster] LOG: database system is shut down 2024-03-12 07:47:09.297 GMT [8108][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:09.297 GMT [8108][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:09.298 GMT [8108][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:09.318 GMT [2492][startup] LOG: database system was shut down at 2024-03-12 07:47:09 GMT 2024-03-12 07:47:09.327 GMT [8108][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:09.399 GMT [3900][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50409 2024-03-12 07:47:09.407 GMT [3900][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-12 07:47:09.407 GMT [3900][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-12 07:47:09.419 GMT [3900][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_g5O6/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-12 07:47:09.421 GMT [3900][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb host=pg-loadbalancetest port=50409 2024-03-12 07:47:09.507 GMT [4284][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50410 2024-03-12 07:47:09.514 GMT [4284][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-12 07:47:09.514 GMT [4284][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-12 07:47:09.569 GMT [4892][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50411 2024-03-12 07:47:09.576 GMT [4892][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-12 07:47:09.576 GMT [4892][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-12 07:47:09.606 GMT [8108][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:09.606 GMT [8108][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:09.611 GMT [8108][postmaster] LOG: background worker "logical replication launcher" (PID 2428) exited with exit code 1 2024-03-12 07:47:09.611 GMT [5872][checkpointer] LOG: shutting down 2024-03-12 07:47:09.612 GMT [5872][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:09.614 GMT [5872][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/40C8088, redo lsn=0/40C8088 2024-03-12 07:47:09.620 GMT [8108][postmaster] LOG: database system is shut down 2024-03-12 07:47:09.770 GMT [7940][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:09.770 GMT [7940][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:09.772 GMT [7940][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:09.798 GMT [2004][startup] LOG: database system was shut down at 2024-03-12 07:47:09 GMT 2024-03-12 07:47:09.805 GMT [7940][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:09.876 GMT [7220][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50412 2024-03-12 07:47:09.883 GMT [7220][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-12 07:47:09.883 GMT [7220][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-12 07:47:09.949 GMT [7940][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:09.950 GMT [7940][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:09.953 GMT [7940][postmaster] LOG: background worker "logical replication launcher" (PID 6816) exited with exit code 1 2024-03-12 07:47:09.954 GMT [4000][checkpointer] LOG: shutting down 2024-03-12 07:47:09.954 GMT [4000][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:09.956 GMT [4000][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/40C8100, redo lsn=0/40C8100 2024-03-12 07:47:09.961 GMT [7940][postmaster] LOG: database system is shut down 2024-03-12 07:47:10.108 GMT [3128][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:10.108 GMT [3128][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:10.110 GMT [3128][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:10.128 GMT [4808][startup] LOG: database system was shut down at 2024-03-12 07:47:09 GMT 2024-03-12 07:47:10.135 GMT [3128][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:10.209 GMT [4812][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50414 2024-03-12 07:47:10.217 GMT [4812][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-12 07:47:10.217 GMT [4812][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-12 07:47:10.270 GMT [7500][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50415 2024-03-12 07:47:10.278 GMT [7500][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: certificate verify failed 2024-03-12 07:47:10.278 GMT [7500][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-12 07:47:10.309 GMT [3128][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:10.309 GMT [3128][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:10.312 GMT [3128][postmaster] LOG: background worker "logical replication launcher" (PID 5116) exited with exit code 1 2024-03-12 07:47:10.313 GMT [6736][checkpointer] LOG: shutting down 2024-03-12 07:47:10.313 GMT [6736][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:10.316 GMT [6736][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8178, redo lsn=0/40C8178 2024-03-12 07:47:10.320 GMT [3128][postmaster] LOG: database system is shut down 2024-03-12 07:47:10.469 GMT [7072][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:10.470 GMT [7072][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:10.471 GMT [7072][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:10.492 GMT [5376][startup] LOG: database system was shut down at 2024-03-12 07:47:10 GMT 2024-03-12 07:47:10.500 GMT [7072][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:10.572 GMT [3812][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50416 2024-03-12 07:47:10.576 GMT [3812][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:10.576 GMT [3812][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:10.634 GMT [6284][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50417 2024-03-12 07:47:10.641 GMT [6284][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-12 07:47:10.641 GMT [6284][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-12 07:47:10.654 GMT [6284][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-12 07:47:10.657 GMT [6284][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50417 2024-03-12 07:47:10.716 GMT [7072][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:10.716 GMT [7072][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:10.720 GMT [7072][postmaster] LOG: background worker "logical replication launcher" (PID 2704) exited with exit code 1 2024-03-12 07:47:10.720 GMT [4500][checkpointer] LOG: shutting down 2024-03-12 07:47:10.720 GMT [4500][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:10.723 GMT [4500][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/40C81F0, redo lsn=0/40C81F0 2024-03-12 07:47:10.728 GMT [7072][postmaster] LOG: database system is shut down 2024-03-12 07:47:10.874 GMT [7036][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:10.875 GMT [7036][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:10.876 GMT [7036][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:10.895 GMT [7128][startup] LOG: database system was shut down at 2024-03-12 07:47:10 GMT 2024-03-12 07:47:10.902 GMT [7036][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:10.976 GMT [5520][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50418 2024-03-12 07:47:10.979 GMT [5520][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:10.979 GMT [5520][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:11.036 GMT [1164][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50419 2024-03-12 07:47:11.043 GMT [1164][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-12 07:47:11.043 GMT [1164][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-12 07:47:11.055 GMT [1164][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-12 07:47:11.058 GMT [1164][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50419 2024-03-12 07:47:11.122 GMT [7036][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:11.122 GMT [7036][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:11.125 GMT [7036][postmaster] LOG: background worker "logical replication launcher" (PID 6720) exited with exit code 1 2024-03-12 07:47:11.126 GMT [2500][checkpointer] LOG: shutting down 2024-03-12 07:47:11.126 GMT [2500][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:11.129 GMT [2500][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8268, redo lsn=0/40C8268 2024-03-12 07:47:11.133 GMT [7036][postmaster] LOG: database system is shut down 2024-03-12 07:47:11.280 GMT [8132][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:11.281 GMT [8132][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:11.282 GMT [8132][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:11.299 GMT [5928][startup] LOG: database system was shut down at 2024-03-12 07:47:11 GMT 2024-03-12 07:47:11.306 GMT [8132][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:11.382 GMT [6660][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50420 2024-03-12 07:47:11.385 GMT [6660][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:11.385 GMT [6660][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:11.443 GMT [6544][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50421 2024-03-12 07:47:11.450 GMT [6544][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-12 07:47:11.450 GMT [6544][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-12 07:47:11.463 GMT [6544][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-12 07:47:11.466 GMT [6544][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50421 2024-03-12 07:47:11.528 GMT [8132][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:11.528 GMT [8132][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:11.536 GMT [8132][postmaster] LOG: background worker "logical replication launcher" (PID 5456) exited with exit code 1 2024-03-12 07:47:11.537 GMT [6900][checkpointer] LOG: shutting down 2024-03-12 07:47:11.537 GMT [6900][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:11.540 GMT [6900][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/40C82E0, redo lsn=0/40C82E0 2024-03-12 07:47:11.544 GMT [8132][postmaster] LOG: database system is shut down 2024-03-12 07:47:11.686 GMT [4148][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:11.687 GMT [4148][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:11.688 GMT [4148][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:11.708 GMT [5180][startup] LOG: database system was shut down at 2024-03-12 07:47:11 GMT 2024-03-12 07:47:11.715 GMT [4148][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:11.789 GMT [7640][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50422 2024-03-12 07:47:11.792 GMT [7640][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:11.793 GMT [7640][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:11.857 GMT [2200][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50423 2024-03-12 07:47:11.864 GMT [2200][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-12 07:47:11.864 GMT [2200][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-12 07:47:11.876 GMT [2200][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-12 07:47:11.879 GMT [2200][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50423 2024-03-12 07:47:11.939 GMT [4148][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:11.939 GMT [4148][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:11.944 GMT [4148][postmaster] LOG: background worker "logical replication launcher" (PID 1260) exited with exit code 1 2024-03-12 07:47:11.945 GMT [4240][checkpointer] LOG: shutting down 2024-03-12 07:47:11.945 GMT [4240][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:11.948 GMT [4240][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/40C8358, redo lsn=0/40C8358 2024-03-12 07:47:11.952 GMT [4148][postmaster] LOG: database system is shut down 2024-03-12 07:47:12.118 GMT [5168][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:12.119 GMT [5168][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:12.120 GMT [5168][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:12.162 GMT [6380][startup] LOG: database system was shut down at 2024-03-12 07:47:11 GMT 2024-03-12 07:47:12.170 GMT [5168][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:12.307 GMT [8016][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50424 2024-03-12 07:47:12.310 GMT [8016][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:12.310 GMT [8016][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:12.369 GMT [7864][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50425 2024-03-12 07:47:12.375 GMT [7864][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-12 07:47:12.375 GMT [7864][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-12 07:47:12.388 GMT [7864][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-12 07:47:12.391 GMT [7864][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50425 2024-03-12 07:47:12.453 GMT [5168][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:12.453 GMT [5168][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:12.456 GMT [5168][postmaster] LOG: background worker "logical replication launcher" (PID 6048) exited with exit code 1 2024-03-12 07:47:12.457 GMT [5396][checkpointer] LOG: shutting down 2024-03-12 07:47:12.457 GMT [5396][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:12.460 GMT [5396][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/40C83D0, redo lsn=0/40C83D0 2024-03-12 07:47:12.465 GMT [5168][postmaster] LOG: database system is shut down 2024-03-12 07:47:12.612 GMT [3736][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:12.612 GMT [3736][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:12.613 GMT [3736][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:12.636 GMT [4420][startup] LOG: database system was shut down at 2024-03-12 07:47:12 GMT 2024-03-12 07:47:12.644 GMT [3736][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:12.716 GMT [4268][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50426 2024-03-12 07:47:12.720 GMT [4268][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:12.720 GMT [4268][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:12.774 GMT [5660][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50427 2024-03-12 07:47:12.781 GMT [5660][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-12 07:47:12.781 GMT [5660][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-12 07:47:12.793 GMT [5660][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-12 07:47:12.796 GMT [5660][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50427 2024-03-12 07:47:12.859 GMT [3736][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:12.859 GMT [3736][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:12.863 GMT [3736][postmaster] LOG: background worker "logical replication launcher" (PID 7760) exited with exit code 1 2024-03-12 07:47:12.863 GMT [4772][checkpointer] LOG: shutting down 2024-03-12 07:47:12.863 GMT [4772][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:12.866 GMT [4772][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8448, redo lsn=0/40C8448 2024-03-12 07:47:12.870 GMT [3736][postmaster] LOG: database system is shut down 2024-03-12 07:47:13.022 GMT [4568][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:13.023 GMT [4568][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:13.024 GMT [4568][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:13.043 GMT [4588][startup] LOG: database system was shut down at 2024-03-12 07:47:12 GMT 2024-03-12 07:47:13.051 GMT [4568][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:13.125 GMT [8004][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50428 2024-03-12 07:47:13.128 GMT [8004][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:13.129 GMT [8004][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:13.186 GMT [5408][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50429 2024-03-12 07:47:13.193 GMT [5408][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-12 07:47:13.193 GMT [5408][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-12 07:47:13.206 GMT [5408][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-12 07:47:13.209 GMT [5408][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50429 2024-03-12 07:47:13.268 GMT [4568][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:13.268 GMT [4568][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:13.272 GMT [4568][postmaster] LOG: background worker "logical replication launcher" (PID 5588) exited with exit code 1 2024-03-12 07:47:13.273 GMT [7752][checkpointer] LOG: shutting down 2024-03-12 07:47:13.273 GMT [7752][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:13.276 GMT [7752][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/40C84C0, redo lsn=0/40C84C0 2024-03-12 07:47:13.280 GMT [4568][postmaster] LOG: database system is shut down 2024-03-12 07:47:13.430 GMT [472][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:13.430 GMT [472][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:13.432 GMT [472][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:13.450 GMT [3676][startup] LOG: database system was shut down at 2024-03-12 07:47:13 GMT 2024-03-12 07:47:13.457 GMT [472][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:13.528 GMT [808][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50430 2024-03-12 07:47:13.531 GMT [808][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:13.531 GMT [808][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:13.591 GMT [3140][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50431 2024-03-12 07:47:13.598 GMT [3140][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-12 07:47:13.598 GMT [3140][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-12 07:47:13.611 GMT [3140][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-12 07:47:13.614 GMT [3140][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50431 2024-03-12 07:47:13.675 GMT [472][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:13.675 GMT [472][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:13.679 GMT [472][postmaster] LOG: background worker "logical replication launcher" (PID 7460) exited with exit code 1 2024-03-12 07:47:13.679 GMT [2712][checkpointer] LOG: shutting down 2024-03-12 07:47:13.679 GMT [2712][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:13.682 GMT [2712][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C8538, redo lsn=0/40C8538 2024-03-12 07:47:13.687 GMT [472][postmaster] LOG: database system is shut down 2024-03-12 07:47:13.834 GMT [1960][postmaster] LOG: starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit 2024-03-12 07:47:13.835 GMT [1960][postmaster] LOG: listening on IPv4 address "127.0.0.1", port 49861 2024-03-12 07:47:13.836 GMT [1960][postmaster] LOG: listening on Unix socket "C:/Windows/TEMP/hq3XOnn3DJ/.s.PGSQL.49861" 2024-03-12 07:47:13.855 GMT [7996][startup] LOG: database system was shut down at 2024-03-12 07:47:13 GMT 2024-03-12 07:47:13.862 GMT [1960][postmaster] LOG: database system is ready to accept connections 2024-03-12 07:47:13.934 GMT [4964][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50432 2024-03-12 07:47:13.937 GMT [4964][not initialized] [[unknown]][:0] WARNING: could not read ssl_ocsp_file 2024-03-12 07:47:13.937 GMT [4964][not initialized] [[unknown]][:0] LOG: could not accept SSL connection: A non-blocking socket operation could not be completed immediately. 2024-03-12 07:47:13.994 GMT [2596][not initialized] [[unknown]][:0] LOG: connection received: host=pg-loadbalancetest port=50433 2024-03-12 07:47:14.001 GMT [2596][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-12 07:47:14.001 GMT [2596][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-12 07:47:14.013 GMT [2596][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-12 07:47:14.016 GMT [2596][client backend] [001_ssltests.pl][:0] LOG: disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50433 2024-03-12 07:47:14.035 GMT [1960][postmaster] LOG: received fast shutdown request 2024-03-12 07:47:14.035 GMT [1960][postmaster] LOG: aborting any active transactions 2024-03-12 07:47:14.039 GMT [1960][postmaster] LOG: background worker "logical replication launcher" (PID 5016) exited with exit code 1 2024-03-12 07:47:14.039 GMT [7324][checkpointer] LOG: shutting down 2024-03-12 07:47:14.040 GMT [7324][checkpointer] LOG: checkpoint starting: shutdown immediate 2024-03-12 07:47:14.042 GMT [7324][checkpointer] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C85B0, redo lsn=0/40C85B0 2024-03-12 07:47:14.047 GMT [1960][postmaster] LOG: database system is shut down 2024-03-12 07:47:14.193 GMT [4200][postmaster] FATAL: could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory 2024-03-12 07:47:14.193 GMT [4200][postmaster] LOG: database system is shut down # No postmaster PID for node "primary" [07:47:14.253](0.234s) Bail out! pg_ctl restart failed # No postmaster PID for node "primary"