[03:31:13.035](0.226s) # setting up data directory
# Checking port 63283
# Found port 63283
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=63283 host=C:/Windows/TEMP/_SgL5oyIMQ
Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log
[03:31:13.106](0.071s) # 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 5808
[03:31:15.329](2.223s) 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 4820
[03:31:20.541](5.211s) # 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-04 03:31:14.842 GMT [5808][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:14.843 GMT [5808][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:14.914 GMT [6140][startup] LOG:  database system was shut down at 2024-04-04 03:20:32 GMT
2024-04-04 03:31:14.963 GMT [5808][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:15.234 GMT [6424][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.236 GMT [6424][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-04 03:31:15.236 GMT [6424][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.252 GMT [6424][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-04-04 03:31:15.255 GMT [6424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.486 GMT [4336][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.488 GMT [4336][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-04 03:31:15.488 GMT [4336][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.490 GMT [4336][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-04-04 03:31:15.491 GMT [4336][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.560 GMT [5012][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.562 GMT [5012][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-04 03:31:15.562 GMT [5012][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.568 GMT [5012][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-04-04 03:31:15.573 GMT [5012][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.667 GMT [1204][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.668 GMT [1204][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-04 03:31:15.668 GMT [1204][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.670 GMT [1204][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-04-04 03:31:15.671 GMT [1204][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.867 GMT [4276][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.868 GMT [4276][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-04 03:31:15.868 GMT [4276][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.871 GMT [4276][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-04-04 03:31:15.871 GMT [4276][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:16.006 GMT [1284][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:16.010 GMT [1284][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-04 03:31:16.010 GMT [1284][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:16.013 GMT [1284][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-04-04 03:31:16.310 GMT [1284][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.307 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:16.546 GMT [4712][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:16.548 GMT [4712][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-04 03:31:16.548 GMT [4712][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:16.559 GMT [4712][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-04-04 03:31:16.865 GMT [4712][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.322 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:17.193 GMT [5476][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:17.194 GMT [5476][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-04 03:31:17.194 GMT [5476][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:17.198 GMT [5476][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-04-04 03:31:17.443 GMT [5476][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.254 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:17.518 GMT [8088][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:17.519 GMT [8088][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-04 03:31:17.519 GMT [8088][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:17.525 GMT [8088][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-04-04 03:31:17.951 GMT [8088][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.436 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:18.053 GMT [1168][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:18.054 GMT [1168][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-04 03:31:18.054 GMT [1168][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:18.057 GMT [1168][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-04-04 03:31:18.766 GMT [1168][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.716 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:18.844 GMT [6500][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:18.845 GMT [6500][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-04 03:31:18.845 GMT [6500][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:18.853 GMT [6500][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-04-04 03:31:19.150 GMT [6500][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.309 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:19.406 GMT [5808][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:19.407 GMT [5808][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:19.429 GMT [5808][postmaster] LOG:  background worker "logical replication launcher" (PID 7464) exited with exit code 1
2024-04-04 03:31:19.438 GMT [5772][checkpointer] LOG:  shutting down
2024-04-04 03:31:19.439 GMT [5772][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:19.697 GMT [5772][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.253 s, sync=0.001 s, total=0.260 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-04 03:31:19.829 GMT [5808][postmaster] LOG:  database system is shut down
2024-04-04 03:31:20.322 GMT [4820][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:20.323 GMT [4820][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:20.324 GMT [4820][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:20.388 GMT [5236][startup] LOG:  database system was shut down at 2024-04-04 03:31:19 GMT
2024-04-04 03:31:20.446 GMT [4820][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:20.586 GMT [4820][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:20.587 GMT [4820][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:20.630 GMT [4820][postmaster] LOG:  background worker "logical replication launcher" (PID 5356) exited with exit code 1
2024-04-04 03:31:20.630 GMT [1204][checkpointer] LOG:  shutting down
2024-04-04 03:31:20.630 GMT [1204][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:20.636 GMT [1204][checkpointer] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 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/407E590, redo lsn=0/407E590
2024-04-04 03:31:20.678 GMT [4820][postmaster] LOG:  database system is shut down
2024-04-04 03:31:20.837 GMT [2760][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-04-04 03:31:20.837 GMT [2760][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[03:31:20.974](0.434s) 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 2852
[03:31:21.245](0.270s) 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-04 03:31:14.842 GMT [5808][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:14.843 GMT [5808][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:14.914 GMT [6140][startup] LOG:  database system was shut down at 2024-04-04 03:20:32 GMT
2024-04-04 03:31:14.963 GMT [5808][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:15.234 GMT [6424][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.236 GMT [6424][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-04 03:31:15.236 GMT [6424][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.252 GMT [6424][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-04-04 03:31:15.255 GMT [6424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.486 GMT [4336][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.488 GMT [4336][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-04 03:31:15.488 GMT [4336][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.490 GMT [4336][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-04-04 03:31:15.491 GMT [4336][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.560 GMT [5012][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.562 GMT [5012][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-04 03:31:15.562 GMT [5012][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.568 GMT [5012][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-04-04 03:31:15.573 GMT [5012][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.667 GMT [1204][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.668 GMT [1204][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-04 03:31:15.668 GMT [1204][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.670 GMT [1204][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-04-04 03:31:15.671 GMT [1204][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.867 GMT [4276][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.868 GMT [4276][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-04 03:31:15.868 GMT [4276][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.871 GMT [4276][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-04-04 03:31:15.871 GMT [4276][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:16.006 GMT [1284][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:16.010 GMT [1284][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-04 03:31:16.010 GMT [1284][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:16.013 GMT [1284][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-04-04 03:31:16.310 GMT [1284][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.307 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:16.546 GMT [4712][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:16.548 GMT [4712][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-04 03:31:16.548 GMT [4712][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:16.559 GMT [4712][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-04-04 03:31:16.865 GMT [4712][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.322 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:17.193 GMT [5476][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:17.194 GMT [5476][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-04 03:31:17.194 GMT [5476][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:17.198 GMT [5476][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-04-04 03:31:17.443 GMT [5476][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.254 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:17.518 GMT [8088][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:17.519 GMT [8088][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-04 03:31:17.519 GMT [8088][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:17.525 GMT [8088][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-04-04 03:31:17.951 GMT [8088][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.436 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:18.053 GMT [1168][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:18.054 GMT [1168][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-04 03:31:18.054 GMT [1168][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:18.057 GMT [1168][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-04-04 03:31:18.766 GMT [1168][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.716 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:18.844 GMT [6500][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:18.845 GMT [6500][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-04 03:31:18.845 GMT [6500][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:18.853 GMT [6500][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-04-04 03:31:19.150 GMT [6500][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.309 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:19.406 GMT [5808][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:19.407 GMT [5808][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:19.429 GMT [5808][postmaster] LOG:  background worker "logical replication launcher" (PID 7464) exited with exit code 1
2024-04-04 03:31:19.438 GMT [5772][checkpointer] LOG:  shutting down
2024-04-04 03:31:19.439 GMT [5772][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:19.697 GMT [5772][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.253 s, sync=0.001 s, total=0.260 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-04 03:31:19.829 GMT [5808][postmaster] LOG:  database system is shut down
2024-04-04 03:31:20.322 GMT [4820][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:20.323 GMT [4820][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:20.324 GMT [4820][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:20.388 GMT [5236][startup] LOG:  database system was shut down at 2024-04-04 03:31:19 GMT
2024-04-04 03:31:20.446 GMT [4820][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:20.586 GMT [4820][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:20.587 GMT [4820][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:20.630 GMT [4820][postmaster] LOG:  background worker "logical replication launcher" (PID 5356) exited with exit code 1
2024-04-04 03:31:20.630 GMT [1204][checkpointer] LOG:  shutting down
2024-04-04 03:31:20.630 GMT [1204][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:20.636 GMT [1204][checkpointer] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 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/407E590, redo lsn=0/407E590
2024-04-04 03:31:20.678 GMT [4820][postmaster] LOG:  database system is shut down
2024-04-04 03:31:20.837 GMT [2760][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-04-04 03:31:20.837 GMT [2760][postmaster] LOG:  database system is shut down
2024-04-04 03:31:21.139 GMT [2852][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:21.139 GMT [2852][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:21.140 GMT [2852][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:21.187 GMT [6816][startup] LOG:  database system was shut down at 2024-04-04 03:31:20 GMT
2024-04-04 03:31:21.202 GMT [2852][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:21.268 GMT [2852][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:21.269 GMT [2852][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:21.325 GMT [2852][postmaster] LOG:  background worker "logical replication launcher" (PID 6188) exited with exit code 1
2024-04-04 03:31:21.327 GMT [2128][checkpointer] LOG:  shutting down
2024-04-04 03:31:21.328 GMT [2128][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:21.339 GMT [2128][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 s, sync=0.001 s, total=0.012 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-04 03:31:21.474 GMT [2852][postmaster] LOG:  database system is shut down
2024-04-04 03:31:21.817 GMT [5388][postmaster] FATAL:  could not set SSL protocol version range
2024-04-04 03:31:21.817 GMT [5388][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-04-04 03:31:21.818 GMT [5388][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[03:31:22.183](0.938s) 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 1104
[03:31:22.509](0.326s) ok 5 - restart succeeds with correct SSL protocol bounds
[03:31:22.509](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 7136
[03:31:22.998](0.488s) ok 6 - server doesn't accept non-SSL connections
[03:31:22.999](0.001s) ok 7 - server doesn't accept non-SSL connections: matches
[03:31:23.112](0.114s) ok 8 - connect without server root cert sslmode=require
[03:31:23.113](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr
[03:31:23.250](0.138s) ok 10 - connect without server root cert sslmode=verify-ca
[03:31:23.251](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[03:31:23.341](0.090s) ok 12 - connect without server root cert sslmode=verify-full
[03:31:23.341](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches
[03:31:23.465](0.124s) ok 14 - connect with wrong server root cert sslmode=require
[03:31:23.465](0.001s) ok 15 - connect with wrong server root cert sslmode=require: matches
[03:31:23.598](0.133s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[03:31:23.598](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[03:31:23.685](0.087s) ok 18 - connect with wrong server root cert sslmode=verify-full
[03:31:23.685](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[03:31:23.794](0.108s) ok 20 - connect with server CA cert, without root CA
[03:31:23.794](0.000s) ok 21 - connect with server CA cert, without root CA: matches
[03:31:23.872](0.078s) ok 22 - connect with correct server CA cert file sslmode=require
[03:31:23.872](0.001s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[03:31:23.961](0.088s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[03:31:23.961](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[03:31:24.124](0.163s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[03:31:24.124](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[03:31:24.210](0.086s) ok 28 - cert root file that contains two certificates, order 1
[03:31:24.210](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[03:31:24.317](0.107s) ok 30 - cert root file that contains two certificates, order 2
[03:31:24.317](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[03:31:24.434](0.118s) ok 32 - connect with sslcertmode=disable
[03:31:24.435](0.001s) ok 33 - connect with sslcertmode=disable: no stderr
[03:31:24.557](0.122s) ok 34 - connect with sslcertmode=allow
[03:31:24.557](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[03:31:24.676](0.118s) ok 36 - connect with sslcertmode=require fails without a client certificate
[03:31:24.676](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[03:31:24.785](0.109s) ok 38 - sslcrl option with invalid file name
[03:31:24.785](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[03:31:24.911](0.126s) ok 40 - CRL belonging to a different CA
[03:31:24.912](0.000s) ok 41 - CRL belonging to a different CA: matches
[03:31:25.050](0.138s) ok 42 - directory CRL belonging to a different CA
[03:31:25.051](0.001s) ok 43 - directory CRL belonging to a different CA: matches
[03:31:25.160](0.109s) ok 44 - CRL with a non-revoked cert
[03:31:25.160](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[03:31:25.235](0.075s) ok 46 - directory CRL with a non-revoked cert
[03:31:25.236](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr
[03:31:25.347](0.111s) ok 48 - mismatch between host name and server certificate sslmode=require
[03:31:25.347](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[03:31:25.555](0.208s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[03:31:25.555](0.001s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[03:31:25.704](0.149s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[03:31:25.704](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 6864
[03:31:26.032](0.328s) ok 54 - IP address in the Common Name
[03:31:26.032](0.000s) ok 55 - IP address in the Common Name: no stderr
[03:31:26.143](0.110s) ok 56 - mismatch between host name and server certificate IP address
[03:31:26.143](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 6984
[03:31:26.533](0.390s) ok 58 - IP address in a dNSName
[03:31:26.534](0.001s) 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 3276
[03:31:26.970](0.437s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[03:31:26.971](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[03:31:27.080](0.109s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[03:31:27.080](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[03:31:27.189](0.109s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[03:31:27.190](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[03:31:27.301](0.111s) ok 66 - host name not matching with X.509 Subject Alternative Names
[03:31:27.301](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[03:31:27.410](0.108s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[03:31:27.410](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 1816
[03:31:27.753](0.343s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[03:31:27.754](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[03:31:27.863](0.110s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[03:31:27.864](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[03:31:27.925](0.061s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[03:31:27.925](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches
[03:31:27.955](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 3728
[03:31:28.411](0.455s) ok 77 - certificate with both a CN and SANs 1
[03:31:28.411](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr
[03:31:28.475](0.064s) ok 79 - certificate with both a CN and SANs 2
[03:31:28.475](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr
[03:31:28.536](0.061s) ok 81 - certificate with both a CN and SANs ignores CN
[03:31:28.536](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches
[03:31:28.566](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 2456
[03:31:29.147](0.581s) ok 84 - certificate with both an IP CN and DNS SANs matches CN
[03:31:29.148](0.001s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[03:31:29.430](0.282s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1
[03:31:29.430](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[03:31:29.538](0.108s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2
[03:31:29.539](0.001s) ok 89 - certificate with both an IP CN and DNS SANs matches SAN 2: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 4316
[03:31:29.882](0.343s) ok 90 - server certificate without CN or SANs sslmode=verify-ca
[03:31:29.883](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[03:31:29.944](0.062s) ok 92 - server certificate without CN or SANs sslmode=verify-full
[03:31:29.945](0.001s) 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 5128
[03:31:30.242](0.297s) ok 94 - sslrootcert=system does not connect with private CA
[03:31:30.242](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches
[03:31:30.304](0.061s) ok 96 - sslrootcert=system only accepts sslmode=verify-full
[03:31:30.304](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches
[03:31:30.414](0.109s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE
[03:31:30.414](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[03:31:30.476](0.062s) ok 100 - sslrootcert=system defaults to sslmode=verify-full
[03:31:30.476](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 1736
[03:31:30.836](0.359s) ok 102 - connects without client-side CRL
[03:31:30.836](0.000s) ok 103 - connects without client-side CRL: no stderr
[03:31:30.945](0.109s) ok 104 - does not connect with client-side CRL file
[03:31:30.946](0.001s) ok 105 - does not connect with client-side CRL file: matches
[03:31:31.008](0.063s) ok 106 - does not connect with client-side CRL directory
[03:31:31.009](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()
[03:31:31.115](0.106s) ok 108 - pg_stat_ssl view without client certificate: exit code 0
[03:31:31.115](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr
[03:31:31.116](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches
[03:31:31.226](0.111s) ok 111 - connection success with correct range of TLS protocol versions
[03:31:31.227](0.001s) ok 112 - connection success with correct range of TLS protocol versions: no stderr
[03:31:31.289](0.062s) ok 113 - connection failure with incorrect range of TLS protocol versions
[03:31:31.289](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches
[03:31:31.352](0.063s) ok 115 - connection failure with an incorrect SSL protocol minimum bound
[03:31:31.353](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches
[03:31:31.415](0.062s) ok 117 - connection failure with an incorrect SSL protocol maximum bound
[03:31:31.415](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches
[03:31:31.415](0.000s) # running server tests
[03:31:31.527](0.112s) ok 119 - certificate authorization fails without client cert
[03:31:31.527](0.000s) ok 120 - certificate authorization fails without client cert: matches
[03:31:31.637](0.110s) ok 121 - certificate authorization succeeds with correct client cert in PEM format
[03:31:31.637](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[03:31:31.747](0.110s) ok 123 - certificate authorization succeeds with correct client cert in DER format
[03:31:31.748](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr
[03:31:31.856](0.109s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format
[03:31:31.857](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[03:31:31.965](0.109s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format
[03:31:31.966](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[03:31:32.074](0.108s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require
[03:31:32.074](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[03:31:32.183](0.109s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[03:31:32.183](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[03:31:32.308](0.125s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable
[03:31:32.309](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[03:31:32.371](0.062s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[03:31:32.371](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[03:31:32.481](0.110s) ok 137 - certificate authorization succeeds with DN mapping
[03:31:32.481](0.000s) ok 138 - certificate authorization succeeds with DN mapping: no stderr
[03:31:32.482](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches
[03:31:32.590](0.109s) ok 140 - certificate authorization succeeds with DN regex mapping
[03:31:32.591](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr
[03:31:32.699](0.108s) ok 142 - certificate authorization succeeds with CN mapping
[03:31:32.699](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr
[03:31:32.699](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches
[03:31:32.700](0.000s) not ok 145 # TODO & SKIP Need Pty support
[03:31:32.700](0.000s) not ok 146 # TODO & SKIP Need Pty support
[03:31:32.700](0.000s) not ok 147 # TODO & SKIP Need Pty support
[03:31:32.700](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_GkUJ/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[03:31:32.807](0.107s) ok 149 - pg_stat_ssl with client certificate: exit code 0
[03:31:32.808](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr
[03:31:32.808](0.000s) ok 151 - pg_stat_ssl with client certificate: matches
[03:31:32.809](0.001s) ok 152 # skip Permissions check not enforced on Windows
[03:31:32.809](0.000s) ok 153 # skip Permissions check not enforced on Windows
[03:31:32.920](0.111s) ok 154 - certificate authorization fails with client cert belonging to another user
[03:31:32.921](0.001s) ok 155 - certificate authorization fails with client cert belonging to another user: matches
[03:31:33.028](0.107s) ok 156 - certificate authorization fails with revoked client cert
[03:31:33.028](0.001s) ok 157 - certificate authorization fails with revoked client cert: matches
[03:31:33.029](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match
[03:31:33.137](0.108s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[03:31:33.137](0.000s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[03:31:33.138](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[03:31:33.200](0.061s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[03:31:33.200](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[03:31:33.200](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[03:31:33.309](0.109s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[03:31:33.309](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[03:31:33.310](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 4692
[03:31:33.654](0.344s) ok 168 - intermediate client certificate is provided by client
[03:31:33.654](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr
[03:31:33.715](0.061s) ok 170 - intermediate client certificate is missing
[03:31:33.716](0.000s) ok 171 - intermediate client certificate is missing: matches
[03:31:33.778](0.063s) ok 172 - logged client certificate Subjects are truncated if they're too long
[03:31:33.779](0.000s) ok 173 - logged client certificate Subjects are truncated if they're too long: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 5804
[03:31:34.121](0.342s) ok 174 - intermediate client certificate is untrusted
[03:31:34.121](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 7484
[03:31:34.482](0.361s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory
[03:31:34.482](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[03:31:34.592](0.110s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[03:31:34.593](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 7788
[03:31:34.907](0.315s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1
[03:31:34.908](0.001s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923.
[03:31:34.909](0.000s) #          got: '2'
#     expected: '0'
[03:31:34.909](0.001s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[03:31:34.910](0.001s) #   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.
[03:31:34.910](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 63283 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: ''
[03:31:35.016](0.106s) ok 182 - connect without requesting ocsp response when sslocspstapling=0
[03:31:35.017](0.001s) ok 183 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 6764
[03:31:35.328](0.312s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1
[03:31:35.438](0.110s) ok 185 - connect without requesting ocsp response when sslocspstapling=0
[03:31:35.439](0.001s) 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 5948
[03:31:35.891](0.452s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1
[03:31:36.001](0.110s) ok 188 - connect without requesting ocsp response when sslocspstapling=0
[03:31:36.002](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 2812
[03:31:36.297](0.295s) ok 190 - failed with an expired ocsp response when sslocspstapling=1
[03:31:36.407](0.110s) ok 191 - connect without requesting ocsp response when sslocspstapling=0
[03:31:36.407](0.001s) 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 3600
[03:31:36.704](0.296s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1
[03:31:36.704](0.001s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001.
[03:31:36.705](0.000s) #          got: '2'
#     expected: '0'
[03:31:36.705](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[03:31:36.705](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.
[03:31:36.705](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 63283 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: ''
[03:31:36.814](0.109s) ok 195 - connect without requesting ocsp response when sslocspstapling=0
[03:31:36.815](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 6004
[03:31:37.111](0.296s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1
[03:31:37.220](0.109s) ok 198 - connect without requesting ocsp response when sslocspstapling=0
[03:31:37.220](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 5912
[03:31:37.517](0.297s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1
[03:31:37.627](0.110s) ok 201 - connect without requesting ocsp response when sslocspstapling=0
[03:31:37.628](0.000s) ok 202 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 4668
[03:31:37.971](0.343s) ok 203 - failed with an expired ocsp response when sslocspstapling=1
[03:31:38.080](0.109s) ok 204 - connect without requesting ocsp response when sslocspstapling=0
[03:31:38.081](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 7508
[03:31:38.377](0.297s) ok 206 - failed with an expired ocsp response when sslocspstapling=1
[03:31:38.487](0.109s) ok 207 - connect without requesting ocsp response when sslocspstapling=0
[03:31:38.487](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-04 03:31:14.842 GMT [5808][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:14.843 GMT [5808][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:14.914 GMT [6140][startup] LOG:  database system was shut down at 2024-04-04 03:20:32 GMT
2024-04-04 03:31:14.963 GMT [5808][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:15.234 GMT [6424][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.236 GMT [6424][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-04 03:31:15.236 GMT [6424][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.252 GMT [6424][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-04-04 03:31:15.255 GMT [6424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.486 GMT [4336][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.488 GMT [4336][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-04 03:31:15.488 GMT [4336][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.490 GMT [4336][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-04-04 03:31:15.491 GMT [4336][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.560 GMT [5012][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.562 GMT [5012][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-04 03:31:15.562 GMT [5012][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.568 GMT [5012][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-04-04 03:31:15.573 GMT [5012][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.016 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.667 GMT [1204][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.668 GMT [1204][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-04 03:31:15.668 GMT [1204][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.670 GMT [1204][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-04-04 03:31:15.671 GMT [1204][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:15.867 GMT [4276][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:15.868 GMT [4276][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-04 03:31:15.868 GMT [4276][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:15.871 GMT [4276][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-04-04 03:31:15.871 GMT [4276][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:16.006 GMT [1284][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:16.010 GMT [1284][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-04 03:31:16.010 GMT [1284][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:16.013 GMT [1284][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-04-04 03:31:16.310 GMT [1284][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.307 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:16.546 GMT [4712][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:16.548 GMT [4712][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-04 03:31:16.548 GMT [4712][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:16.559 GMT [4712][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-04-04 03:31:16.865 GMT [4712][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.322 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:17.193 GMT [5476][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:17.194 GMT [5476][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-04 03:31:17.194 GMT [5476][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:17.198 GMT [5476][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-04-04 03:31:17.443 GMT [5476][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.254 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:17.518 GMT [8088][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:17.519 GMT [8088][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-04 03:31:17.519 GMT [8088][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:17.525 GMT [8088][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-04-04 03:31:17.951 GMT [8088][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.436 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:18.053 GMT [1168][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:18.054 GMT [1168][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-04 03:31:18.054 GMT [1168][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:18.057 GMT [1168][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-04-04 03:31:18.766 GMT [1168][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.716 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:18.844 GMT [6500][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-04-04 03:31:18.845 GMT [6500][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-04 03:31:18.845 GMT [6500][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-04-04 03:31:18.853 GMT [6500][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-04-04 03:31:19.150 GMT [6500][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.309 user=SYSTEM database=postgres host=[local]
2024-04-04 03:31:19.406 GMT [5808][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:19.407 GMT [5808][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:19.429 GMT [5808][postmaster] LOG:  background worker "logical replication launcher" (PID 7464) exited with exit code 1
2024-04-04 03:31:19.438 GMT [5772][checkpointer] LOG:  shutting down
2024-04-04 03:31:19.439 GMT [5772][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:19.697 GMT [5772][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.253 s, sync=0.001 s, total=0.260 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-04 03:31:19.829 GMT [5808][postmaster] LOG:  database system is shut down
2024-04-04 03:31:20.322 GMT [4820][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:20.323 GMT [4820][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:20.324 GMT [4820][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:20.388 GMT [5236][startup] LOG:  database system was shut down at 2024-04-04 03:31:19 GMT
2024-04-04 03:31:20.446 GMT [4820][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:20.586 GMT [4820][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:20.587 GMT [4820][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:20.630 GMT [4820][postmaster] LOG:  background worker "logical replication launcher" (PID 5356) exited with exit code 1
2024-04-04 03:31:20.630 GMT [1204][checkpointer] LOG:  shutting down
2024-04-04 03:31:20.630 GMT [1204][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:20.636 GMT [1204][checkpointer] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 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/407E590, redo lsn=0/407E590
2024-04-04 03:31:20.678 GMT [4820][postmaster] LOG:  database system is shut down
2024-04-04 03:31:20.837 GMT [2760][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-04-04 03:31:20.837 GMT [2760][postmaster] LOG:  database system is shut down
2024-04-04 03:31:21.139 GMT [2852][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:21.139 GMT [2852][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:21.140 GMT [2852][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:21.187 GMT [6816][startup] LOG:  database system was shut down at 2024-04-04 03:31:20 GMT
2024-04-04 03:31:21.202 GMT [2852][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:21.268 GMT [2852][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:21.269 GMT [2852][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:21.325 GMT [2852][postmaster] LOG:  background worker "logical replication launcher" (PID 6188) exited with exit code 1
2024-04-04 03:31:21.327 GMT [2128][checkpointer] LOG:  shutting down
2024-04-04 03:31:21.328 GMT [2128][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:21.339 GMT [2128][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 s, sync=0.001 s, total=0.012 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-04 03:31:21.474 GMT [2852][postmaster] LOG:  database system is shut down
2024-04-04 03:31:21.817 GMT [5388][postmaster] FATAL:  could not set SSL protocol version range
2024-04-04 03:31:21.817 GMT [5388][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-04-04 03:31:21.818 GMT [5388][postmaster] LOG:  database system is shut down
2024-04-04 03:31:22.293 GMT [1104][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:22.294 GMT [1104][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:22.297 GMT [1104][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:22.332 GMT [4036][startup] LOG:  database system was shut down at 2024-04-04 03:31:21 GMT
2024-04-04 03:31:22.348 GMT [1104][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:22.546 GMT [1104][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:22.547 GMT [1104][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:22.574 GMT [1104][postmaster] LOG:  background worker "logical replication launcher" (PID 6256) exited with exit code 1
2024-04-04 03:31:22.580 GMT [5628][checkpointer] LOG:  shutting down
2024-04-04 03:31:22.580 GMT [5628][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:22.583 GMT [5628][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/407E680, redo lsn=0/407E680
2024-04-04 03:31:22.610 GMT [1104][postmaster] LOG:  database system is shut down
2024-04-04 03:31:22.779 GMT [7136][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:22.780 GMT [7136][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:22.781 GMT [7136][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:22.804 GMT [7604][startup] LOG:  database system was shut down at 2024-04-04 03:31:22 GMT
2024-04-04 03:31:22.813 GMT [7136][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:22.980 GMT [7264][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50391
2024-04-04 03:31:22.982 GMT [7264][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-04 03:31:22.982 GMT [7264][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "pg-loadbalancetest", forward lookup not checked.
2024-04-04 03:31:23.059 GMT [2580][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50394
2024-04-04 03:31:23.066 GMT [2580][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-04 03:31:23.066 GMT [2580][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-04 03:31:23.079 GMT [2580][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-04 03:31:23.082 GMT [2580][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50394
2024-04-04 03:31:23.178 GMT [7260][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50396
2024-04-04 03:31:23.188 GMT [7260][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-04-04 03:31:23.307 GMT [6108][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50398
2024-04-04 03:31:23.316 GMT [6108][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-04-04 03:31:23.399 GMT [7788][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50400
2024-04-04 03:31:23.404 GMT [7788][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-04 03:31:23.563 GMT [7732][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50403
2024-04-04 03:31:23.569 GMT [7732][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-04 03:31:23.660 GMT [3844][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50405
2024-04-04 03:31:23.666 GMT [3844][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-04 03:31:23.740 GMT [1468][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50407
2024-04-04 03:31:23.746 GMT [1468][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-04 03:31:23.848 GMT [5556][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50409
2024-04-04 03:31:23.856 GMT [5556][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-04 03:31:23.856 GMT [5556][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-04 03:31:23.859 GMT [5556][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-04 03:31:23.862 GMT [5556][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.025 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50409
2024-04-04 03:31:23.927 GMT [7728][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50411
2024-04-04 03:31:23.935 GMT [7728][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-04 03:31:23.935 GMT [7728][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-04 03:31:23.938 GMT [7728][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-04 03:31:23.940 GMT [7728][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50411
2024-04-04 03:31:24.012 GMT [6088][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50413
2024-04-04 03:31:24.022 GMT [6088][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-04 03:31:24.022 GMT [6088][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-04 03:31:24.026 GMT [6088][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-04 03:31:24.036 GMT [6088][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50413
2024-04-04 03:31:24.182 GMT [1244][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50415
2024-04-04 03:31:24.190 GMT [1244][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-04 03:31:24.190 GMT [1244][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-04 03:31:24.192 GMT [1244][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-04 03:31:24.196 GMT [1244][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50415
2024-04-04 03:31:24.277 GMT [6548][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50416
2024-04-04 03:31:24.284 GMT [6548][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-04 03:31:24.284 GMT [6548][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-04 03:31:24.287 GMT [6548][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-04 03:31:24.291 GMT [6548][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50416
2024-04-04 03:31:24.375 GMT [1048][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50418
2024-04-04 03:31:24.382 GMT [1048][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-04 03:31:24.382 GMT [1048][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-04 03:31:24.385 GMT [1048][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-04 03:31:24.389 GMT [1048][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50418
2024-04-04 03:31:24.505 GMT [6080][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50420
2024-04-04 03:31:24.517 GMT [6080][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-04 03:31:24.517 GMT [6080][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-04 03:31:24.519 GMT [6080][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-04 03:31:24.522 GMT [6080][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50420
2024-04-04 03:31:24.629 GMT [1156][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50421
2024-04-04 03:31:24.636 GMT [1156][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-04 03:31:24.636 GMT [1156][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-04 03:31:24.652 GMT [1156][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50421
2024-04-04 03:31:24.728 GMT [5744][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50423
2024-04-04 03:31:24.735 GMT [5744][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-04 03:31:24.735 GMT [5744][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-04 03:31:24.758 GMT [5744][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-04 03:31:24.763 GMT [5744][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.041 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50423
2024-04-04 03:31:24.847 GMT [5808][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50425
2024-04-04 03:31:24.853 GMT [5808][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-04 03:31:24.982 GMT [5784][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50428
2024-04-04 03:31:24.989 GMT [5784][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-04 03:31:25.100 GMT [5668][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50430
2024-04-04 03:31:25.108 GMT [5668][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-04 03:31:25.108 GMT [5668][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-04 03:31:25.111 GMT [5668][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-04 03:31:25.115 GMT [5668][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50430
2024-04-04 03:31:25.212 GMT [6248][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50431
2024-04-04 03:31:25.220 GMT [6248][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-04 03:31:25.220 GMT [6248][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-04 03:31:25.223 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 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-04 03:31:25.227 GMT [6248][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50431
2024-04-04 03:31:25.320 GMT [1124][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50432
2024-04-04 03:31:25.328 GMT [1124][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-04 03:31:25.328 GMT [1124][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-04 03:31:25.331 GMT [1124][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-04 03:31:25.335 GMT [1124][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50432
2024-04-04 03:31:25.484 GMT [7292][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50433
2024-04-04 03:31:25.493 GMT [7292][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-04 03:31:25.493 GMT [7292][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-04 03:31:25.498 GMT [7292][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-04 03:31:25.503 GMT [7292][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.040 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50433
2024-04-04 03:31:25.657 GMT [6240][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50434
2024-04-04 03:31:25.723 GMT [7136][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:25.724 GMT [7136][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:25.732 GMT [7136][postmaster] LOG:  background worker "logical replication launcher" (PID 6856) exited with exit code 1
2024-04-04 03:31:25.735 GMT [6448][checkpointer] LOG:  shutting down
2024-04-04 03:31:25.735 GMT [6448][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:25.738 GMT [6448][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-04 03:31:25.744 GMT [7136][postmaster] LOG:  database system is shut down
2024-04-04 03:31:25.882 GMT [6864][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:25.883 GMT [6864][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:25.884 GMT [6864][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:25.909 GMT [2084][startup] LOG:  database system was shut down at 2024-04-04 03:31:25 GMT
2024-04-04 03:31:25.918 GMT [6864][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:25.996 GMT [2612][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50435
2024-04-04 03:31:26.004 GMT [2612][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-04-04 03:31:26.004 GMT [2612][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-04-04 03:31:26.021 GMT [2612][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-04-04 03:31:26.024 GMT [2612][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50435
2024-04-04 03:31:26.081 GMT [7000][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50436
2024-04-04 03:31:26.164 GMT [6864][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:26.164 GMT [6864][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:26.174 GMT [6864][postmaster] LOG:  background worker "logical replication launcher" (PID 1484) exited with exit code 1
2024-04-04 03:31:26.175 GMT [3688][checkpointer] LOG:  shutting down
2024-04-04 03:31:26.176 GMT [3688][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:26.179 GMT [3688][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-04 03:31:26.184 GMT [6864][postmaster] LOG:  database system is shut down
2024-04-04 03:31:26.339 GMT [6984][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:26.340 GMT [6984][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:26.342 GMT [6984][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:26.375 GMT [7352][startup] LOG:  database system was shut down at 2024-04-04 03:31:26 GMT
2024-04-04 03:31:26.386 GMT [6984][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:26.487 GMT [2228][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50437
2024-04-04 03:31:26.494 GMT [2228][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-04 03:31:26.494 GMT [2228][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-04 03:31:26.508 GMT [2228][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-04 03:31:26.513 GMT [2228][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50437
2024-04-04 03:31:26.554 GMT [6984][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:26.554 GMT [6984][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:26.562 GMT [6984][postmaster] LOG:  background worker "logical replication launcher" (PID 2516) exited with exit code 1
2024-04-04 03:31:26.564 GMT [3452][checkpointer] LOG:  shutting down
2024-04-04 03:31:26.565 GMT [3452][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:26.569 GMT [3452][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.005 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-04 03:31:26.574 GMT [6984][postmaster] LOG:  database system is shut down
2024-04-04 03:31:26.716 GMT [3276][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:26.717 GMT [3276][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:26.719 GMT [3276][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:26.766 GMT [4172][startup] LOG:  database system was shut down at 2024-04-04 03:31:26 GMT
2024-04-04 03:31:26.820 GMT [3276][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:26.923 GMT [5504][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50438
2024-04-04 03:31:26.933 GMT [5504][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-04-04 03:31:26.933 GMT [5504][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-04-04 03:31:26.946 GMT [5504][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns1.alt-name.pg-ssltest.test$$
2024-04-04 03:31:26.951 GMT [5504][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50438
2024-04-04 03:31:27.020 GMT [5608][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50439
2024-04-04 03:31:27.027 GMT [5608][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-04 03:31:27.027 GMT [5608][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-04 03:31:27.030 GMT [5608][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-04 03:31:27.034 GMT [5608][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50439
2024-04-04 03:31:27.129 GMT [968][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50440
2024-04-04 03:31:27.137 GMT [968][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-04 03:31:27.137 GMT [968][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-04 03:31:27.140 GMT [968][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-04 03:31:27.144 GMT [968][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50440
2024-04-04 03:31:27.232 GMT [916][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50441
2024-04-04 03:31:27.346 GMT [4712][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50442
2024-04-04 03:31:27.431 GMT [3276][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:27.431 GMT [3276][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:27.436 GMT [3276][postmaster] LOG:  background worker "logical replication launcher" (PID 3620) exited with exit code 1
2024-04-04 03:31:27.437 GMT [5980][checkpointer] LOG:  shutting down
2024-04-04 03:31:27.438 GMT [5980][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:27.441 GMT [5980][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/407E860, redo lsn=0/407E860
2024-04-04 03:31:27.446 GMT [3276][postmaster] LOG:  database system is shut down
2024-04-04 03:31:27.594 GMT [1816][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:27.595 GMT [1816][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:27.596 GMT [1816][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:27.618 GMT [6536][startup] LOG:  database system was shut down at 2024-04-04 03:31:27 GMT
2024-04-04 03:31:27.626 GMT [1816][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:27.688 GMT [7092][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50443
2024-04-04 03:31:27.696 GMT [7092][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-04 03:31:27.696 GMT [7092][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-04 03:31:27.710 GMT [7092][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-04 03:31:27.714 GMT [7092][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50443
2024-04-04 03:31:27.799 GMT [7760][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50444
2024-04-04 03:31:27.906 GMT [3916][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50445
2024-04-04 03:31:27.973 GMT [1816][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:27.973 GMT [1816][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:27.978 GMT [1816][postmaster] LOG:  background worker "logical replication launcher" (PID 5224) exited with exit code 1
2024-04-04 03:31:27.979 GMT [3768][checkpointer] LOG:  shutting down
2024-04-04 03:31:27.979 GMT [3768][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:27.982 GMT [3768][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/407E8D8, redo lsn=0/407E8D8
2024-04-04 03:31:27.987 GMT [1816][postmaster] LOG:  database system is shut down
2024-04-04 03:31:28.141 GMT [3728][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:28.142 GMT [3728][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:28.143 GMT [3728][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:28.174 GMT [5836][startup] LOG:  database system was shut down at 2024-04-04 03:31:27 GMT
2024-04-04 03:31:28.194 GMT [3728][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:28.346 GMT [3732][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50446
2024-04-04 03:31:28.354 GMT [3732][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-04 03:31:28.354 GMT [3732][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-04 03:31:28.367 GMT [3732][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-04 03:31:28.370 GMT [3732][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50446
2024-04-04 03:31:28.455 GMT [1032][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50447
2024-04-04 03:31:28.464 GMT [1032][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-04 03:31:28.464 GMT [1032][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-04 03:31:28.467 GMT [1032][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-04 03:31:28.469 GMT [1032][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50447
2024-04-04 03:31:28.519 GMT [3864][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50448
2024-04-04 03:31:28.584 GMT [3728][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:28.584 GMT [3728][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:28.591 GMT [3728][postmaster] LOG:  background worker "logical replication launcher" (PID 5964) exited with exit code 1
2024-04-04 03:31:28.592 GMT [7708][checkpointer] LOG:  shutting down
2024-04-04 03:31:28.592 GMT [7708][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:28.595 GMT [7708][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/407E950, redo lsn=0/407E950
2024-04-04 03:31:28.601 GMT [3728][postmaster] LOG:  database system is shut down
2024-04-04 03:31:28.752 GMT [2456][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:28.753 GMT [2456][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:28.755 GMT [2456][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:28.778 GMT [6616][startup] LOG:  database system was shut down at 2024-04-04 03:31:28 GMT
2024-04-04 03:31:28.797 GMT [2456][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:28.940 GMT [7464][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50449
2024-04-04 03:31:28.947 GMT [7464][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-04 03:31:28.947 GMT [7464][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-04 03:31:28.960 GMT [7464][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-04 03:31:29.047 GMT [7464][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.115 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50449
2024-04-04 03:31:29.278 GMT [5936][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50450
2024-04-04 03:31:29.287 GMT [5936][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-04 03:31:29.287 GMT [5936][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-04 03:31:29.290 GMT [5936][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-04 03:31:29.339 GMT [5936][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.070 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50450
2024-04-04 03:31:29.478 GMT [6708][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50451
2024-04-04 03:31:29.484 GMT [6708][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-04 03:31:29.484 GMT [6708][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-04 03:31:29.488 GMT [6708][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-04 03:31:29.491 GMT [6708][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50451
2024-04-04 03:31:29.557 GMT [2456][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:29.558 GMT [2456][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:29.563 GMT [2456][postmaster] LOG:  background worker "logical replication launcher" (PID 6868) exited with exit code 1
2024-04-04 03:31:29.564 GMT [4176][checkpointer] LOG:  shutting down
2024-04-04 03:31:29.565 GMT [4176][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:29.567 GMT [4176][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/407E9C8, redo lsn=0/407E9C8
2024-04-04 03:31:29.572 GMT [2456][postmaster] LOG:  database system is shut down
2024-04-04 03:31:29.722 GMT [4316][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:29.723 GMT [4316][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:29.724 GMT [4316][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:29.750 GMT [4664][startup] LOG:  database system was shut down at 2024-04-04 03:31:29 GMT
2024-04-04 03:31:29.761 GMT [4316][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:29.822 GMT [7428][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50452
2024-04-04 03:31:29.829 GMT [7428][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-04 03:31:29.829 GMT [7428][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-04 03:31:29.842 GMT [7428][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-04 03:31:29.844 GMT [7428][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50452
2024-04-04 03:31:29.924 GMT [6468][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50453
2024-04-04 03:31:29.962 GMT [4316][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:29.963 GMT [4316][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:29.967 GMT [4316][postmaster] LOG:  background worker "logical replication launcher" (PID 3344) exited with exit code 1
2024-04-04 03:31:29.968 GMT [6744][checkpointer] LOG:  shutting down
2024-04-04 03:31:29.968 GMT [6744][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:29.971 GMT [6744][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-04 03:31:29.975 GMT [4316][postmaster] LOG:  database system is shut down
2024-04-04 03:31:30.119 GMT [5128][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:30.120 GMT [5128][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:30.121 GMT [5128][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:30.144 GMT [4092][startup] LOG:  database system was shut down at 2024-04-04 03:31:29 GMT
2024-04-04 03:31:30.151 GMT [5128][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:30.223 GMT [7072][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50454
2024-04-04 03:31:30.228 GMT [7072][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-04-04 03:31:30.351 GMT [3760][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50455
2024-04-04 03:31:30.358 GMT [3760][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-04-04 03:31:30.358 GMT [3760][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-04-04 03:31:30.371 GMT [3760][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=system hostaddr=127.0.0.1 sslmode=verify-full host=common-name.pg-ssltest.test$$
2024-04-04 03:31:30.375 GMT [3760][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50455
2024-04-04 03:31:30.458 GMT [8052][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50456
2024-04-04 03:31:30.492 GMT [5128][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:30.493 GMT [5128][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:30.498 GMT [5128][postmaster] LOG:  background worker "logical replication launcher" (PID 6052) exited with exit code 1
2024-04-04 03:31:30.498 GMT [6660][checkpointer] LOG:  shutting down
2024-04-04 03:31:30.498 GMT [6660][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:30.501 GMT [6660][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-04 03:31:30.505 GMT [5128][postmaster] LOG:  database system is shut down
2024-04-04 03:31:30.657 GMT [1736][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:30.658 GMT [1736][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:30.659 GMT [1736][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:30.695 GMT [1408][startup] LOG:  database system was shut down at 2024-04-04 03:31:30 GMT
2024-04-04 03:31:30.703 GMT [1736][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:30.770 GMT [8148][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50458
2024-04-04 03:31:30.777 GMT [8148][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-04 03:31:30.777 GMT [8148][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-04 03:31:30.790 GMT [8148][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-04 03:31:30.793 GMT [8148][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50458
2024-04-04 03:31:30.881 GMT [5304][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50459
2024-04-04 03:31:30.896 GMT [5304][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-04-04 03:31:30.989 GMT [5648][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50460
2024-04-04 03:31:30.996 GMT [5648][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-04-04 03:31:31.055 GMT [2148][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50461
2024-04-04 03:31:31.062 GMT [2148][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-04 03:31:31.062 GMT [2148][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-04 03:31:31.065 GMT [2148][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-04-04 03:31:31.070 GMT [2148][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50461
2024-04-04 03:31:31.163 GMT [5512][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50462
2024-04-04 03:31:31.171 GMT [5512][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-04 03:31:31.171 GMT [5512][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-04 03:31:31.174 GMT [5512][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-04 03:31:31.177 GMT [5512][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50462
2024-04-04 03:31:31.461 GMT [4340][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50463
2024-04-04 03:31:31.469 GMT [4340][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-04-04 03:31:31.570 GMT [1324][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50464
2024-04-04 03:31:31.580 GMT [1324][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-04 03:31:31.580 GMT [1324][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-04 03:31:31.593 GMT [1324][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_GkUJ/client.key$$
2024-04-04 03:31:31.597 GMT [1324][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb host=pg-loadbalancetest port=50464
2024-04-04 03:31:31.684 GMT [3320][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50465
2024-04-04 03:31:31.693 GMT [3320][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-04 03:31:31.693 GMT [3320][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-04 03:31:31.696 GMT [3320][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_GkUJ/client-der.key$$
2024-04-04 03:31:31.699 GMT [3320][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50465
2024-04-04 03:31:31.794 GMT [5992][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50466
2024-04-04 03:31:31.804 GMT [5992][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-04 03:31:31.804 GMT [5992][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-04 03:31:31.807 GMT [5992][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_GkUJ/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-04-04 03:31:31.809 GMT [5992][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50466
2024-04-04 03:31:31.903 GMT [4032][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50467
2024-04-04 03:31:31.912 GMT [4032][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-04 03:31:31.912 GMT [4032][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-04 03:31:31.915 GMT [4032][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_GkUJ/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-04-04 03:31:31.919 GMT [4032][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50467
2024-04-04 03:31:32.009 GMT [6256][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50468
2024-04-04 03:31:32.018 GMT [6256][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-04 03:31:32.019 GMT [6256][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-04 03:31:32.021 GMT [6256][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_GkUJ/client.key$$
2024-04-04 03:31:32.024 GMT [6256][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50468
2024-04-04 03:31:32.119 GMT [2940][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50469
2024-04-04 03:31:32.129 GMT [2940][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-04 03:31:32.129 GMT [2940][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-04 03:31:32.131 GMT [2940][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_GkUJ/client.key$$
2024-04-04 03:31:32.134 GMT [2940][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50469
2024-04-04 03:31:32.228 GMT [4328][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50470
2024-04-04 03:31:32.236 GMT [4328][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-04-04 03:31:32.351 GMT [440][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50471
2024-04-04 03:31:32.363 GMT [440][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-04-04 03:31:32.419 GMT [7380][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50472
2024-04-04 03:31:32.428 GMT [7380][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-04 03:31:32.428 GMT [7380][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-04 03:31:32.442 GMT [7380][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_GkUJ/client-dn.key$$
2024-04-04 03:31:32.445 GMT [7380][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50472
2024-04-04 03:31:32.531 GMT [5444][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50473
2024-04-04 03:31:32.541 GMT [5444][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-04 03:31:32.541 GMT [5444][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-04 03:31:32.555 GMT [5444][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_GkUJ/client-dn.key$$
2024-04-04 03:31:32.558 GMT [5444][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50473
2024-04-04 03:31:32.638 GMT [4932][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50474
2024-04-04 03:31:32.648 GMT [4932][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-04 03:31:32.648 GMT [4932][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-04 03:31:32.661 GMT [4932][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_GkUJ/client-dn.key$$
2024-04-04 03:31:32.665 GMT [4932][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50474
2024-04-04 03:31:32.751 GMT [4640][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50475
2024-04-04 03:31:32.761 GMT [4640][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-04 03:31:32.761 GMT [4640][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-04 03:31:32.764 GMT [4640][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-04-04 03:31:32.770 GMT [4640][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=certdb host=pg-loadbalancetest port=50475
2024-04-04 03:31:32.855 GMT [1200][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50476
2024-04-04 03:31:32.865 GMT [1200][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-04 03:31:32.865 GMT [1200][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-04-04 03:31:32.865 GMT [1200][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-04-04 03:31:32.865 GMT [1200][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-04 03:31:32.969 GMT [3784][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50477
2024-04-04 03:31:32.976 GMT [3784][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-04 03:31:32.976 GMT [3784][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-04 03:31:33.075 GMT [6576][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50479
2024-04-04 03:31:33.084 GMT [6576][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-04 03:31:33.084 GMT [6576][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-04 03:31:33.096 GMT [6576][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_GkUJ/client.key$$
2024-04-04 03:31:33.100 GMT [6576][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50479
2024-04-04 03:31:33.178 GMT [2404][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50480
2024-04-04 03:31:33.187 GMT [2404][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-04-04 03:31:33.188 GMT [2404][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-04-04 03:31:33.188 GMT [2404][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-04-04 03:31:33.188 GMT [2404][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-04 03:31:33.245 GMT [796][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50481
2024-04-04 03:31:33.255 GMT [796][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-04 03:31:33.255 GMT [796][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-04 03:31:33.258 GMT [796][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_GkUJ/client.key$$
2024-04-04 03:31:33.261 GMT [796][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50481
2024-04-04 03:31:33.327 GMT [1736][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:33.327 GMT [1736][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:33.332 GMT [1736][postmaster] LOG:  background worker "logical replication launcher" (PID 496) exited with exit code 1
2024-04-04 03:31:33.333 GMT [4892][checkpointer] LOG:  shutting down
2024-04-04 03:31:33.333 GMT [4892][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:33.336 GMT [4892][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-04 03:31:33.341 GMT [1736][postmaster] LOG:  database system is shut down
2024-04-04 03:31:33.491 GMT [4692][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:33.491 GMT [4692][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:33.492 GMT [4692][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:33.518 GMT [6212][startup] LOG:  database system was shut down at 2024-04-04 03:31:33 GMT
2024-04-04 03:31:33.526 GMT [4692][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:33.591 GMT [8064][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50482
2024-04-04 03:31:33.600 GMT [8064][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-04 03:31:33.600 GMT [8064][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-04 03:31:33.617 GMT [8064][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=certdb  sslkey=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_GkUJ/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-04 03:31:33.620 GMT [8064][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.037 user=ssltestuser database=certdb host=pg-loadbalancetest port=50482
2024-04-04 03:31:33.697 GMT [7416][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50483
2024-04-04 03:31:33.705 GMT [7416][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-04 03:31:33.705 GMT [7416][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-04 03:31:33.762 GMT [3776][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50484
2024-04-04 03:31:33.769 GMT [3776][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-04 03:31:33.769 GMT [3776][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-04 03:31:33.797 GMT [4692][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:33.797 GMT [4692][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:33.801 GMT [4692][postmaster] LOG:  background worker "logical replication launcher" (PID 6440) exited with exit code 1
2024-04-04 03:31:33.801 GMT [2252][checkpointer] LOG:  shutting down
2024-04-04 03:31:33.802 GMT [2252][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:33.804 GMT [2252][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/407EBA8, redo lsn=0/407EBA8
2024-04-04 03:31:33.809 GMT [4692][postmaster] LOG:  database system is shut down
2024-04-04 03:31:33.957 GMT [5804][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:33.958 GMT [5804][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:33.959 GMT [5804][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:33.980 GMT [5180][startup] LOG:  database system was shut down at 2024-04-04 03:31:33 GMT
2024-04-04 03:31:33.988 GMT [5804][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:34.063 GMT [7644][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50485
2024-04-04 03:31:34.071 GMT [7644][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-04 03:31:34.071 GMT [7644][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-04 03:31:34.139 GMT [5804][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:34.139 GMT [5804][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:34.144 GMT [5804][postmaster] LOG:  background worker "logical replication launcher" (PID 5664) exited with exit code 1
2024-04-04 03:31:34.145 GMT [7388][checkpointer] LOG:  shutting down
2024-04-04 03:31:34.145 GMT [7388][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:34.148 GMT [7388][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/407EC20, redo lsn=0/407EC20
2024-04-04 03:31:34.154 GMT [5804][postmaster] LOG:  database system is shut down
2024-04-04 03:31:34.310 GMT [7484][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:34.310 GMT [7484][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:34.312 GMT [7484][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:34.340 GMT [5108][startup] LOG:  database system was shut down at 2024-04-04 03:31:34 GMT
2024-04-04 03:31:34.351 GMT [7484][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:34.416 GMT [1216][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50486
2024-04-04 03:31:34.424 GMT [1216][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-04 03:31:34.424 GMT [1216][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-04 03:31:34.529 GMT [3512][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50487
2024-04-04 03:31:34.537 GMT [3512][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-04-04 03:31:34.537 GMT [3512][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-04 03:31:34.615 GMT [7484][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:34.615 GMT [7484][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:34.620 GMT [7484][postmaster] LOG:  background worker "logical replication launcher" (PID 3448) exited with exit code 1
2024-04-04 03:31:34.620 GMT [4796][checkpointer] LOG:  shutting down
2024-04-04 03:31:34.620 GMT [4796][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:34.623 GMT [4796][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/407EC98, redo lsn=0/407EC98
2024-04-04 03:31:34.627 GMT [7484][postmaster] LOG:  database system is shut down
2024-04-04 03:31:34.781 GMT [7788][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:34.781 GMT [7788][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:34.782 GMT [7788][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:34.803 GMT [5864][startup] LOG:  database system was shut down at 2024-04-04 03:31:34 GMT
2024-04-04 03:31:34.810 GMT [7788][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:34.877 GMT [6104][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50488
2024-04-04 03:31:34.881 GMT [6104][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:34.881 GMT [6104][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:34.957 GMT [2076][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50489
2024-04-04 03:31:34.965 GMT [2076][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-04 03:31:34.965 GMT [2076][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-04 03:31:34.985 GMT [2076][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-04 03:31:34.990 GMT [2076][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.039 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50489
2024-04-04 03:31:35.035 GMT [7788][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:35.035 GMT [7788][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:35.043 GMT [7788][postmaster] LOG:  background worker "logical replication launcher" (PID 3544) exited with exit code 1
2024-04-04 03:31:35.045 GMT [6780][checkpointer] LOG:  shutting down
2024-04-04 03:31:35.045 GMT [6780][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:35.048 GMT [6780][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/407ED10, redo lsn=0/407ED10
2024-04-04 03:31:35.054 GMT [7788][postmaster] LOG:  database system is shut down
2024-04-04 03:31:35.215 GMT [6764][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:35.215 GMT [6764][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:35.216 GMT [6764][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:35.237 GMT [3404][startup] LOG:  database system was shut down at 2024-04-04 03:31:35 GMT
2024-04-04 03:31:35.249 GMT [6764][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:35.309 GMT [7724][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50490
2024-04-04 03:31:35.313 GMT [7724][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:35.313 GMT [7724][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:35.378 GMT [3988][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50491
2024-04-04 03:31:35.385 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-04 03:31:35.385 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-04 03:31:35.397 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+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-04-04 03:31:35.400 GMT [3988][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50491
2024-04-04 03:31:35.457 GMT [6764][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:35.458 GMT [6764][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:35.462 GMT [6764][postmaster] LOG:  background worker "logical replication launcher" (PID 5416) exited with exit code 1
2024-04-04 03:31:35.462 GMT [7704][checkpointer] LOG:  shutting down
2024-04-04 03:31:35.462 GMT [7704][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:35.465 GMT [7704][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/407ED88, redo lsn=0/407ED88
2024-04-04 03:31:35.470 GMT [6764][postmaster] LOG:  database system is shut down
2024-04-04 03:31:35.644 GMT [5948][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:35.645 GMT [5948][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:35.646 GMT [5948][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:35.675 GMT [7596][startup] LOG:  database system was shut down at 2024-04-04 03:31:35 GMT
2024-04-04 03:31:35.683 GMT [5948][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:35.832 GMT [7964][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50492
2024-04-04 03:31:35.835 GMT [7964][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:35.835 GMT [7964][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:35.936 GMT [1604][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50493
2024-04-04 03:31:35.943 GMT [1604][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-04 03:31:35.943 GMT [1604][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-04 03:31:35.957 GMT [1604][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-04 03:31:35.961 GMT [1604][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50493
2024-04-04 03:31:36.021 GMT [5948][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:36.021 GMT [5948][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:36.025 GMT [5948][postmaster] LOG:  background worker "logical replication launcher" (PID 3384) exited with exit code 1
2024-04-04 03:31:36.026 GMT [3504][checkpointer] LOG:  shutting down
2024-04-04 03:31:36.026 GMT [3504][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:36.029 GMT [3504][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/407EE00, redo lsn=0/407EE00
2024-04-04 03:31:36.034 GMT [5948][postmaster] LOG:  database system is shut down
2024-04-04 03:31:36.179 GMT [2812][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:36.180 GMT [2812][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:36.181 GMT [2812][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:36.200 GMT [7408][startup] LOG:  database system was shut down at 2024-04-04 03:31:36 GMT
2024-04-04 03:31:36.208 GMT [2812][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:36.280 GMT [3796][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50494
2024-04-04 03:31:36.283 GMT [3796][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:36.284 GMT [3796][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:36.348 GMT [6324][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50495
2024-04-04 03:31:36.355 GMT [6324][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-04 03:31:36.355 GMT [6324][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-04 03:31:36.368 GMT [6324][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-04 03:31:36.371 GMT [6324][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50495
2024-04-04 03:31:36.425 GMT [2812][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:36.425 GMT [2812][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:36.430 GMT [2812][postmaster] LOG:  background worker "logical replication launcher" (PID 1440) exited with exit code 1
2024-04-04 03:31:36.431 GMT [1572][checkpointer] LOG:  shutting down
2024-04-04 03:31:36.431 GMT [1572][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:36.434 GMT [1572][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-04 03:31:36.439 GMT [2812][postmaster] LOG:  database system is shut down
2024-04-04 03:31:36.587 GMT [3600][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:36.588 GMT [3600][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:36.589 GMT [3600][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:36.610 GMT [4704][startup] LOG:  database system was shut down at 2024-04-04 03:31:36 GMT
2024-04-04 03:31:36.618 GMT [3600][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:36.685 GMT [6020][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50496
2024-04-04 03:31:36.688 GMT [6020][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:36.689 GMT [6020][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:36.753 GMT [4808][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50497
2024-04-04 03:31:36.760 GMT [4808][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-04 03:31:36.760 GMT [4808][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-04 03:31:36.773 GMT [4808][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-04 03:31:36.776 GMT [4808][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50497
2024-04-04 03:31:36.831 GMT [3600][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:36.831 GMT [3600][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:36.837 GMT [3600][postmaster] LOG:  background worker "logical replication launcher" (PID 6776) exited with exit code 1
2024-04-04 03:31:36.837 GMT [6932][checkpointer] LOG:  shutting down
2024-04-04 03:31:36.837 GMT [6932][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:36.840 GMT [6932][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-04 03:31:36.845 GMT [3600][postmaster] LOG:  database system is shut down
2024-04-04 03:31:36.996 GMT [6004][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:36.997 GMT [6004][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:36.998 GMT [6004][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:37.020 GMT [2324][startup] LOG:  database system was shut down at 2024-04-04 03:31:36 GMT
2024-04-04 03:31:37.028 GMT [6004][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:37.092 GMT [2216][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50498
2024-04-04 03:31:37.095 GMT [2216][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:37.095 GMT [2216][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:37.160 GMT [5232][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50499
2024-04-04 03:31:37.168 GMT [5232][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-04 03:31:37.168 GMT [5232][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-04 03:31:37.181 GMT [5232][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-04 03:31:37.185 GMT [5232][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50499
2024-04-04 03:31:37.239 GMT [6004][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:37.239 GMT [6004][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:37.244 GMT [6004][postmaster] LOG:  background worker "logical replication launcher" (PID 1060) exited with exit code 1
2024-04-04 03:31:37.245 GMT [7972][checkpointer] LOG:  shutting down
2024-04-04 03:31:37.245 GMT [7972][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:37.248 GMT [7972][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/407EF68, redo lsn=0/407EF68
2024-04-04 03:31:37.252 GMT [6004][postmaster] LOG:  database system is shut down
2024-04-04 03:31:37.405 GMT [5912][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:37.406 GMT [5912][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:37.407 GMT [5912][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:37.429 GMT [7356][startup] LOG:  database system was shut down at 2024-04-04 03:31:37 GMT
2024-04-04 03:31:37.438 GMT [5912][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:37.500 GMT [6496][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50500
2024-04-04 03:31:37.503 GMT [6496][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:37.504 GMT [6496][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:37.564 GMT [4120][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50501
2024-04-04 03:31:37.571 GMT [4120][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-04 03:31:37.571 GMT [4120][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-04 03:31:37.584 GMT [4120][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-04 03:31:37.587 GMT [4120][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50501
2024-04-04 03:31:37.649 GMT [5912][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:37.649 GMT [5912][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:37.653 GMT [5912][postmaster] LOG:  background worker "logical replication launcher" (PID 708) exited with exit code 1
2024-04-04 03:31:37.654 GMT [3164][checkpointer] LOG:  shutting down
2024-04-04 03:31:37.654 GMT [3164][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:37.657 GMT [3164][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/407EFE0, redo lsn=0/407EFE0
2024-04-04 03:31:37.663 GMT [5912][postmaster] LOG:  database system is shut down
2024-04-04 03:31:37.815 GMT [4668][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:37.816 GMT [4668][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:37.817 GMT [4668][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:37.847 GMT [3868][startup] LOG:  database system was shut down at 2024-04-04 03:31:37 GMT
2024-04-04 03:31:37.855 GMT [4668][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:37.912 GMT [6216][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50502
2024-04-04 03:31:37.915 GMT [6216][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:37.916 GMT [6216][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:38.018 GMT [6008][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50503
2024-04-04 03:31:38.025 GMT [6008][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-04 03:31:38.025 GMT [6008][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-04 03:31:38.038 GMT [6008][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-04 03:31:38.041 GMT [6008][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50503
2024-04-04 03:31:38.098 GMT [4668][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:38.098 GMT [4668][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:38.102 GMT [4668][postmaster] LOG:  background worker "logical replication launcher" (PID 1812) exited with exit code 1
2024-04-04 03:31:38.104 GMT [7712][checkpointer] LOG:  shutting down
2024-04-04 03:31:38.104 GMT [7712][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:38.107 GMT [7712][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/407F058, redo lsn=0/407F058
2024-04-04 03:31:38.112 GMT [4668][postmaster] LOG:  database system is shut down
2024-04-04 03:31:38.263 GMT [7508][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-04-04 03:31:38.264 GMT [7508][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63283
2024-04-04 03:31:38.265 GMT [7508][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/_SgL5oyIMQ/.s.PGSQL.63283"
2024-04-04 03:31:38.295 GMT [4328][startup] LOG:  database system was shut down at 2024-04-04 03:31:38 GMT
2024-04-04 03:31:38.303 GMT [7508][postmaster] LOG:  database system is ready to accept connections
2024-04-04 03:31:38.359 GMT [4296][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50504
2024-04-04 03:31:38.363 GMT [4296][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-04-04 03:31:38.363 GMT [4296][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-04-04 03:31:38.422 GMT [2092][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50505
2024-04-04 03:31:38.429 GMT [2092][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-04 03:31:38.429 GMT [2092][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-04 03:31:38.443 GMT [2092][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-04 03:31:38.445 GMT [2092][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50505
2024-04-04 03:31:38.505 GMT [7508][postmaster] LOG:  received fast shutdown request
2024-04-04 03:31:38.505 GMT [7508][postmaster] LOG:  aborting any active transactions
2024-04-04 03:31:38.512 GMT [7508][postmaster] LOG:  background worker "logical replication launcher" (PID 1904) exited with exit code 1
2024-04-04 03:31:38.513 GMT [3812][checkpointer] LOG:  shutting down
2024-04-04 03:31:38.513 GMT [3812][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-04-04 03:31:38.516 GMT [3812][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-04 03:31:38.521 GMT [7508][postmaster] LOG:  database system is shut down
2024-04-04 03:31:38.661 GMT [7336][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-04-04 03:31:38.661 GMT [7336][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[03:31:38.723](0.236s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"