[05:19:16.982](0.192s) # setting up data directory
# Checking port 49817
# Found port 49817
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=49817 host=C:/Windows/TEMP/OJu2oaVRS9
Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log
[05:19:17.039](0.057s) # 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 3272
[05:19:19.371](2.332s) 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 2260
[05:19:23.352](3.980s) # 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-04-06 05:19:18.930 GMT [3272][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:18.934 GMT [3272][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:18.972 GMT [3928][startup] LOG:  database system was shut down at 2024-04-06 05:09:47 GMT
2024-04-06 05:19:19.036 GMT [3272][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:19.306 GMT [2844][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.308 GMT [2844][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-04-06 05:19:19.308 GMT [2844][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.325 GMT [2844][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-04-06 05:19:19.327 GMT [2844][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.460 GMT [6568][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.462 GMT [6568][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-04-06 05:19:19.462 GMT [6568][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.464 GMT [6568][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-04-06 05:19:19.465 GMT [6568][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.594 GMT [5896][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.596 GMT [5896][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-04-06 05:19:19.596 GMT [5896][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.598 GMT [5896][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-04-06 05:19:19.599 GMT [5896][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.733 GMT [7564][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.734 GMT [7564][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-04-06 05:19:19.734 GMT [7564][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.737 GMT [7564][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-04-06 05:19:19.737 GMT [7564][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.845 GMT [580][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.847 GMT [580][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-04-06 05:19:19.847 GMT [580][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.849 GMT [580][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-04-06 05:19:19.850 GMT [580][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.989 GMT [7980][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.990 GMT [7980][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-04-06 05:19:19.990 GMT [7980][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.992 GMT [7980][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-04-06 05:19:20.284 GMT [7980][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.298 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:20.476 GMT [7568][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:20.478 GMT [7568][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-04-06 05:19:20.478 GMT [7568][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:20.480 GMT [7568][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-04-06 05:19:20.855 GMT [7568][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.381 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:20.933 GMT [5020][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:20.935 GMT [5020][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-04-06 05:19:20.935 GMT [5020][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:20.937 GMT [5020][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-04-06 05:19:21.186 GMT [5020][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.255 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:21.263 GMT [5528][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:21.264 GMT [5528][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-04-06 05:19:21.264 GMT [5528][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:21.267 GMT [5528][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-04-06 05:19:21.612 GMT [5528][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.353 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:21.806 GMT [5208][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:21.808 GMT [5208][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-04-06 05:19:21.808 GMT [5208][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:21.810 GMT [5208][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-04-06 05:19:22.230 GMT [5208][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.426 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:22.368 GMT [6756][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:22.369 GMT [6756][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-04-06 05:19:22.369 GMT [6756][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:22.372 GMT [6756][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-04-06 05:19:22.667 GMT [6756][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.305 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:22.808 GMT [3272][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:22.808 GMT [3272][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:22.820 GMT [3272][postmaster] LOG:  background worker "logical replication launcher" (PID 2440) exited with exit code 1
2024-04-06 05:19:22.824 GMT [5460][checkpointer] LOG:  shutting down
2024-04-06 05:19:22.824 GMT [5460][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:22.997 GMT [5460][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.167 s, sync=0.001 s, total=0.174 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407E518, redo lsn=0/407E518
2024-04-06 05:19:23.052 GMT [3272][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.205 GMT [2260][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:23.206 GMT [2260][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:23.209 GMT [2260][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:23.236 GMT [8176][startup] LOG:  database system was shut down at 2024-04-06 05:19:22 GMT
2024-04-06 05:19:23.251 GMT [2260][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:23.377 GMT [2260][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:23.377 GMT [2260][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:23.384 GMT [2260][postmaster] LOG:  background worker "logical replication launcher" (PID 6804) exited with exit code 1
2024-04-06 05:19:23.384 GMT [6656][checkpointer] LOG:  shutting down
2024-04-06 05:19:23.384 GMT [6656][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:23.387 GMT [6656][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/407E590, redo lsn=0/407E590
2024-04-06 05:19:23.396 GMT [2260][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.587 GMT [6232][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-04-06 05:19:23.587 GMT [6232][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[05:19:23.598](0.247s) 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 6132
[05:19:23.778](0.180s) 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-04-06 05:19:18.930 GMT [3272][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:18.934 GMT [3272][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:18.972 GMT [3928][startup] LOG:  database system was shut down at 2024-04-06 05:09:47 GMT
2024-04-06 05:19:19.036 GMT [3272][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:19.306 GMT [2844][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.308 GMT [2844][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-04-06 05:19:19.308 GMT [2844][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.325 GMT [2844][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-04-06 05:19:19.327 GMT [2844][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.460 GMT [6568][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.462 GMT [6568][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-04-06 05:19:19.462 GMT [6568][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.464 GMT [6568][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-04-06 05:19:19.465 GMT [6568][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.594 GMT [5896][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.596 GMT [5896][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-04-06 05:19:19.596 GMT [5896][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.598 GMT [5896][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-04-06 05:19:19.599 GMT [5896][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.733 GMT [7564][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.734 GMT [7564][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-04-06 05:19:19.734 GMT [7564][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.737 GMT [7564][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-04-06 05:19:19.737 GMT [7564][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.845 GMT [580][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.847 GMT [580][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-04-06 05:19:19.847 GMT [580][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.849 GMT [580][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-04-06 05:19:19.850 GMT [580][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.989 GMT [7980][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.990 GMT [7980][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-04-06 05:19:19.990 GMT [7980][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.992 GMT [7980][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-04-06 05:19:20.284 GMT [7980][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.298 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:20.476 GMT [7568][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:20.478 GMT [7568][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-04-06 05:19:20.478 GMT [7568][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:20.480 GMT [7568][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-04-06 05:19:20.855 GMT [7568][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.381 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:20.933 GMT [5020][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:20.935 GMT [5020][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-04-06 05:19:20.935 GMT [5020][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:20.937 GMT [5020][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-04-06 05:19:21.186 GMT [5020][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.255 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:21.263 GMT [5528][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:21.264 GMT [5528][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-04-06 05:19:21.264 GMT [5528][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:21.267 GMT [5528][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-04-06 05:19:21.612 GMT [5528][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.353 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:21.806 GMT [5208][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:21.808 GMT [5208][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-04-06 05:19:21.808 GMT [5208][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:21.810 GMT [5208][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-04-06 05:19:22.230 GMT [5208][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.426 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:22.368 GMT [6756][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:22.369 GMT [6756][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-04-06 05:19:22.369 GMT [6756][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:22.372 GMT [6756][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-04-06 05:19:22.667 GMT [6756][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.305 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:22.808 GMT [3272][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:22.808 GMT [3272][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:22.820 GMT [3272][postmaster] LOG:  background worker "logical replication launcher" (PID 2440) exited with exit code 1
2024-04-06 05:19:22.824 GMT [5460][checkpointer] LOG:  shutting down
2024-04-06 05:19:22.824 GMT [5460][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:22.997 GMT [5460][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.167 s, sync=0.001 s, total=0.174 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407E518, redo lsn=0/407E518
2024-04-06 05:19:23.052 GMT [3272][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.205 GMT [2260][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:23.206 GMT [2260][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:23.209 GMT [2260][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:23.236 GMT [8176][startup] LOG:  database system was shut down at 2024-04-06 05:19:22 GMT
2024-04-06 05:19:23.251 GMT [2260][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:23.377 GMT [2260][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:23.377 GMT [2260][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:23.384 GMT [2260][postmaster] LOG:  background worker "logical replication launcher" (PID 6804) exited with exit code 1
2024-04-06 05:19:23.384 GMT [6656][checkpointer] LOG:  shutting down
2024-04-06 05:19:23.384 GMT [6656][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:23.387 GMT [6656][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/407E590, redo lsn=0/407E590
2024-04-06 05:19:23.396 GMT [2260][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.587 GMT [6232][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-04-06 05:19:23.587 GMT [6232][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.697 GMT [6132][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:23.697 GMT [6132][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:23.698 GMT [6132][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:23.721 GMT [2432][startup] LOG:  database system was shut down at 2024-04-06 05:19:23 GMT
2024-04-06 05:19:23.736 GMT [6132][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:23.806 GMT [6132][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:23.806 GMT [6132][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:23.838 GMT [6132][postmaster] LOG:  background worker "logical replication launcher" (PID 1276) exited with exit code 1
2024-04-06 05:19:23.839 GMT [6208][checkpointer] LOG:  shutting down
2024-04-06 05:19:23.840 GMT [6208][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:23.845 GMT [6208][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.003 s, sync=0.001 s, total=0.007 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407E608, redo lsn=0/407E608
2024-04-06 05:19:23.856 GMT [6132][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.968 GMT [848][postmaster] FATAL:  could not set SSL protocol version range
2024-04-06 05:19:23.968 GMT [848][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-04-06 05:19:23.968 GMT [848][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[05:19:24.039](0.261s) 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 4652
[05:19:24.337](0.298s) ok 5 - restart succeeds with correct SSL protocol bounds
[05:19:24.338](0.001s) # running client tests
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 8028
[05:19:24.821](0.484s) ok 6 - server doesn't accept non-SSL connections
[05:19:24.822](0.001s) ok 7 - server doesn't accept non-SSL connections: matches
[05:19:25.049](0.227s) ok 8 - connect without server root cert sslmode=require
[05:19:25.049](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr
[05:19:25.150](0.100s) ok 10 - connect without server root cert sslmode=verify-ca
[05:19:25.150](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[05:19:25.338](0.188s) ok 12 - connect without server root cert sslmode=verify-full
[05:19:25.338](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches
[05:19:25.464](0.126s) ok 14 - connect with wrong server root cert sslmode=require
[05:19:25.465](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches
[05:19:25.527](0.062s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[05:19:25.527](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[05:19:25.683](0.156s) ok 18 - connect with wrong server root cert sslmode=verify-full
[05:19:25.683](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[05:19:25.761](0.078s) ok 20 - connect with server CA cert, without root CA
[05:19:25.762](0.001s) ok 21 - connect with server CA cert, without root CA: matches
[05:19:25.853](0.092s) ok 22 - connect with correct server CA cert file sslmode=require
[05:19:25.854](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[05:19:25.935](0.081s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[05:19:25.935](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[05:19:26.041](0.106s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[05:19:26.041](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[05:19:26.134](0.092s) ok 28 - cert root file that contains two certificates, order 1
[05:19:26.134](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[05:19:26.347](0.213s) ok 30 - cert root file that contains two certificates, order 2
[05:19:26.347](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[05:19:26.494](0.147s) ok 32 - connect with sslcertmode=disable
[05:19:26.494](0.000s) ok 33 - connect with sslcertmode=disable: no stderr
[05:19:26.606](0.111s) ok 34 - connect with sslcertmode=allow
[05:19:26.606](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[05:19:26.711](0.105s) ok 36 - connect with sslcertmode=require fails without a client certificate
[05:19:26.711](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[05:19:26.800](0.089s) ok 38 - sslcrl option with invalid file name
[05:19:26.800](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[05:19:26.906](0.106s) ok 40 - CRL belonging to a different CA
[05:19:26.907](0.000s) ok 41 - CRL belonging to a different CA: matches
[05:19:27.012](0.105s) ok 42 - directory CRL belonging to a different CA
[05:19:27.012](0.000s) ok 43 - directory CRL belonging to a different CA: matches
[05:19:27.105](0.093s) ok 44 - CRL with a non-revoked cert
[05:19:27.105](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[05:19:27.261](0.155s) ok 46 - directory CRL with a non-revoked cert
[05:19:27.261](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr
[05:19:27.340](0.079s) ok 48 - mismatch between host name and server certificate sslmode=require
[05:19:27.340](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[05:19:27.669](0.329s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[05:19:27.669](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[05:19:27.776](0.107s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[05:19:27.776](0.000s) ok 53 - mismatch between host name and server certificate sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 7532
[05:19:28.121](0.345s) ok 54 - IP address in the Common Name
[05:19:28.121](0.000s) ok 55 - IP address in the Common Name: no stderr
[05:19:28.186](0.064s) ok 56 - mismatch between host name and server certificate IP address
[05:19:28.186](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 5240
[05:19:28.530](0.344s) ok 58 - IP address in a dNSName
[05:19:28.530](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 5916
[05:19:28.826](0.296s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[05:19:28.827](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[05:19:28.893](0.066s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[05:19:28.893](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[05:19:28.950](0.057s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[05:19:28.950](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[05:19:29.013](0.062s) ok 66 - host name not matching with X.509 Subject Alternative Names
[05:19:29.013](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[05:19:29.076](0.063s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[05:19:29.076](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 6344
[05:19:29.373](0.297s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[05:19:29.373](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[05:19:29.434](0.061s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[05:19:29.434](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[05:19:29.496](0.062s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[05:19:29.497](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches
[05:19:29.527](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 5420
[05:19:29.872](0.345s) ok 77 - certificate with both a CN and SANs 1
[05:19:29.872](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr
[05:19:29.937](0.065s) ok 79 - certificate with both a CN and SANs 2
[05:19:29.937](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr
[05:19:30.000](0.062s) ok 81 - certificate with both a CN and SANs ignores CN
[05:19:30.000](0.001s) ok 82 - certificate with both a CN and SANs ignores CN: matches
[05:19:30.030](0.030s) ok 83 # skip IPv6 addresses in certificates not support on this platform
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 2620
[05:19:30.376](0.346s) ok 84 - certificate with both an IP CN and DNS SANs matches CN
[05:19:30.376](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[05:19:30.438](0.062s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1
[05:19:30.438](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[05:19:30.500](0.062s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2
[05:19:30.501](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 884
[05:19:30.844](0.343s) ok 90 - server certificate without CN or SANs sslmode=verify-ca
[05:19:30.844](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[05:19:30.907](0.063s) ok 92 - server certificate without CN or SANs sslmode=verify-full
[05:19:30.907](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 7052
[05:19:31.205](0.298s) ok 94 - sslrootcert=system does not connect with private CA
[05:19:31.205](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches
[05:19:31.237](0.031s) ok 96 - sslrootcert=system only accepts sslmode=verify-full
[05:19:31.237](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches
[05:19:31.346](0.109s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE
[05:19:31.346](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[05:19:31.409](0.062s) ok 100 - sslrootcert=system defaults to sslmode=verify-full
[05:19:31.409](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 5856
[05:19:31.831](0.422s) ok 102 - connects without client-side CRL
[05:19:31.831](0.001s) ok 103 - connects without client-side CRL: no stderr
[05:19:31.893](0.062s) ok 104 - does not connect with client-side CRL file
[05:19:31.894](0.000s) ok 105 - does not connect with client-side CRL file: matches
[05:19:31.957](0.063s) ok 106 - does not connect with client-side CRL directory
[05:19:31.958](0.000s) ok 107 - does not connect with client-side CRL directory: matches
# Running: psql -X -A -F , -P null=_null_ -d sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=invalid -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[05:19:32.018](0.060s) ok 108 - pg_stat_ssl view without client certificate: exit code 0
[05:19:32.018](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr
[05:19:32.018](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches
[05:19:32.082](0.064s) ok 111 - connection success with correct range of TLS protocol versions
[05:19:32.083](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr
[05:19:32.113](0.030s) ok 113 - connection failure with incorrect range of TLS protocol versions
[05:19:32.113](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches
[05:19:32.144](0.031s) ok 115 - connection failure with an incorrect SSL protocol minimum bound
[05:19:32.144](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches
[05:19:32.175](0.031s) ok 117 - connection failure with an incorrect SSL protocol maximum bound
[05:19:32.175](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches
[05:19:32.176](0.000s) # running server tests
[05:19:32.238](0.063s) ok 119 - certificate authorization fails without client cert
[05:19:32.239](0.000s) ok 120 - certificate authorization fails without client cert: matches
[05:19:32.347](0.108s) ok 121 - certificate authorization succeeds with correct client cert in PEM format
[05:19:32.347](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[05:19:32.410](0.063s) ok 123 - certificate authorization succeeds with correct client cert in DER format
[05:19:32.410](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr
[05:19:32.472](0.062s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format
[05:19:32.473](0.001s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[05:19:32.534](0.062s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format
[05:19:32.535](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[05:19:32.598](0.063s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require
[05:19:32.598](0.001s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[05:19:32.659](0.061s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[05:19:32.660](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[05:19:32.722](0.062s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable
[05:19:32.722](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[05:19:32.785](0.062s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[05:19:32.785](0.001s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[05:19:32.894](0.109s) ok 137 - certificate authorization succeeds with DN mapping
[05:19:32.895](0.001s) ok 138 - certificate authorization succeeds with DN mapping: no stderr
[05:19:32.895](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches
[05:19:33.003](0.108s) ok 140 - certificate authorization succeeds with DN regex mapping
[05:19:33.003](0.001s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr
[05:19:33.112](0.109s) ok 142 - certificate authorization succeeds with CN mapping
[05:19:33.112](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr
[05:19:33.113](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches
[05:19:33.113](0.000s) not ok 145 # TODO & SKIP Need Pty support
[05:19:33.113](0.000s) not ok 146 # TODO & SKIP Need Pty support
[05:19:33.113](0.000s) not ok 147 # TODO & SKIP Need Pty support
[05:19:33.113](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_jaxw/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[05:19:33.220](0.106s) ok 149 - pg_stat_ssl with client certificate: exit code 0
[05:19:33.220](0.001s) ok 150 - pg_stat_ssl with client certificate: no stderr
[05:19:33.220](0.000s) ok 151 - pg_stat_ssl with client certificate: matches
[05:19:33.221](0.000s) ok 152 # skip Permissions check not enforced on Windows
[05:19:33.221](0.000s) ok 153 # skip Permissions check not enforced on Windows
[05:19:33.285](0.064s) ok 154 - certificate authorization fails with client cert belonging to another user
[05:19:33.285](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches
[05:19:33.347](0.062s) ok 156 - certificate authorization fails with revoked client cert
[05:19:33.347](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches
[05:19:33.348](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match
[05:19:33.411](0.063s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[05:19:33.411](0.000s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[05:19:33.411](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[05:19:33.470](0.059s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[05:19:33.471](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[05:19:33.471](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[05:19:33.533](0.062s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[05:19:33.534](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[05:19:33.534](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 6796
[05:19:33.845](0.311s) ok 168 - intermediate client certificate is provided by client
[05:19:33.846](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr
[05:19:33.908](0.063s) ok 170 - intermediate client certificate is missing
[05:19:33.909](0.000s) ok 171 - intermediate client certificate is missing: matches
[05:19:33.973](0.065s) ok 172 - logged client certificate Subjects are truncated if they're too long
[05:19:33.974](0.001s) ok 173 - logged client certificate Subjects are truncated if they're too long: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 796
[05:19:34.269](0.296s) ok 174 - intermediate client certificate is untrusted
[05:19:34.270](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 7468
[05:19:34.567](0.297s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory
[05:19:34.567](0.001s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[05:19:34.629](0.062s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[05:19:34.630](0.001s) 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 3140
[05:19:34.928](0.298s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1
[05:19:34.928](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923.
[05:19:34.928](0.000s) #          got: '2'
#     expected: '0'
[05:19:34.928](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[05:19:34.928](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923.
[05:19:34.928](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 49817 failed: server closed the connection unexpectedly
# 	This probably means the server terminated abnormally
# 	before or while processing the request.
# SSL SYSCALL error: Connection reset by peer (0x00002746/10054)'
#     expected: ''
[05:19:35.039](0.110s) ok 182 - connect without requesting ocsp response when sslocspstapling=0
[05:19:35.039](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 3160
[05:19:35.335](0.296s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1
[05:19:35.445](0.109s) ok 185 - connect without requesting ocsp response when sslocspstapling=0
[05:19:35.445](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 7740
[05:19:35.741](0.296s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1
[05:19:35.806](0.065s) ok 188 - connect without requesting ocsp response when sslocspstapling=0
[05:19:35.807](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 5484
[05:19:36.101](0.294s) ok 190 - failed with an expired ocsp response when sslocspstapling=1
[05:19:36.210](0.109s) ok 191 - connect without requesting ocsp response when sslocspstapling=0
[05:19:36.211](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 6072
[05:19:36.523](0.312s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1
[05:19:36.523](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001.
[05:19:36.523](0.000s) #          got: '2'
#     expected: '0'
[05:19:36.524](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[05:19:36.524](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001.
[05:19:36.524](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 49817 failed: server closed the connection unexpectedly
# 	This probably means the server terminated abnormally
# 	before or while processing the request.
# SSL SYSCALL error: Connection reset by peer (0x00002746/10054)'
#     expected: ''
[05:19:36.633](0.109s) ok 195 - connect without requesting ocsp response when sslocspstapling=0
[05:19:36.634](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 5432
[05:19:36.931](0.297s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1
[05:19:36.994](0.063s) ok 198 - connect without requesting ocsp response when sslocspstapling=0
[05:19:36.994](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 1240
[05:19:37.306](0.312s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1
[05:19:37.417](0.111s) ok 201 - connect without requesting ocsp response when sslocspstapling=0
[05:19:37.417](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 2132
[05:19:37.712](0.295s) ok 203 - failed with an expired ocsp response when sslocspstapling=1
[05:19:37.822](0.110s) ok 204 - connect without requesting ocsp response when sslocspstapling=0
[05:19:37.822](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 7228
[05:19:38.119](0.297s) ok 206 - failed with an expired ocsp response when sslocspstapling=1
[05:19:38.183](0.064s) ok 207 - connect without requesting ocsp response when sslocspstapling=0
[05:19:38.183](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-04-06 05:19:18.930 GMT [3272][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:18.934 GMT [3272][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:18.972 GMT [3928][startup] LOG:  database system was shut down at 2024-04-06 05:09:47 GMT
2024-04-06 05:19:19.036 GMT [3272][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:19.306 GMT [2844][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.308 GMT [2844][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-04-06 05:19:19.308 GMT [2844][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.325 GMT [2844][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-04-06 05:19:19.327 GMT [2844][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.460 GMT [6568][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.462 GMT [6568][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-04-06 05:19:19.462 GMT [6568][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.464 GMT [6568][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-04-06 05:19:19.465 GMT [6568][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.594 GMT [5896][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.596 GMT [5896][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-04-06 05:19:19.596 GMT [5896][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.598 GMT [5896][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-04-06 05:19:19.599 GMT [5896][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.733 GMT [7564][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.734 GMT [7564][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-04-06 05:19:19.734 GMT [7564][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.737 GMT [7564][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-04-06 05:19:19.737 GMT [7564][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.845 GMT [580][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.847 GMT [580][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-04-06 05:19:19.847 GMT [580][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.849 GMT [580][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-04-06 05:19:19.850 GMT [580][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:19.989 GMT [7980][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:19.990 GMT [7980][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-04-06 05:19:19.990 GMT [7980][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:19.992 GMT [7980][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-04-06 05:19:20.284 GMT [7980][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.298 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:20.476 GMT [7568][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:20.478 GMT [7568][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-04-06 05:19:20.478 GMT [7568][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:20.480 GMT [7568][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-04-06 05:19:20.855 GMT [7568][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.381 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:20.933 GMT [5020][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:20.935 GMT [5020][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-04-06 05:19:20.935 GMT [5020][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:20.937 GMT [5020][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-04-06 05:19:21.186 GMT [5020][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.255 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:21.263 GMT [5528][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:21.264 GMT [5528][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-04-06 05:19:21.264 GMT [5528][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:21.267 GMT [5528][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-04-06 05:19:21.612 GMT [5528][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.353 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:21.806 GMT [5208][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:21.808 GMT [5208][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-04-06 05:19:21.808 GMT [5208][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:21.810 GMT [5208][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-04-06 05:19:22.230 GMT [5208][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.426 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:22.368 GMT [6756][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-06 05:19:22.369 GMT [6756][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-04-06 05:19:22.369 GMT [6756][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-06 05:19:22.372 GMT [6756][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-04-06 05:19:22.667 GMT [6756][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.305 user=SYSTEM database=postgres host=[local]
2024-04-06 05:19:22.808 GMT [3272][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:22.808 GMT [3272][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:22.820 GMT [3272][postmaster] LOG:  background worker "logical replication launcher" (PID 2440) exited with exit code 1
2024-04-06 05:19:22.824 GMT [5460][checkpointer] LOG:  shutting down
2024-04-06 05:19:22.824 GMT [5460][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:22.997 GMT [5460][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.167 s, sync=0.001 s, total=0.174 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407E518, redo lsn=0/407E518
2024-04-06 05:19:23.052 GMT [3272][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.205 GMT [2260][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:23.206 GMT [2260][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:23.209 GMT [2260][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:23.236 GMT [8176][startup] LOG:  database system was shut down at 2024-04-06 05:19:22 GMT
2024-04-06 05:19:23.251 GMT [2260][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:23.377 GMT [2260][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:23.377 GMT [2260][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:23.384 GMT [2260][postmaster] LOG:  background worker "logical replication launcher" (PID 6804) exited with exit code 1
2024-04-06 05:19:23.384 GMT [6656][checkpointer] LOG:  shutting down
2024-04-06 05:19:23.384 GMT [6656][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:23.387 GMT [6656][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/407E590, redo lsn=0/407E590
2024-04-06 05:19:23.396 GMT [2260][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.587 GMT [6232][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-04-06 05:19:23.587 GMT [6232][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.697 GMT [6132][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:23.697 GMT [6132][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:23.698 GMT [6132][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:23.721 GMT [2432][startup] LOG:  database system was shut down at 2024-04-06 05:19:23 GMT
2024-04-06 05:19:23.736 GMT [6132][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:23.806 GMT [6132][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:23.806 GMT [6132][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:23.838 GMT [6132][postmaster] LOG:  background worker "logical replication launcher" (PID 1276) exited with exit code 1
2024-04-06 05:19:23.839 GMT [6208][checkpointer] LOG:  shutting down
2024-04-06 05:19:23.840 GMT [6208][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:23.845 GMT [6208][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.003 s, sync=0.001 s, total=0.007 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407E608, redo lsn=0/407E608
2024-04-06 05:19:23.856 GMT [6132][postmaster] LOG:  database system is shut down
2024-04-06 05:19:23.968 GMT [848][postmaster] FATAL:  could not set SSL protocol version range
2024-04-06 05:19:23.968 GMT [848][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-04-06 05:19:23.968 GMT [848][postmaster] LOG:  database system is shut down
2024-04-06 05:19:24.236 GMT [4652][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:24.237 GMT [4652][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:24.238 GMT [4652][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:24.267 GMT [7132][startup] LOG:  database system was shut down at 2024-04-06 05:19:23 GMT
2024-04-06 05:19:24.287 GMT [4652][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:24.375 GMT [4652][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:24.376 GMT [4652][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:24.388 GMT [4652][postmaster] LOG:  background worker "logical replication launcher" (PID 4620) exited with exit code 1
2024-04-06 05:19:24.390 GMT [5600][checkpointer] LOG:  shutting down
2024-04-06 05:19:24.391 GMT [5600][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:24.395 GMT [5600][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/407E680, redo lsn=0/407E680
2024-04-06 05:19:24.409 GMT [4652][postmaster] LOG:  database system is shut down
2024-04-06 05:19:24.555 GMT [8028][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:24.556 GMT [8028][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:24.557 GMT [8028][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:24.581 GMT [2420][startup] LOG:  database system was shut down at 2024-04-06 05:19:24 GMT
2024-04-06 05:19:24.594 GMT [8028][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:24.762 GMT [1280][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50392
2024-04-06 05:19:24.763 GMT [1280][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-04-06 05:19:24.763 GMT [1280][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "pg-loadbalancetest", forward lookup not checked.
2024-04-06 05:19:24.879 GMT [6284][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50395
2024-04-06 05:19:24.885 GMT [6284][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-04-06 05:19:24.885 GMT [6284][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-04-06 05:19:24.960 GMT [6284][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-04-06 05:19:24.963 GMT [6284][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.090 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50395
2024-04-06 05:19:25.124 GMT [3684][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50398
2024-04-06 05:19:25.136 GMT [3684][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-04-06 05:19:25.253 GMT [4912][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50400
2024-04-06 05:19:25.264 GMT [4912][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-04-06 05:19:25.387 GMT [6332][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50402
2024-04-06 05:19:25.393 GMT [6332][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-06 05:19:25.508 GMT [6948][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50404
2024-04-06 05:19:25.514 GMT [6948][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-06 05:19:25.576 GMT [5468][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50406
2024-04-06 05:19:25.581 GMT [5468][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-06 05:19:25.727 GMT [7516][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50408
2024-04-06 05:19:25.732 GMT [7516][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-06 05:19:25.812 GMT [7404][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50412
2024-04-06 05:19:25.819 GMT [7404][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-04-06 05:19:25.819 GMT [7404][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-04-06 05:19:25.822 GMT [7404][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-04-06 05:19:25.825 GMT [7404][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50412
2024-04-06 05:19:25.900 GMT [5328][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50413
2024-04-06 05:19:25.907 GMT [5328][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-04-06 05:19:25.907 GMT [5328][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-04-06 05:19:25.909 GMT [5328][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-04-06 05:19:25.912 GMT [5328][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50413
2024-04-06 05:19:25.987 GMT [5588][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50415
2024-04-06 05:19:25.995 GMT [5588][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-04-06 05:19:25.995 GMT [5588][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-04-06 05:19:25.998 GMT [5588][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-04-06 05:19:26.001 GMT [5588][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50415
2024-04-06 05:19:26.093 GMT [7848][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50418
2024-04-06 05:19:26.100 GMT [7848][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-04-06 05:19:26.100 GMT [7848][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-04-06 05:19:26.103 GMT [7848][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-04-06 05:19:26.107 GMT [7848][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50418
2024-04-06 05:19:26.251 GMT [5144][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50419
2024-04-06 05:19:26.260 GMT [5144][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-04-06 05:19:26.260 GMT [5144][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-04-06 05:19:26.263 GMT [5144][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-04-06 05:19:26.266 GMT [5144][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50419
2024-04-06 05:19:26.417 GMT [7788][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50421
2024-04-06 05:19:26.424 GMT [7788][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-04-06 05:19:26.424 GMT [7788][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-04-06 05:19:26.447 GMT [7788][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-04-06 05:19:26.449 GMT [7788][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.043 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50421
2024-04-06 05:19:26.557 GMT [4332][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50423
2024-04-06 05:19:26.569 GMT [4332][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-04-06 05:19:26.569 GMT [4332][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-04-06 05:19:26.571 GMT [4332][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-04-06 05:19:26.575 GMT [4332][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50423
2024-04-06 05:19:26.657 GMT [7488][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50424
2024-04-06 05:19:26.664 GMT [7488][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-04-06 05:19:26.664 GMT [7488][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-04-06 05:19:26.677 GMT [7488][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50424
2024-04-06 05:19:26.755 GMT [580][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50425
2024-04-06 05:19:26.762 GMT [580][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-04-06 05:19:26.762 GMT [580][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-04-06 05:19:26.765 GMT [580][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-04-06 05:19:26.768 GMT [580][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50425
2024-04-06 05:19:26.844 GMT [5852][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50426
2024-04-06 05:19:26.849 GMT [5852][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-06 05:19:26.954 GMT [2964][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50427
2024-04-06 05:19:26.959 GMT [2964][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-06 05:19:27.059 GMT [7132][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50428
2024-04-06 05:19:27.066 GMT [7132][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-04-06 05:19:27.066 GMT [7132][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-04-06 05:19:27.072 GMT [7132][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-04-06 05:19:27.075 GMT [7132][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50428
2024-04-06 05:19:27.197 GMT [4460][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50429
2024-04-06 05:19:27.205 GMT [4460][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-04-06 05:19:27.205 GMT [4460][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-04-06 05:19:27.207 GMT [4460][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-04-06 05:19:27.211 GMT [4460][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50429
2024-04-06 05:19:27.308 GMT [5784][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50430
2024-04-06 05:19:27.315 GMT [5784][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-04-06 05:19:27.315 GMT [5784][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-04-06 05:19:27.318 GMT [5784][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-04-06 05:19:27.320 GMT [5784][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50430
2024-04-06 05:19:27.385 GMT [4888][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50431
2024-04-06 05:19:27.392 GMT [4888][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-04-06 05:19:27.392 GMT [4888][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-04-06 05:19:27.395 GMT [4888][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-04-06 05:19:27.397 GMT [4888][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50431
2024-04-06 05:19:27.718 GMT [2808][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50432
2024-04-06 05:19:27.794 GMT [8028][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:27.794 GMT [8028][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:27.798 GMT [8028][postmaster] LOG:  background worker "logical replication launcher" (PID 6028) exited with exit code 1
2024-04-06 05:19:27.800 GMT [2112][checkpointer] LOG:  shutting down
2024-04-06 05:19:27.800 GMT [2112][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:27.803 GMT [2112][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/407E6F8, redo lsn=0/407E6F8
2024-04-06 05:19:27.809 GMT [8028][postmaster] LOG:  database system is shut down
2024-04-06 05:19:27.959 GMT [7532][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:27.959 GMT [7532][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:27.961 GMT [7532][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:27.980 GMT [7044][startup] LOG:  database system was shut down at 2024-04-06 05:19:27 GMT
2024-04-06 05:19:27.988 GMT [7532][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:28.053 GMT [4292][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50433
2024-04-06 05:19:28.060 GMT [4292][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-04-06 05:19:28.060 GMT [4292][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-04-06 05:19:28.073 GMT [4292][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-04-06 05:19:28.076 GMT [4292][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50433
2024-04-06 05:19:28.162 GMT [7356][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50434
2024-04-06 05:19:28.202 GMT [7532][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:28.202 GMT [7532][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:28.206 GMT [7532][postmaster] LOG:  background worker "logical replication launcher" (PID 1724) exited with exit code 1
2024-04-06 05:19:28.206 GMT [4212][checkpointer] LOG:  shutting down
2024-04-06 05:19:28.206 GMT [4212][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:28.209 GMT [4212][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/407E770, redo lsn=0/407E770
2024-04-06 05:19:28.213 GMT [7532][postmaster] LOG:  database system is shut down
2024-04-06 05:19:28.364 GMT [5240][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:28.364 GMT [5240][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:28.365 GMT [5240][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:28.393 GMT [8176][startup] LOG:  database system was shut down at 2024-04-06 05:19:28 GMT
2024-04-06 05:19:28.400 GMT [5240][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:28.461 GMT [7320][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50435
2024-04-06 05:19:28.468 GMT [7320][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-04-06 05:19:28.468 GMT [7320][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-04-06 05:19:28.481 GMT [7320][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-04-06 05:19:28.483 GMT [7320][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50435
2024-04-06 05:19:28.549 GMT [5240][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:28.549 GMT [5240][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:28.556 GMT [5240][postmaster] LOG:  background worker "logical replication launcher" (PID 4020) exited with exit code 1
2024-04-06 05:19:28.556 GMT [836][checkpointer] LOG:  shutting down
2024-04-06 05:19:28.556 GMT [836][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:28.559 GMT [836][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/407E7E8, redo lsn=0/407E7E8
2024-04-06 05:19:28.568 GMT [5240][postmaster] LOG:  database system is shut down
2024-04-06 05:19:28.708 GMT [5916][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:28.708 GMT [5916][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:28.709 GMT [5916][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:28.729 GMT [1596][startup] LOG:  database system was shut down at 2024-04-06 05:19:28 GMT
2024-04-06 05:19:28.736 GMT [5916][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:28.804 GMT [6460][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50436
2024-04-06 05:19:28.811 GMT [6460][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-04-06 05:19:28.811 GMT [6460][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-04-06 05:19:28.823 GMT [6460][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-04-06 05:19:28.825 GMT [6460][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50436
2024-04-06 05:19:28.867 GMT [8040][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50437
2024-04-06 05:19:28.874 GMT [8040][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-04-06 05:19:28.874 GMT [8040][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-04-06 05:19:28.877 GMT [8040][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-04-06 05:19:28.879 GMT [8040][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50437
2024-04-06 05:19:28.934 GMT [5252][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50438
2024-04-06 05:19:28.942 GMT [5252][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-04-06 05:19:28.942 GMT [5252][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-04-06 05:19:28.944 GMT [5252][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-04-06 05:19:28.946 GMT [5252][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50438
2024-04-06 05:19:28.989 GMT [4128][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50439
2024-04-06 05:19:29.052 GMT [5312][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50440
2024-04-06 05:19:29.092 GMT [5916][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:29.093 GMT [5916][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:29.096 GMT [5916][postmaster] LOG:  background worker "logical replication launcher" (PID 3060) exited with exit code 1
2024-04-06 05:19:29.097 GMT [5960][checkpointer] LOG:  shutting down
2024-04-06 05:19:29.097 GMT [5960][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:29.100 GMT [5960][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/407E860, redo lsn=0/407E860
2024-04-06 05:19:29.104 GMT [5916][postmaster] LOG:  database system is shut down
2024-04-06 05:19:29.257 GMT [6344][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:29.258 GMT [6344][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:29.259 GMT [6344][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:29.280 GMT [4704][startup] LOG:  database system was shut down at 2024-04-06 05:19:29 GMT
2024-04-06 05:19:29.288 GMT [6344][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:29.350 GMT [5152][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50441
2024-04-06 05:19:29.357 GMT [5152][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-04-06 05:19:29.357 GMT [5152][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-04-06 05:19:29.369 GMT [5152][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-04-06 05:19:29.372 GMT [5152][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50441
2024-04-06 05:19:29.416 GMT [1816][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50442
2024-04-06 05:19:29.475 GMT [5820][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50443
2024-04-06 05:19:29.544 GMT [6344][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:29.544 GMT [6344][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:29.549 GMT [6344][postmaster] LOG:  background worker "logical replication launcher" (PID 7624) exited with exit code 1
2024-04-06 05:19:29.550 GMT [4524][checkpointer] LOG:  shutting down
2024-04-06 05:19:29.550 GMT [4524][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:29.552 GMT [4524][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/407E8D8, redo lsn=0/407E8D8
2024-04-06 05:19:29.556 GMT [6344][postmaster] LOG:  database system is shut down
2024-04-06 05:19:29.708 GMT [5420][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:29.709 GMT [5420][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:29.710 GMT [5420][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:29.736 GMT [5072][startup] LOG:  database system was shut down at 2024-04-06 05:19:29 GMT
2024-04-06 05:19:29.744 GMT [5420][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:29.807 GMT [6480][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50444
2024-04-06 05:19:29.814 GMT [6480][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-04-06 05:19:29.814 GMT [6480][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-04-06 05:19:29.827 GMT [6480][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-04-06 05:19:29.830 GMT [6480][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50444
2024-04-06 05:19:29.915 GMT [6520][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50445
2024-04-06 05:19:29.922 GMT [6520][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-04-06 05:19:29.922 GMT [6520][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-04-06 05:19:29.925 GMT [6520][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-04-06 05:19:29.927 GMT [6520][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50445
2024-04-06 05:19:29.975 GMT [5780][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50446
2024-04-06 05:19:30.046 GMT [5420][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:30.046 GMT [5420][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:30.050 GMT [5420][postmaster] LOG:  background worker "logical replication launcher" (PID 6552) exited with exit code 1
2024-04-06 05:19:30.051 GMT [5388][checkpointer] LOG:  shutting down
2024-04-06 05:19:30.051 GMT [5388][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:30.054 GMT [5388][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/407E950, redo lsn=0/407E950
2024-04-06 05:19:30.058 GMT [5420][postmaster] LOG:  database system is shut down
2024-04-06 05:19:30.204 GMT [2620][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:30.205 GMT [2620][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:30.206 GMT [2620][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:30.224 GMT [2560][startup] LOG:  database system was shut down at 2024-04-06 05:19:30 GMT
2024-04-06 05:19:30.231 GMT [2620][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:30.341 GMT [7180][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50447
2024-04-06 05:19:30.348 GMT [7180][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-04-06 05:19:30.348 GMT [7180][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-04-06 05:19:30.360 GMT [7180][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-04-06 05:19:30.363 GMT [7180][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50447
2024-04-06 05:19:30.418 GMT [2920][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50448
2024-04-06 05:19:30.425 GMT [2920][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-04-06 05:19:30.425 GMT [2920][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-04-06 05:19:30.428 GMT [2920][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-04-06 05:19:30.431 GMT [2920][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50448
2024-04-06 05:19:30.479 GMT [3548][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50449
2024-04-06 05:19:30.487 GMT [3548][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-04-06 05:19:30.487 GMT [3548][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-04-06 05:19:30.490 GMT [3548][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-04-06 05:19:30.492 GMT [3548][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50449
2024-04-06 05:19:30.517 GMT [2620][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:30.517 GMT [2620][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:30.521 GMT [2620][postmaster] LOG:  background worker "logical replication launcher" (PID 6592) exited with exit code 1
2024-04-06 05:19:30.522 GMT [7488][checkpointer] LOG:  shutting down
2024-04-06 05:19:30.523 GMT [7488][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:30.525 GMT [7488][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/407E9C8, redo lsn=0/407E9C8
2024-04-06 05:19:30.530 GMT [2620][postmaster] LOG:  database system is shut down
2024-04-06 05:19:30.680 GMT [884][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:30.680 GMT [884][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:30.681 GMT [884][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:30.706 GMT [5968][startup] LOG:  database system was shut down at 2024-04-06 05:19:30 GMT
2024-04-06 05:19:30.713 GMT [884][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:30.778 GMT [7376][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50450
2024-04-06 05:19:30.785 GMT [7376][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-04-06 05:19:30.785 GMT [7376][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-04-06 05:19:30.797 GMT [7376][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-04-06 05:19:30.799 GMT [7376][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50450
2024-04-06 05:19:30.883 GMT [4812][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50451
2024-04-06 05:19:30.923 GMT [884][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:30.923 GMT [884][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:30.927 GMT [884][postmaster] LOG:  background worker "logical replication launcher" (PID 6228) exited with exit code 1
2024-04-06 05:19:30.927 GMT [6076][checkpointer] LOG:  shutting down
2024-04-06 05:19:30.927 GMT [6076][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:30.930 GMT [6076][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/407EA40, redo lsn=0/407EA40
2024-04-06 05:19:30.934 GMT [884][postmaster] LOG:  database system is shut down
2024-04-06 05:19:31.083 GMT [7052][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:31.083 GMT [7052][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:31.084 GMT [7052][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:31.104 GMT [7900][startup] LOG:  database system was shut down at 2024-04-06 05:19:30 GMT
2024-04-06 05:19:31.111 GMT [7052][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:31.183 GMT [4156][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50452
2024-04-06 05:19:31.188 GMT [4156][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-06 05:19:31.276 GMT [2804][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50453
2024-04-06 05:19:31.283 GMT [2804][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-04-06 05:19:31.283 GMT [2804][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-04-06 05:19:31.295 GMT [2804][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-04-06 05:19:31.298 GMT [2804][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50453
2024-04-06 05:19:31.384 GMT [7432][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50454
2024-04-06 05:19:31.424 GMT [7052][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:31.425 GMT [7052][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:31.429 GMT [7052][postmaster] LOG:  background worker "logical replication launcher" (PID 8152) exited with exit code 1
2024-04-06 05:19:31.430 GMT [2320][checkpointer] LOG:  shutting down
2024-04-06 05:19:31.430 GMT [2320][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:31.433 GMT [2320][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/407EAB8, redo lsn=0/407EAB8
2024-04-06 05:19:31.437 GMT [7052][postmaster] LOG:  database system is shut down
2024-04-06 05:19:31.593 GMT [5856][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:31.593 GMT [5856][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:31.595 GMT [5856][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:31.632 GMT [4908][startup] LOG:  database system was shut down at 2024-04-06 05:19:31 GMT
2024-04-06 05:19:31.648 GMT [5856][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:31.802 GMT [2336][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50455
2024-04-06 05:19:31.809 GMT [2336][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-04-06 05:19:31.809 GMT [2336][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-04-06 05:19:31.822 GMT [2336][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-04-06 05:19:31.824 GMT [2336][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50455
2024-04-06 05:19:31.874 GMT [6524][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50456
2024-04-06 05:19:31.880 GMT [6524][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-04-06 05:19:31.933 GMT [8156][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50457
2024-04-06 05:19:31.940 GMT [8156][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-04-06 05:19:31.996 GMT [8060][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50458
2024-04-06 05:19:32.004 GMT [8060][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-04-06 05:19:32.004 GMT [8060][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-04-06 05:19:32.007 GMT [8060][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-04-06 05:19:32.011 GMT [8060][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50458
2024-04-06 05:19:32.061 GMT [6512][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50459
2024-04-06 05:19:32.068 GMT [6512][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-04-06 05:19:32.068 GMT [6512][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-04-06 05:19:32.071 GMT [6512][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-04-06 05:19:32.073 GMT [6512][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50459
2024-04-06 05:19:32.216 GMT [3740][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50460
2024-04-06 05:19:32.224 GMT [3740][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-04-06 05:19:32.282 GMT [476][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50461
2024-04-06 05:19:32.292 GMT [476][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-04-06 05:19:32.292 GMT [476][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-04-06 05:19:32.305 GMT [476][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_jaxw/client.key$$
2024-04-06 05:19:32.307 GMT [476][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=certdb host=pg-loadbalancetest port=50461
2024-04-06 05:19:32.387 GMT [4264][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50462
2024-04-06 05:19:32.396 GMT [4264][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-04-06 05:19:32.396 GMT [4264][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-04-06 05:19:32.399 GMT [4264][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_jaxw/client-der.key$$
2024-04-06 05:19:32.401 GMT [4264][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50462
2024-04-06 05:19:32.452 GMT [6720][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50463
2024-04-06 05:19:32.462 GMT [6720][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-04-06 05:19:32.462 GMT [6720][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-04-06 05:19:32.465 GMT [6720][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_jaxw/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-04-06 05:19:32.467 GMT [6720][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50463
2024-04-06 05:19:32.516 GMT [6784][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50464
2024-04-06 05:19:32.525 GMT [6784][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-04-06 05:19:32.525 GMT [6784][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-04-06 05:19:32.528 GMT [6784][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_jaxw/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-04-06 05:19:32.530 GMT [6784][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50464
2024-04-06 05:19:32.576 GMT [5832][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50465
2024-04-06 05:19:32.585 GMT [5832][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-04-06 05:19:32.585 GMT [5832][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-04-06 05:19:32.588 GMT [5832][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_jaxw/client.key$$
2024-04-06 05:19:32.590 GMT [5832][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50465
2024-04-06 05:19:32.638 GMT [6516][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50466
2024-04-06 05:19:32.647 GMT [6516][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-04-06 05:19:32.647 GMT [6516][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-04-06 05:19:32.649 GMT [6516][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_jaxw/client.key$$
2024-04-06 05:19:32.651 GMT [6516][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50466
2024-04-06 05:19:32.699 GMT [5384][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50467
2024-04-06 05:19:32.706 GMT [5384][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-04-06 05:19:32.762 GMT [7296][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50468
2024-04-06 05:19:32.772 GMT [7296][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-04-06 05:19:32.828 GMT [7916][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50469
2024-04-06 05:19:32.838 GMT [7916][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-04-06 05:19:32.838 GMT [7916][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-04-06 05:19:32.849 GMT [7916][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_jaxw/client-dn.key$$
2024-04-06 05:19:32.853 GMT [7916][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50469
2024-04-06 05:19:32.938 GMT [6248][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50470
2024-04-06 05:19:32.947 GMT [6248][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-04-06 05:19:32.947 GMT [6248][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-04-06 05:19:32.959 GMT [6248][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_jaxw/client-dn.key$$
2024-04-06 05:19:32.962 GMT [6248][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50470
2024-04-06 05:19:33.046 GMT [7300][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50471
2024-04-06 05:19:33.055 GMT [7300][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-04-06 05:19:33.055 GMT [7300][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-04-06 05:19:33.067 GMT [7300][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_jaxw/client-dn.key$$
2024-04-06 05:19:33.070 GMT [7300][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50471
2024-04-06 05:19:33.159 GMT [6724][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50472
2024-04-06 05:19:33.168 GMT [6724][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-04-06 05:19:33.168 GMT [6724][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-04-06 05:19:33.171 GMT [6724][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-04-06 05:19:33.175 GMT [6724][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50472
2024-04-06 05:19:33.263 GMT [8064][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50473
2024-04-06 05:19:33.272 GMT [8064][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-04-06 05:19:33.272 GMT [8064][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-04-06 05:19:33.272 GMT [8064][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-04-06 05:19:33.272 GMT [8064][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-04-06 05:19:33.324 GMT [5872][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50474
2024-04-06 05:19:33.331 GMT [5872][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-06 05:19:33.331 GMT [5872][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-04-06 05:19:33.388 GMT [5536][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50475
2024-04-06 05:19:33.396 GMT [5536][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-04-06 05:19:33.396 GMT [5536][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-04-06 05:19:33.407 GMT [5536][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_jaxw/client.key$$
2024-04-06 05:19:33.410 GMT [5536][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50475
2024-04-06 05:19:33.454 GMT [4224][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50476
2024-04-06 05:19:33.462 GMT [4224][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-04-06 05:19:33.463 GMT [4224][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-04-06 05:19:33.463 GMT [4224][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-04-06 05:19:33.463 GMT [4224][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-04-06 05:19:33.514 GMT [6952][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50477
2024-04-06 05:19:33.523 GMT [6952][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-04-06 05:19:33.523 GMT [6952][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-04-06 05:19:33.526 GMT [6952][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_jaxw/client.key$$
2024-04-06 05:19:33.528 GMT [6952][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50477
2024-04-06 05:19:33.552 GMT [5856][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:33.552 GMT [5856][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:33.556 GMT [5856][postmaster] LOG:  background worker "logical replication launcher" (PID 6692) exited with exit code 1
2024-04-06 05:19:33.557 GMT [2436][checkpointer] LOG:  shutting down
2024-04-06 05:19:33.557 GMT [2436][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:33.560 GMT [2436][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/407EB30, redo lsn=0/407EB30
2024-04-06 05:19:33.565 GMT [5856][postmaster] LOG:  database system is shut down
2024-04-06 05:19:33.713 GMT [6796][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:33.713 GMT [6796][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:33.714 GMT [6796][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:33.750 GMT [2492][startup] LOG:  database system was shut down at 2024-04-06 05:19:33 GMT
2024-04-06 05:19:33.759 GMT [6796][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:33.820 GMT [7212][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50478
2024-04-06 05:19:33.829 GMT [7212][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-04-06 05:19:33.829 GMT [7212][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-04-06 05:19:33.841 GMT [7212][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_jaxw/client.key sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 host=localhost sslmode=require sslcert=ssl/client+client_ca.crt$$
2024-04-06 05:19:33.843 GMT [7212][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb host=pg-loadbalancetest port=50478
2024-04-06 05:19:33.886 GMT [5668][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50479
2024-04-06 05:19:33.893 GMT [5668][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-06 05:19:33.893 GMT [5668][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-04-06 05:19:33.952 GMT [3060][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50480
2024-04-06 05:19:33.959 GMT [3060][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-06 05:19:33.959 GMT [3060][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-04-06 05:19:33.991 GMT [6796][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:33.991 GMT [6796][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:33.996 GMT [6796][postmaster] LOG:  background worker "logical replication launcher" (PID 5840) exited with exit code 1
2024-04-06 05:19:33.997 GMT [6568][checkpointer] LOG:  shutting down
2024-04-06 05:19:33.997 GMT [6568][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:34.000 GMT [6568][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/407EBA8, redo lsn=0/407EBA8
2024-04-06 05:19:34.004 GMT [6796][postmaster] LOG:  database system is shut down
2024-04-06 05:19:34.146 GMT [796][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:34.146 GMT [796][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:34.147 GMT [796][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:34.166 GMT [6856][startup] LOG:  database system was shut down at 2024-04-06 05:19:33 GMT
2024-04-06 05:19:34.173 GMT [796][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:34.247 GMT [4272][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50481
2024-04-06 05:19:34.254 GMT [4272][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-06 05:19:34.254 GMT [4272][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-04-06 05:19:34.286 GMT [796][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:34.286 GMT [796][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:34.289 GMT [796][postmaster] LOG:  background worker "logical replication launcher" (PID 1524) exited with exit code 1
2024-04-06 05:19:34.291 GMT [3396][checkpointer] LOG:  shutting down
2024-04-06 05:19:34.291 GMT [3396][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:34.294 GMT [3396][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/407EC20, redo lsn=0/407EC20
2024-04-06 05:19:34.298 GMT [796][postmaster] LOG:  database system is shut down
2024-04-06 05:19:34.447 GMT [7468][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:34.448 GMT [7468][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:34.449 GMT [7468][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:34.468 GMT [2844][startup] LOG:  database system was shut down at 2024-04-06 05:19:34 GMT
2024-04-06 05:19:34.476 GMT [7468][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:34.545 GMT [5436][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50482
2024-04-06 05:19:34.554 GMT [5436][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-06 05:19:34.554 GMT [5436][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-04-06 05:19:34.607 GMT [1416][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50483
2024-04-06 05:19:34.615 GMT [1416][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-06 05:19:34.615 GMT [1416][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-04-06 05:19:34.648 GMT [7468][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:34.648 GMT [7468][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:34.652 GMT [7468][postmaster] LOG:  background worker "logical replication launcher" (PID 3176) exited with exit code 1
2024-04-06 05:19:34.654 GMT [4204][checkpointer] LOG:  shutting down
2024-04-06 05:19:34.654 GMT [4204][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:34.657 GMT [4204][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/407EC98, redo lsn=0/407EC98
2024-04-06 05:19:34.661 GMT [7468][postmaster] LOG:  database system is shut down
2024-04-06 05:19:34.806 GMT [3140][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:34.807 GMT [3140][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:34.808 GMT [3140][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:34.830 GMT [2664][startup] LOG:  database system was shut down at 2024-04-06 05:19:34 GMT
2024-04-06 05:19:34.838 GMT [3140][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:34.909 GMT [4148][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50484
2024-04-06 05:19:34.912 GMT [4148][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:34.912 GMT [4148][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:34.969 GMT [632][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50485
2024-04-06 05:19:34.975 GMT [632][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-04-06 05:19:34.975 GMT [632][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-04-06 05:19:34.988 GMT [632][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-04-06 05:19:34.990 GMT [632][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50485
2024-04-06 05:19:35.054 GMT [3140][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:35.055 GMT [3140][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:35.062 GMT [3140][postmaster] LOG:  background worker "logical replication launcher" (PID 2304) exited with exit code 1
2024-04-06 05:19:35.063 GMT [2384][checkpointer] LOG:  shutting down
2024-04-06 05:19:35.063 GMT [2384][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:35.065 GMT [2384][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/407ED10, redo lsn=0/407ED10
2024-04-06 05:19:35.070 GMT [3140][postmaster] LOG:  database system is shut down
2024-04-06 05:19:35.212 GMT [3160][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:35.213 GMT [3160][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:35.214 GMT [3160][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:35.244 GMT [4332][startup] LOG:  database system was shut down at 2024-04-06 05:19:35 GMT
2024-04-06 05:19:35.251 GMT [3160][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:35.311 GMT [484][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50486
2024-04-06 05:19:35.314 GMT [484][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:35.314 GMT [484][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:35.380 GMT [1948][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50487
2024-04-06 05:19:35.387 GMT [1948][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-04-06 05:19:35.387 GMT [1948][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-04-06 05:19:35.399 GMT [1948][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-04-06 05:19:35.402 GMT [1948][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50487
2024-04-06 05:19:35.460 GMT [3160][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:35.460 GMT [3160][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:35.464 GMT [3160][postmaster] LOG:  background worker "logical replication launcher" (PID 3552) exited with exit code 1
2024-04-06 05:19:35.464 GMT [2008][checkpointer] LOG:  shutting down
2024-04-06 05:19:35.464 GMT [2008][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:35.467 GMT [2008][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/407ED88, redo lsn=0/407ED88
2024-04-06 05:19:35.472 GMT [3160][postmaster] LOG:  database system is shut down
2024-04-06 05:19:35.620 GMT [7740][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:35.620 GMT [7740][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:35.621 GMT [7740][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:35.641 GMT [6240][startup] LOG:  database system was shut down at 2024-04-06 05:19:35 GMT
2024-04-06 05:19:35.649 GMT [7740][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:35.719 GMT [7412][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50488
2024-04-06 05:19:35.722 GMT [7412][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:35.722 GMT [7412][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:35.782 GMT [3792][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50489
2024-04-06 05:19:35.789 GMT [3792][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-04-06 05:19:35.789 GMT [3792][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-04-06 05:19:35.801 GMT [3792][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-04-06 05:19:35.803 GMT [3792][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50489
2024-04-06 05:19:35.823 GMT [7740][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:35.823 GMT [7740][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:35.828 GMT [7740][postmaster] LOG:  background worker "logical replication launcher" (PID 3548) exited with exit code 1
2024-04-06 05:19:35.828 GMT [4920][checkpointer] LOG:  shutting down
2024-04-06 05:19:35.828 GMT [4920][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:35.831 GMT [4920][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/407EE00, redo lsn=0/407EE00
2024-04-06 05:19:35.836 GMT [7740][postmaster] LOG:  database system is shut down
2024-04-06 05:19:35.978 GMT [5484][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:35.979 GMT [5484][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:35.980 GMT [5484][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:36.001 GMT [1464][startup] LOG:  database system was shut down at 2024-04-06 05:19:35 GMT
2024-04-06 05:19:36.008 GMT [5484][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:36.080 GMT [7672][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50490
2024-04-06 05:19:36.083 GMT [7672][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:36.083 GMT [7672][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:36.147 GMT [5084][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50491
2024-04-06 05:19:36.154 GMT [5084][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-04-06 05:19:36.154 GMT [5084][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-04-06 05:19:36.167 GMT [5084][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-04-06 05:19:36.169 GMT [5084][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50491
2024-04-06 05:19:36.226 GMT [5484][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:36.226 GMT [5484][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:36.230 GMT [5484][postmaster] LOG:  background worker "logical replication launcher" (PID 4812) exited with exit code 1
2024-04-06 05:19:36.231 GMT [7684][checkpointer] LOG:  shutting down
2024-04-06 05:19:36.231 GMT [7684][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:36.234 GMT [7684][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/407EE78, redo lsn=0/407EE78
2024-04-06 05:19:36.238 GMT [5484][postmaster] LOG:  database system is shut down
2024-04-06 05:19:36.384 GMT [6072][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:36.385 GMT [6072][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:36.386 GMT [6072][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:36.417 GMT [6096][startup] LOG:  database system was shut down at 2024-04-06 05:19:36 GMT
2024-04-06 05:19:36.427 GMT [6072][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:36.494 GMT [5520][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50492
2024-04-06 05:19:36.497 GMT [5520][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:36.497 GMT [5520][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:36.565 GMT [4776][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50493
2024-04-06 05:19:36.572 GMT [4776][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-04-06 05:19:36.572 GMT [4776][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-04-06 05:19:36.584 GMT [4776][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-04-06 05:19:36.587 GMT [4776][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50493
2024-04-06 05:19:36.649 GMT [6072][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:36.650 GMT [6072][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:36.654 GMT [6072][postmaster] LOG:  background worker "logical replication launcher" (PID 2440) exited with exit code 1
2024-04-06 05:19:36.654 GMT [6352][checkpointer] LOG:  shutting down
2024-04-06 05:19:36.654 GMT [6352][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:36.657 GMT [6352][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/407EEF0, redo lsn=0/407EEF0
2024-04-06 05:19:36.661 GMT [6072][postmaster] LOG:  database system is shut down
2024-04-06 05:19:36.807 GMT [5432][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:36.808 GMT [5432][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:36.809 GMT [5432][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:36.828 GMT [560][startup] LOG:  database system was shut down at 2024-04-06 05:19:36 GMT
2024-04-06 05:19:36.835 GMT [5432][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:36.907 GMT [6164][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50494
2024-04-06 05:19:36.910 GMT [6164][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:36.910 GMT [6164][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:36.969 GMT [3988][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50495
2024-04-06 05:19:36.976 GMT [3988][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-04-06 05:19:36.976 GMT [3988][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-04-06 05:19:36.989 GMT [3988][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-04-06 05:19:36.991 GMT [3988][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50495
2024-04-06 05:19:37.010 GMT [5432][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:37.010 GMT [5432][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:37.013 GMT [5432][postmaster] LOG:  background worker "logical replication launcher" (PID 5716) exited with exit code 1
2024-04-06 05:19:37.014 GMT [7052][checkpointer] LOG:  shutting down
2024-04-06 05:19:37.014 GMT [7052][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:37.017 GMT [7052][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/407EF68, redo lsn=0/407EF68
2024-04-06 05:19:37.021 GMT [5432][postmaster] LOG:  database system is shut down
2024-04-06 05:19:37.168 GMT [1240][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:37.169 GMT [1240][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:37.170 GMT [1240][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:37.191 GMT [6512][startup] LOG:  database system was shut down at 2024-04-06 05:19:37 GMT
2024-04-06 05:19:37.198 GMT [1240][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:37.269 GMT [7816][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50496
2024-04-06 05:19:37.272 GMT [7816][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:37.272 GMT [7816][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:37.349 GMT [476][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50497
2024-04-06 05:19:37.356 GMT [476][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-04-06 05:19:37.356 GMT [476][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-04-06 05:19:37.368 GMT [476][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-04-06 05:19:37.372 GMT [476][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50497
2024-04-06 05:19:37.435 GMT [1240][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:37.435 GMT [1240][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:37.445 GMT [1240][postmaster] LOG:  background worker "logical replication launcher" (PID 5744) exited with exit code 1
2024-04-06 05:19:37.446 GMT [3216][checkpointer] LOG:  shutting down
2024-04-06 05:19:37.446 GMT [3216][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:37.449 GMT [3216][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/407EFE0, redo lsn=0/407EFE0
2024-04-06 05:19:37.454 GMT [1240][postmaster] LOG:  database system is shut down
2024-04-06 05:19:37.594 GMT [2132][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:37.595 GMT [2132][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:37.596 GMT [2132][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:37.615 GMT [5264][startup] LOG:  database system was shut down at 2024-04-06 05:19:37 GMT
2024-04-06 05:19:37.622 GMT [2132][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:37.690 GMT [2892][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50498
2024-04-06 05:19:37.693 GMT [2892][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:37.693 GMT [2892][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:37.752 GMT [7296][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50499
2024-04-06 05:19:37.759 GMT [7296][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-04-06 05:19:37.759 GMT [7296][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-04-06 05:19:37.773 GMT [7296][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-04-06 05:19:37.775 GMT [7296][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50499
2024-04-06 05:19:37.837 GMT [2132][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:37.837 GMT [2132][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:37.843 GMT [2132][postmaster] LOG:  background worker "logical replication launcher" (PID 3440) exited with exit code 1
2024-04-06 05:19:37.843 GMT [1072][checkpointer] LOG:  shutting down
2024-04-06 05:19:37.843 GMT [1072][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:37.846 GMT [1072][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/407F058, redo lsn=0/407F058
2024-04-06 05:19:37.850 GMT [2132][postmaster] LOG:  database system is shut down
2024-04-06 05:19:37.994 GMT [7228][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-06 05:19:37.994 GMT [7228][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 49817
2024-04-06 05:19:37.995 GMT [7228][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/OJu2oaVRS9/.s.PGSQL.49817"
2024-04-06 05:19:38.013 GMT [7080][startup] LOG:  database system was shut down at 2024-04-06 05:19:37 GMT
2024-04-06 05:19:38.020 GMT [7228][postmaster] LOG:  database system is ready to accept connections
2024-04-06 05:19:38.096 GMT [4564][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50500
2024-04-06 05:19:38.099 GMT [4564][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-06 05:19:38.099 GMT [4564][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-06 05:19:38.158 GMT [4828][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50501
2024-04-06 05:19:38.165 GMT [4828][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-04-06 05:19:38.165 GMT [4828][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-04-06 05:19:38.178 GMT [4828][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-04-06 05:19:38.180 GMT [4828][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50501
2024-04-06 05:19:38.198 GMT [7228][postmaster] LOG:  received fast shutdown request
2024-04-06 05:19:38.198 GMT [7228][postmaster] LOG:  aborting any active transactions
2024-04-06 05:19:38.202 GMT [7228][postmaster] LOG:  background worker "logical replication launcher" (PID 6724) exited with exit code 1
2024-04-06 05:19:38.202 GMT [5008][checkpointer] LOG:  shutting down
2024-04-06 05:19:38.202 GMT [5008][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-06 05:19:38.205 GMT [5008][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/407F0D0, redo lsn=0/407F0D0
2024-04-06 05:19:38.209 GMT [7228][postmaster] LOG:  database system is shut down
2024-04-06 05:19:38.346 GMT [3972][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-04-06 05:19:38.346 GMT [3972][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[05:19:38.416](0.232s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"