[13:27:42.875](0.237s) # setting up data directory
# Checking port 64238
# Found port 64238
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=64238 host=C:/Windows/TEMP/0FugazuNjO
Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log
[13:27:42.893](0.019s) # 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 3556
[13:27:44.686](1.792s) 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 6124
[13:27:50.536](5.851s) # testing password-protected keys
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
# pg_ctl restart failed; logfile:
2024-03-16 13:27:44.299 GMT [3556][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:44.301 GMT [3556][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:44.333 GMT [5848][startup] LOG:  database system was shut down at 2024-03-16 13:18:11 GMT
2024-03-16 13:27:44.399 GMT [3556][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:44.594 GMT [3696][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:44.596 GMT [3696][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:44.596 GMT [3696][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:44.609 GMT [3696][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-16 13:27:44.612 GMT [3696][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:44.786 GMT [1892][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:44.787 GMT [1892][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:44.787 GMT [1892][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:44.790 GMT [1892][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-16 13:27:44.791 GMT [1892][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.098 GMT [1712][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.100 GMT [1712][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.100 GMT [1712][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.102 GMT [1712][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-16 13:27:45.103 GMT [1712][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.242 GMT [6544][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.243 GMT [6544][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.243 GMT [6544][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.245 GMT [6544][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-16 13:27:45.246 GMT [6544][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.395 GMT [5556][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.401 GMT [5556][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.401 GMT [5556][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.423 GMT [5556][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-16 13:27:45.424 GMT [5556][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.046 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.573 GMT [2224][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.591 GMT [2224][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.591 GMT [2224][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.600 GMT [2224][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-16 13:27:46.390 GMT [2224][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.827 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:46.895 GMT [4116][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:46.897 GMT [4116][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:46.897 GMT [4116][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:46.899 GMT [4116][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-16 13:27:47.135 GMT [4116][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.242 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:47.387 GMT [664][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:47.389 GMT [664][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:47.389 GMT [664][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:47.391 GMT [664][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-16 13:27:47.590 GMT [664][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.206 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:47.792 GMT [6240][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:47.794 GMT [6240][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:47.794 GMT [6240][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:47.819 GMT [6240][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-16 13:27:48.113 GMT [6240][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.323 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:48.362 GMT [6172][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:48.368 GMT [6172][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:48.368 GMT [6172][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:48.374 GMT [6172][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-16 13:27:48.612 GMT [6172][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.268 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:48.878 GMT [2416][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:48.883 GMT [2416][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:48.883 GMT [2416][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:48.888 GMT [2416][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-16 13:27:49.176 GMT [2416][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.302 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:49.445 GMT [3556][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:49.446 GMT [3556][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:49.492 GMT [3556][postmaster] LOG:  background worker "logical replication launcher" (PID 5936) exited with exit code 1
2024-03-16 13:27:49.529 GMT [7880][checkpointer] LOG:  shutting down
2024-03-16 13:27:49.530 GMT [7880][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:49.860 GMT [7880][checkpointer] LOG:  checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.322 s, sync=0.001 s, total=0.332 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C5EE8, redo lsn=0/40C5EE8
2024-03-16 13:27:49.995 GMT [3556][postmaster] LOG:  database system is shut down
2024-03-16 13:27:50.397 GMT [6124][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:50.398 GMT [6124][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:50.399 GMT [6124][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:50.454 GMT [4780][startup] LOG:  database system was shut down at 2024-03-16 13:27:49 GMT
2024-03-16 13:27:50.490 GMT [6124][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:50.589 GMT [6124][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:50.589 GMT [6124][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:50.631 GMT [6124][postmaster] LOG:  background worker "logical replication launcher" (PID 5364) exited with exit code 1
2024-03-16 13:27:50.631 GMT [724][checkpointer] LOG:  shutting down
2024-03-16 13:27:50.631 GMT [724][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:50.635 GMT [724][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/40C5F60, redo lsn=0/40C5F60
2024-03-16 13:27:50.690 GMT [6124][postmaster] LOG:  database system is shut down
2024-03-16 13:27:51.015 GMT [2416][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-16 13:27:51.015 GMT [2416][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:27:51.208](0.672s) 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 7316
[13:27:51.640](0.432s) ok 3 - restart succeeds with password-protected key file
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
# pg_ctl restart failed; logfile:
2024-03-16 13:27:44.299 GMT [3556][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:44.301 GMT [3556][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:44.333 GMT [5848][startup] LOG:  database system was shut down at 2024-03-16 13:18:11 GMT
2024-03-16 13:27:44.399 GMT [3556][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:44.594 GMT [3696][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:44.596 GMT [3696][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:44.596 GMT [3696][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:44.609 GMT [3696][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-16 13:27:44.612 GMT [3696][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:44.786 GMT [1892][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:44.787 GMT [1892][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:44.787 GMT [1892][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:44.790 GMT [1892][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-16 13:27:44.791 GMT [1892][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.098 GMT [1712][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.100 GMT [1712][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.100 GMT [1712][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.102 GMT [1712][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-16 13:27:45.103 GMT [1712][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.242 GMT [6544][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.243 GMT [6544][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.243 GMT [6544][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.245 GMT [6544][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-16 13:27:45.246 GMT [6544][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.395 GMT [5556][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.401 GMT [5556][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.401 GMT [5556][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.423 GMT [5556][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-16 13:27:45.424 GMT [5556][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.046 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.573 GMT [2224][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.591 GMT [2224][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.591 GMT [2224][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.600 GMT [2224][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-16 13:27:46.390 GMT [2224][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.827 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:46.895 GMT [4116][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:46.897 GMT [4116][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:46.897 GMT [4116][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:46.899 GMT [4116][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-16 13:27:47.135 GMT [4116][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.242 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:47.387 GMT [664][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:47.389 GMT [664][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:47.389 GMT [664][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:47.391 GMT [664][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-16 13:27:47.590 GMT [664][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.206 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:47.792 GMT [6240][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:47.794 GMT [6240][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:47.794 GMT [6240][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:47.819 GMT [6240][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-16 13:27:48.113 GMT [6240][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.323 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:48.362 GMT [6172][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:48.368 GMT [6172][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:48.368 GMT [6172][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:48.374 GMT [6172][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-16 13:27:48.612 GMT [6172][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.268 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:48.878 GMT [2416][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:48.883 GMT [2416][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:48.883 GMT [2416][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:48.888 GMT [2416][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-16 13:27:49.176 GMT [2416][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.302 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:49.445 GMT [3556][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:49.446 GMT [3556][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:49.492 GMT [3556][postmaster] LOG:  background worker "logical replication launcher" (PID 5936) exited with exit code 1
2024-03-16 13:27:49.529 GMT [7880][checkpointer] LOG:  shutting down
2024-03-16 13:27:49.530 GMT [7880][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:49.860 GMT [7880][checkpointer] LOG:  checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.322 s, sync=0.001 s, total=0.332 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C5EE8, redo lsn=0/40C5EE8
2024-03-16 13:27:49.995 GMT [3556][postmaster] LOG:  database system is shut down
2024-03-16 13:27:50.397 GMT [6124][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:50.398 GMT [6124][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:50.399 GMT [6124][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:50.454 GMT [4780][startup] LOG:  database system was shut down at 2024-03-16 13:27:49 GMT
2024-03-16 13:27:50.490 GMT [6124][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:50.589 GMT [6124][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:50.589 GMT [6124][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:50.631 GMT [6124][postmaster] LOG:  background worker "logical replication launcher" (PID 5364) exited with exit code 1
2024-03-16 13:27:50.631 GMT [724][checkpointer] LOG:  shutting down
2024-03-16 13:27:50.631 GMT [724][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:50.635 GMT [724][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/40C5F60, redo lsn=0/40C5F60
2024-03-16 13:27:50.690 GMT [6124][postmaster] LOG:  database system is shut down
2024-03-16 13:27:51.015 GMT [2416][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-16 13:27:51.015 GMT [2416][postmaster] LOG:  database system is shut down
2024-03-16 13:27:51.498 GMT [7316][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:51.500 GMT [7316][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:51.502 GMT [7316][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:51.546 GMT [6188][startup] LOG:  database system was shut down at 2024-03-16 13:27:50 GMT
2024-03-16 13:27:51.584 GMT [7316][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:51.690 GMT [7316][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:51.691 GMT [7316][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:51.723 GMT [7316][postmaster] LOG:  background worker "logical replication launcher" (PID 2212) exited with exit code 1
2024-03-16 13:27:51.724 GMT [2084][checkpointer] LOG:  shutting down
2024-03-16 13:27:51.724 GMT [2084][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:51.728 GMT [2084][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/40C5FD8, redo lsn=0/40C5FD8
2024-03-16 13:27:51.763 GMT [7316][postmaster] LOG:  database system is shut down
2024-03-16 13:27:51.894 GMT [4692][postmaster] FATAL:  could not set SSL protocol version range
2024-03-16 13:27:51.894 GMT [4692][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-16 13:27:51.894 GMT [4692][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:27:52.039](0.400s) 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 4204
[13:27:52.473](0.434s) ok 5 - restart succeeds with correct SSL protocol bounds
[13:27:52.474](0.000s) # running client tests
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 7548
[13:27:52.930](0.456s) ok 6 - server doesn't accept non-SSL connections
[13:27:52.930](0.000s) ok 7 - server doesn't accept non-SSL connections: matches
[13:27:53.025](0.095s) ok 8 - connect without server root cert sslmode=require
[13:27:53.025](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr
[13:27:53.114](0.089s) ok 10 - connect without server root cert sslmode=verify-ca
[13:27:53.115](0.001s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[13:27:53.251](0.136s) ok 12 - connect without server root cert sslmode=verify-full
[13:27:53.251](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches
[13:27:53.364](0.113s) ok 14 - connect with wrong server root cert sslmode=require
[13:27:53.364](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches
[13:27:53.445](0.081s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[13:27:53.446](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[13:27:53.562](0.116s) ok 18 - connect with wrong server root cert sslmode=verify-full
[13:27:53.562](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[13:27:53.701](0.139s) ok 20 - connect with server CA cert, without root CA
[13:27:53.702](0.000s) ok 21 - connect with server CA cert, without root CA: matches
[13:27:53.875](0.174s) ok 22 - connect with correct server CA cert file sslmode=require
[13:27:53.876](0.001s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[13:27:54.056](0.180s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[13:27:54.056](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[13:27:54.792](0.736s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[13:27:54.792](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[13:27:54.899](0.107s) ok 28 - cert root file that contains two certificates, order 1
[13:27:54.900](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[13:27:55.011](0.111s) ok 30 - cert root file that contains two certificates, order 2
[13:27:55.011](0.001s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[13:27:55.248](0.237s) ok 32 - connect with sslcertmode=disable
[13:27:55.248](0.000s) ok 33 - connect with sslcertmode=disable: no stderr
[13:27:55.356](0.107s) ok 34 - connect with sslcertmode=allow
[13:27:55.356](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[13:27:55.464](0.108s) ok 36 - connect with sslcertmode=require fails without a client certificate
[13:27:55.464](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[13:27:55.528](0.064s) ok 38 - sslcrl option with invalid file name
[13:27:55.529](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[13:27:55.635](0.106s) ok 40 - CRL belonging to a different CA
[13:27:55.636](0.001s) ok 41 - CRL belonging to a different CA: matches
[13:27:55.712](0.076s) ok 42 - directory CRL belonging to a different CA
[13:27:55.712](0.001s) ok 43 - directory CRL belonging to a different CA: matches
[13:27:55.777](0.064s) ok 44 - CRL with a non-revoked cert
[13:27:55.777](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[13:27:55.887](0.110s) ok 46 - directory CRL with a non-revoked cert
[13:27:55.887](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr
[13:27:55.949](0.062s) ok 48 - mismatch between host name and server certificate sslmode=require
[13:27:55.950](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[13:27:56.026](0.077s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[13:27:56.027](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[13:27:56.137](0.110s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[13:27:56.137](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 2800
[13:27:56.481](0.344s) ok 54 - IP address in the Common Name
[13:27:56.482](0.001s) ok 55 - IP address in the Common Name: no stderr
[13:27:56.604](0.122s) ok 56 - mismatch between host name and server certificate IP address
[13:27:56.604](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 4776
[13:27:56.948](0.344s) ok 58 - IP address in a dNSName
[13:27:56.948](0.000s) ok 59 - IP address in a dNSName: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 3976
[13:27:57.296](0.348s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[13:27:57.296](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[13:27:57.358](0.062s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[13:27:57.358](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[13:27:57.421](0.062s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[13:27:57.421](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[13:27:57.483](0.062s) ok 66 - host name not matching with X.509 Subject Alternative Names
[13:27:57.483](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[13:27:57.546](0.063s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[13:27:57.547](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 7136
[13:27:57.890](0.343s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[13:27:57.890](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[13:27:57.952](0.062s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[13:27:57.952](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[13:27:58.015](0.062s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[13:27:58.015](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches
[13:27:58.044](0.029s) ok 76 # skip IPv6 addresses in certificates not support on this platform
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 6180
[13:27:58.390](0.345s) ok 77 - certificate with both a CN and SANs 1
[13:27:58.390](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr
[13:27:58.499](0.109s) ok 79 - certificate with both a CN and SANs 2
[13:27:58.499](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr
[13:27:58.561](0.062s) ok 81 - certificate with both a CN and SANs ignores CN
[13:27:58.561](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches
[13:27:58.591](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 6680
[13:27:58.939](0.348s) ok 84 - certificate with both an IP CN and DNS SANs matches CN
[13:27:58.939](0.001s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[13:27:59.017](0.078s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1
[13:27:59.017](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[13:27:59.080](0.062s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2
[13:27:59.080](0.000s) ok 89 - certificate with both an IP CN and DNS SANs matches SAN 2: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 7524
[13:27:59.424](0.344s) ok 90 - server certificate without CN or SANs sslmode=verify-ca
[13:27:59.424](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[13:27:59.486](0.062s) ok 92 - server certificate without CN or SANs sslmode=verify-full
[13:27:59.487](0.000s) ok 93 - server certificate without CN or SANs sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 2532
[13:27:59.784](0.298s) ok 94 - sslrootcert=system does not connect with private CA
[13:27:59.785](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches
[13:27:59.846](0.062s) ok 96 - sslrootcert=system only accepts sslmode=verify-full
[13:27:59.846](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches
[13:27:59.955](0.109s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE
[13:27:59.956](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[13:28:00.018](0.062s) ok 100 - sslrootcert=system defaults to sslmode=verify-full
[13:28:00.018](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 4720
[13:28:00.361](0.343s) ok 102 - connects without client-side CRL
[13:28:00.361](0.000s) ok 103 - connects without client-side CRL: no stderr
[13:28:00.423](0.062s) ok 104 - does not connect with client-side CRL file
[13:28:00.423](0.000s) ok 105 - does not connect with client-side CRL file: matches
[13:28:00.487](0.063s) ok 106 - does not connect with client-side CRL directory
[13:28:00.487](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()
[13:28:00.596](0.109s) ok 108 - pg_stat_ssl view without client certificate: exit code 0
[13:28:00.596](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr
[13:28:00.596](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches
[13:28:00.660](0.064s) ok 111 - connection success with correct range of TLS protocol versions
[13:28:00.660](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr
[13:28:00.722](0.062s) ok 113 - connection failure with incorrect range of TLS protocol versions
[13:28:00.723](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches
[13:28:00.785](0.062s) ok 115 - connection failure with an incorrect SSL protocol minimum bound
[13:28:00.785](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches
[13:28:00.816](0.031s) ok 117 - connection failure with an incorrect SSL protocol maximum bound
[13:28:00.816](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches
[13:28:00.816](0.000s) # running server tests
[13:28:00.879](0.062s) ok 119 - certificate authorization fails without client cert
[13:28:00.879](0.000s) ok 120 - certificate authorization fails without client cert: matches
[13:28:00.988](0.109s) ok 121 - certificate authorization succeeds with correct client cert in PEM format
[13:28:00.988](0.001s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[13:28:01.066](0.078s) ok 123 - certificate authorization succeeds with correct client cert in DER format
[13:28:01.067](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr
[13:28:01.127](0.060s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format
[13:28:01.127](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[13:28:01.236](0.109s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format
[13:28:01.237](0.001s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[13:28:01.315](0.077s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require
[13:28:01.315](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[13:28:01.424](0.109s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[13:28:01.425](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[13:28:01.486](0.062s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable
[13:28:01.487](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[13:28:01.549](0.062s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[13:28:01.549](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[13:28:01.658](0.109s) ok 137 - certificate authorization succeeds with DN mapping
[13:28:01.658](0.000s) ok 138 - certificate authorization succeeds with DN mapping: no stderr
[13:28:01.659](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches
[13:28:01.768](0.109s) ok 140 - certificate authorization succeeds with DN regex mapping
[13:28:01.768](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr
[13:28:01.877](0.109s) ok 142 - certificate authorization succeeds with CN mapping
[13:28:01.877](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr
[13:28:01.878](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches
[13:28:01.878](0.000s) not ok 145 # TODO & SKIP Need Pty support
[13:28:01.878](0.000s) not ok 146 # TODO & SKIP Need Pty support
[13:28:01.879](0.000s) not ok 147 # TODO & SKIP Need Pty support
[13:28:01.879](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_CTtr/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[13:28:01.953](0.075s) ok 149 - pg_stat_ssl with client certificate: exit code 0
[13:28:01.954](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr
[13:28:01.954](0.000s) ok 151 - pg_stat_ssl with client certificate: matches
[13:28:01.954](0.000s) ok 152 # skip Permissions check not enforced on Windows
[13:28:01.954](0.000s) ok 153 # skip Permissions check not enforced on Windows
[13:28:02.018](0.064s) ok 154 - certificate authorization fails with client cert belonging to another user
[13:28:02.018](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches
[13:28:02.081](0.063s) ok 156 - certificate authorization fails with revoked client cert
[13:28:02.082](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches
[13:28:02.082](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match
[13:28:02.190](0.108s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[13:28:02.191](0.001s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[13:28:02.192](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[13:28:02.268](0.076s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[13:28:02.268](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[13:28:02.269](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[13:28:02.331](0.062s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[13:28:02.331](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[13:28:02.332](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 4836
[13:28:02.675](0.343s) ok 168 - intermediate client certificate is provided by client
[13:28:02.675](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr
[13:28:02.737](0.062s) ok 170 - intermediate client certificate is missing
[13:28:02.738](0.000s) ok 171 - intermediate client certificate is missing: matches
[13:28:02.801](0.063s) ok 172 - logged client certificate Subjects are truncated if they're too long
[13:28:02.801](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 7532
[13:28:03.096](0.296s) ok 174 - intermediate client certificate is untrusted
[13:28:03.097](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 7992
[13:28:03.394](0.297s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory
[13:28:03.394](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[13:28:03.456](0.062s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[13:28:03.456](0.000s) ok 179 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 6604
[13:28:03.755](0.299s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1
[13:28:03.756](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923.
[13:28:03.756](0.000s) #          got: '2'
#     expected: '0'
[13:28:03.756](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[13:28:03.756](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923.
[13:28:03.756](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 64238 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: ''
[13:28:03.866](0.110s) ok 182 - connect without requesting ocsp response when sslocspstapling=0
[13:28:03.866](0.000s) ok 183 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 7968
[13:28:04.163](0.297s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1
[13:28:04.226](0.063s) ok 185 - connect without requesting ocsp response when sslocspstapling=0
[13:28:04.226](0.000s) ok 186 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 1168
[13:28:04.524](0.298s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1
[13:28:04.633](0.109s) ok 188 - connect without requesting ocsp response when sslocspstapling=0
[13:28:04.634](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 7416
[13:28:04.930](0.296s) ok 190 - failed with an expired ocsp response when sslocspstapling=1
[13:28:05.040](0.110s) ok 191 - connect without requesting ocsp response when sslocspstapling=0
[13:28:05.040](0.000s) ok 192 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 2272
[13:28:05.383](0.344s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1
[13:28:05.384](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001.
[13:28:05.384](0.000s) #          got: '2'
#     expected: '0'
[13:28:05.384](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[13:28:05.384](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.
[13:28:05.384](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 64238 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: ''
[13:28:05.478](0.093s) ok 195 - connect without requesting ocsp response when sslocspstapling=0
[13:28:05.478](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 7420
[13:28:05.775](0.297s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1
[13:28:05.884](0.109s) ok 198 - connect without requesting ocsp response when sslocspstapling=0
[13:28:05.885](0.001s) 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 6424
[13:28:06.181](0.296s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1
[13:28:06.290](0.110s) ok 201 - connect without requesting ocsp response when sslocspstapling=0
[13:28:06.291](0.001s) ok 202 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 7272
[13:28:06.588](0.297s) ok 203 - failed with an expired ocsp response when sslocspstapling=1
[13:28:06.697](0.109s) ok 204 - connect without requesting ocsp response when sslocspstapling=0
[13:28:06.698](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 6200
[13:28:06.993](0.296s) ok 206 - failed with an expired ocsp response when sslocspstapling=1
[13:28:07.057](0.063s) ok 207 - connect without requesting ocsp response when sslocspstapling=0
[13:28:07.057](0.000s) ok 208 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
# pg_ctl restart failed; logfile:
2024-03-16 13:27:44.299 GMT [3556][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:44.301 GMT [3556][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:44.333 GMT [5848][startup] LOG:  database system was shut down at 2024-03-16 13:18:11 GMT
2024-03-16 13:27:44.399 GMT [3556][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:44.594 GMT [3696][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:44.596 GMT [3696][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:44.596 GMT [3696][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:44.609 GMT [3696][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-16 13:27:44.612 GMT [3696][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:44.786 GMT [1892][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:44.787 GMT [1892][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:44.787 GMT [1892][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:44.790 GMT [1892][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-16 13:27:44.791 GMT [1892][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.098 GMT [1712][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.100 GMT [1712][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.100 GMT [1712][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.102 GMT [1712][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-16 13:27:45.103 GMT [1712][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.242 GMT [6544][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.243 GMT [6544][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.243 GMT [6544][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.245 GMT [6544][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-16 13:27:45.246 GMT [6544][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.395 GMT [5556][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.401 GMT [5556][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.401 GMT [5556][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.423 GMT [5556][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-16 13:27:45.424 GMT [5556][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.046 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:45.573 GMT [2224][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:45.591 GMT [2224][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:45.591 GMT [2224][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:45.600 GMT [2224][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-16 13:27:46.390 GMT [2224][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.827 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:46.895 GMT [4116][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:46.897 GMT [4116][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:46.897 GMT [4116][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:46.899 GMT [4116][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-16 13:27:47.135 GMT [4116][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.242 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:47.387 GMT [664][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:47.389 GMT [664][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:47.389 GMT [664][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:47.391 GMT [664][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-16 13:27:47.590 GMT [664][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.206 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:47.792 GMT [6240][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:47.794 GMT [6240][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:47.794 GMT [6240][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:47.819 GMT [6240][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-16 13:27:48.113 GMT [6240][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.323 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:48.362 GMT [6172][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:48.368 GMT [6172][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:48.368 GMT [6172][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:48.374 GMT [6172][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-16 13:27:48.612 GMT [6172][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.268 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:48.878 GMT [2416][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-16 13:27:48.883 GMT [2416][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="SYSTEM" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:117)
2024-03-16 13:27:48.883 GMT [2416][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-16 13:27:48.888 GMT [2416][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-16 13:27:49.176 GMT [2416][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.302 user=SYSTEM database=postgres host=[local]
2024-03-16 13:27:49.445 GMT [3556][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:49.446 GMT [3556][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:49.492 GMT [3556][postmaster] LOG:  background worker "logical replication launcher" (PID 5936) exited with exit code 1
2024-03-16 13:27:49.529 GMT [7880][checkpointer] LOG:  shutting down
2024-03-16 13:27:49.530 GMT [7880][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:49.860 GMT [7880][checkpointer] LOG:  checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.322 s, sync=0.001 s, total=0.332 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44804 kB, estimate=44804 kB; lsn=0/40C5EE8, redo lsn=0/40C5EE8
2024-03-16 13:27:49.995 GMT [3556][postmaster] LOG:  database system is shut down
2024-03-16 13:27:50.397 GMT [6124][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:50.398 GMT [6124][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:50.399 GMT [6124][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:50.454 GMT [4780][startup] LOG:  database system was shut down at 2024-03-16 13:27:49 GMT
2024-03-16 13:27:50.490 GMT [6124][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:50.589 GMT [6124][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:50.589 GMT [6124][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:50.631 GMT [6124][postmaster] LOG:  background worker "logical replication launcher" (PID 5364) exited with exit code 1
2024-03-16 13:27:50.631 GMT [724][checkpointer] LOG:  shutting down
2024-03-16 13:27:50.631 GMT [724][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:50.635 GMT [724][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/40C5F60, redo lsn=0/40C5F60
2024-03-16 13:27:50.690 GMT [6124][postmaster] LOG:  database system is shut down
2024-03-16 13:27:51.015 GMT [2416][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-16 13:27:51.015 GMT [2416][postmaster] LOG:  database system is shut down
2024-03-16 13:27:51.498 GMT [7316][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:51.500 GMT [7316][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:51.502 GMT [7316][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:51.546 GMT [6188][startup] LOG:  database system was shut down at 2024-03-16 13:27:50 GMT
2024-03-16 13:27:51.584 GMT [7316][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:51.690 GMT [7316][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:51.691 GMT [7316][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:51.723 GMT [7316][postmaster] LOG:  background worker "logical replication launcher" (PID 2212) exited with exit code 1
2024-03-16 13:27:51.724 GMT [2084][checkpointer] LOG:  shutting down
2024-03-16 13:27:51.724 GMT [2084][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:51.728 GMT [2084][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/40C5FD8, redo lsn=0/40C5FD8
2024-03-16 13:27:51.763 GMT [7316][postmaster] LOG:  database system is shut down
2024-03-16 13:27:51.894 GMT [4692][postmaster] FATAL:  could not set SSL protocol version range
2024-03-16 13:27:51.894 GMT [4692][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-16 13:27:51.894 GMT [4692][postmaster] LOG:  database system is shut down
2024-03-16 13:27:52.242 GMT [4204][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:52.243 GMT [4204][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:52.244 GMT [4204][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:52.311 GMT [5192][startup] LOG:  database system was shut down at 2024-03-16 13:27:51 GMT
2024-03-16 13:27:52.348 GMT [4204][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:52.505 GMT [4204][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:52.505 GMT [4204][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:52.533 GMT [4204][postmaster] LOG:  background worker "logical replication launcher" (PID 2824) exited with exit code 1
2024-03-16 13:27:52.533 GMT [1932][checkpointer] LOG:  shutting down
2024-03-16 13:27:52.533 GMT [1932][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:52.536 GMT [1932][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/40C6068, redo lsn=0/40C6068
2024-03-16 13:27:52.557 GMT [4204][postmaster] LOG:  database system is shut down
2024-03-16 13:27:52.747 GMT [7548][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:52.748 GMT [7548][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:52.750 GMT [7548][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:52.781 GMT [5448][startup] LOG:  database system was shut down at 2024-03-16 13:27:52 GMT
2024-03-16 13:27:52.788 GMT [7548][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:52.918 GMT [5668][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50350
2024-03-16 13:27:52.920 GMT [5668][client backend] [[unknown]][0/1:0] FATAL:  no pg_hba.conf entry for host "127.0.0.1", user "ssltestuser", database "trustdb", no encryption
2024-03-16 13:27:52.920 GMT [5668][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "pg-loadbalancetest", forward lookup not checked.
2024-03-16 13:27:52.980 GMT [2608][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50352
2024-03-16 13:27:52.987 GMT [2608][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:52.987 GMT [2608][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:53.001 GMT [2608][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=invalid sslmode=require$$
2024-03-16 13:27:53.004 GMT [2608][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50352
2024-03-16 13:27:53.088 GMT [5020][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50354
2024-03-16 13:27:53.104 GMT [5020][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:27:53.204 GMT [7164][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50356
2024-03-16 13:27:53.217 GMT [7164][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:27:53.331 GMT [5964][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50358
2024-03-16 13:27:53.337 GMT [5964][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:27:53.415 GMT [7060][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50360
2024-03-16 13:27:53.421 GMT [7060][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:27:53.527 GMT [4900][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50362
2024-03-16 13:27:53.533 GMT [4900][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:27:53.641 GMT [3332][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50364
2024-03-16 13:27:53.647 GMT [3332][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:27:53.858 GMT [3808][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50366
2024-03-16 13:27:53.866 GMT [3808][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:53.866 GMT [3808][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:53.869 GMT [3808][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require$$
2024-03-16 13:27:53.873 GMT [3808][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50366
2024-03-16 13:27:53.942 GMT [5576][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50367
2024-03-16 13:27:53.950 GMT [5576][client backend] [[unknown]][3/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:53.950 GMT [5576][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:53.953 GMT [5576][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca$$
2024-03-16 13:27:53.956 GMT [5576][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50367
2024-03-16 13:27:54.452 GMT [480][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50369
2024-03-16 13:27:54.459 GMT [480][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:54.459 GMT [480][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:54.461 GMT [480][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-full$$
2024-03-16 13:27:54.465 GMT [480][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50369
2024-03-16 13:27:54.839 GMT [1304][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50371
2024-03-16 13:27:54.847 GMT [1304][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:54.847 GMT [1304][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:54.850 GMT [1304][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/both-cas-1.crt sslmode=verify-ca$$
2024-03-16 13:27:54.853 GMT [1304][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50371
2024-03-16 13:27:54.948 GMT [8084][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50373
2024-03-16 13:27:54.955 GMT [8084][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:54.955 GMT [8084][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:54.958 GMT [8084][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/both-cas-2.crt sslmode=verify-ca$$
2024-03-16 13:27:54.960 GMT [8084][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50373
2024-03-16 13:27:55.096 GMT [4864][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50375
2024-03-16 13:27:55.104 GMT [4864][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:55.104 GMT [4864][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:55.107 GMT [4864][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require sslcertmode=disable$$
2024-03-16 13:27:55.146 GMT [4864][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.093 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50375
2024-03-16 13:27:55.301 GMT [5224][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50378
2024-03-16 13:27:55.309 GMT [5224][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:55.309 GMT [5224][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:55.312 GMT [5224][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require sslcertmode=allow$$
2024-03-16 13:27:55.314 GMT [5224][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50378
2024-03-16 13:27:55.402 GMT [4876][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50380
2024-03-16 13:27:55.410 GMT [4876][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:55.410 GMT [4876][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:55.423 GMT [4876][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50380
2024-03-16 13:27:55.515 GMT [820][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50382
2024-03-16 13:27:55.522 GMT [820][client backend] [[unknown]][10/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:55.522 GMT [820][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:55.524 GMT [820][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslcrl=invalid$$
2024-03-16 13:27:55.528 GMT [820][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50382
2024-03-16 13:27:55.574 GMT [7920][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50383
2024-03-16 13:27:55.579 GMT [7920][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:27:55.692 GMT [1428][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50384
2024-03-16 13:27:55.698 GMT [1428][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:27:55.760 GMT [5320][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50385
2024-03-16 13:27:55.767 GMT [5320][client backend] [[unknown]][11/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:55.767 GMT [5320][client backend] [[unknown]][11/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:55.770 GMT [5320][client backend] [001_ssltests.pl][11/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslcrl=ssl/root+server.crl$$
2024-03-16 13:27:55.774 GMT [5320][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50385
2024-03-16 13:27:55.826 GMT [2484][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50386
2024-03-16 13:27:55.833 GMT [2484][client backend] [[unknown]][12/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:55.833 GMT [2484][client backend] [[unknown]][12/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:55.836 GMT [2484][client backend] [001_ssltests.pl][12/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslcrldir=ssl/root+server-crldir$$
2024-03-16 13:27:55.840 GMT [2484][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50386
2024-03-16 13:27:55.936 GMT [6560][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50387
2024-03-16 13:27:55.943 GMT [6560][client backend] [[unknown]][13/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:55.943 GMT [6560][client backend] [[unknown]][13/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:55.945 GMT [6560][client backend] [001_ssltests.pl][13/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=require host=wronghost.test$$
2024-03-16 13:27:55.947 GMT [6560][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50387
2024-03-16 13:27:55.998 GMT [2832][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50388
2024-03-16 13:27:56.005 GMT [2832][client backend] [[unknown]][14/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:56.005 GMT [2832][client backend] [[unknown]][14/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:56.008 GMT [2832][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-ca host=wronghost.test$$
2024-03-16 13:27:56.013 GMT [2832][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50388
2024-03-16 13:27:56.071 GMT [7048][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50389
2024-03-16 13:27:56.158 GMT [7548][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:56.158 GMT [7548][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:56.168 GMT [7548][postmaster] LOG:  background worker "logical replication launcher" (PID 5796) exited with exit code 1
2024-03-16 13:27:56.170 GMT [6816][checkpointer] LOG:  shutting down
2024-03-16 13:27:56.170 GMT [6816][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:56.174 GMT [6816][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/40C60E0, redo lsn=0/40C60E0
2024-03-16 13:27:56.180 GMT [7548][postmaster] LOG:  database system is shut down
2024-03-16 13:27:56.315 GMT [2800][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:56.316 GMT [2800][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:56.317 GMT [2800][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:56.340 GMT [2424][startup] LOG:  database system was shut down at 2024-03-16 13:27:56 GMT
2024-03-16 13:27:56.347 GMT [2800][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:56.418 GMT [5664][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50390
2024-03-16 13:27:56.425 GMT [5664][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:56.425 GMT [5664][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:56.438 GMT [5664][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:27:56.443 GMT [5664][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50390
2024-03-16 13:27:56.550 GMT [5160][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50391
2024-03-16 13:27:56.626 GMT [2800][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:56.627 GMT [2800][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:56.634 GMT [2800][postmaster] LOG:  background worker "logical replication launcher" (PID 6768) exited with exit code 1
2024-03-16 13:27:56.634 GMT [6872][checkpointer] LOG:  shutting down
2024-03-16 13:27:56.634 GMT [6872][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:56.637 GMT [6872][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/40C6158, redo lsn=0/40C6158
2024-03-16 13:27:56.642 GMT [2800][postmaster] LOG:  database system is shut down
2024-03-16 13:27:56.785 GMT [4776][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:56.785 GMT [4776][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:56.787 GMT [4776][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:56.809 GMT [5484][startup] LOG:  database system was shut down at 2024-03-16 13:27:56 GMT
2024-03-16 13:27:56.816 GMT [4776][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:56.888 GMT [5880][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50392
2024-03-16 13:27:56.896 GMT [5880][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:56.896 GMT [5880][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:56.909 GMT [5880][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:27:56.912 GMT [5880][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50392
2024-03-16 13:27:56.968 GMT [4776][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:56.968 GMT [4776][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:56.972 GMT [4776][postmaster] LOG:  background worker "logical replication launcher" (PID 6812) exited with exit code 1
2024-03-16 13:27:56.972 GMT [3768][checkpointer] LOG:  shutting down
2024-03-16 13:27:56.972 GMT [3768][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:56.975 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.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/40C61D0, redo lsn=0/40C61D0
2024-03-16 13:27:56.979 GMT [4776][postmaster] LOG:  database system is shut down
2024-03-16 13:27:57.127 GMT [3976][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:57.127 GMT [3976][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:57.128 GMT [3976][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:57.147 GMT [4424][startup] LOG:  database system was shut down at 2024-03-16 13:27:56 GMT
2024-03-16 13:27:57.154 GMT [3976][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:57.228 GMT [1832][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50393
2024-03-16 13:27:57.234 GMT [1832][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:57.234 GMT [1832][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:57.246 GMT [1832][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns1.alt-name.pg-ssltest.test$$
2024-03-16 13:27:57.249 GMT [1832][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50393
2024-03-16 13:27:57.337 GMT [3812][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50394
2024-03-16 13:27:57.344 GMT [3812][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:57.344 GMT [3812][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:57.346 GMT [3812][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns2.alt-name.pg-ssltest.test$$
2024-03-16 13:27:57.349 GMT [3812][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50394
2024-03-16 13:27:57.400 GMT [3972][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50395
2024-03-16 13:27:57.408 GMT [3972][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:57.408 GMT [3972][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:57.411 GMT [3972][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=foo.wildcard.pg-ssltest.test$$
2024-03-16 13:27:57.413 GMT [3972][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50395
2024-03-16 13:27:57.460 GMT [7552][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50396
2024-03-16 13:27:57.524 GMT [2608][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50397
2024-03-16 13:27:57.563 GMT [3976][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:57.563 GMT [3976][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:57.568 GMT [3976][postmaster] LOG:  background worker "logical replication launcher" (PID 2204) exited with exit code 1
2024-03-16 13:27:57.569 GMT [7360][checkpointer] LOG:  shutting down
2024-03-16 13:27:57.569 GMT [7360][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:57.572 GMT [7360][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/40C6248, redo lsn=0/40C6248
2024-03-16 13:27:57.576 GMT [3976][postmaster] LOG:  database system is shut down
2024-03-16 13:27:57.724 GMT [7136][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:57.724 GMT [7136][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:57.725 GMT [7136][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:57.745 GMT [6140][startup] LOG:  database system was shut down at 2024-03-16 13:27:57 GMT
2024-03-16 13:27:57.753 GMT [7136][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:57.849 GMT [564][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50398
2024-03-16 13:27:57.856 GMT [564][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:57.856 GMT [564][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:57.868 GMT [564][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=single.alt-name.pg-ssltest.test$$
2024-03-16 13:27:57.871 GMT [564][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50398
2024-03-16 13:27:57.930 GMT [3612][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50399
2024-03-16 13:27:57.991 GMT [3480][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50400
2024-03-16 13:27:58.060 GMT [7136][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:58.060 GMT [7136][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:58.066 GMT [7136][postmaster] LOG:  background worker "logical replication launcher" (PID 7772) exited with exit code 1
2024-03-16 13:27:58.066 GMT [7412][checkpointer] LOG:  shutting down
2024-03-16 13:27:58.066 GMT [7412][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:58.069 GMT [7412][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/40C62C0, redo lsn=0/40C62C0
2024-03-16 13:27:58.073 GMT [7136][postmaster] LOG:  database system is shut down
2024-03-16 13:27:58.225 GMT [6180][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:58.226 GMT [6180][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:58.227 GMT [6180][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:58.253 GMT [7880][startup] LOG:  database system was shut down at 2024-03-16 13:27:58 GMT
2024-03-16 13:27:58.260 GMT [6180][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:58.323 GMT [7944][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50401
2024-03-16 13:27:58.330 GMT [7944][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:58.330 GMT [7944][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:58.343 GMT [7944][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns1.alt-name.pg-ssltest.test$$
2024-03-16 13:27:58.346 GMT [7944][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50401
2024-03-16 13:27:58.435 GMT [4168][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50402
2024-03-16 13:27:58.443 GMT [4168][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:58.443 GMT [4168][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:58.446 GMT [4168][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns2.alt-name.pg-ssltest.test$$
2024-03-16 13:27:58.448 GMT [4168][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50402
2024-03-16 13:27:58.541 GMT [8028][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50403
2024-03-16 13:27:58.608 GMT [6180][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:58.609 GMT [6180][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:58.614 GMT [6180][postmaster] LOG:  background worker "logical replication launcher" (PID 6380) exited with exit code 1
2024-03-16 13:27:58.614 GMT [5316][checkpointer] LOG:  shutting down
2024-03-16 13:27:58.614 GMT [5316][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:58.617 GMT [5316][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/40C6338, redo lsn=0/40C6338
2024-03-16 13:27:58.622 GMT [6180][postmaster] LOG:  database system is shut down
2024-03-16 13:27:58.769 GMT [6680][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:58.769 GMT [6680][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:58.770 GMT [6680][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:58.790 GMT [2576][startup] LOG:  database system was shut down at 2024-03-16 13:27:58 GMT
2024-03-16 13:27:58.797 GMT [6680][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:58.869 GMT [6268][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50404
2024-03-16 13:27:58.876 GMT [6268][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:58.876 GMT [6268][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:58.888 GMT [6268][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-16 13:27:58.891 GMT [6268][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50404
2024-03-16 13:27:58.982 GMT [4116][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50405
2024-03-16 13:27:58.989 GMT [4116][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:58.989 GMT [4116][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:58.991 GMT [4116][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns1.alt-name.pg-ssltest.test$$
2024-03-16 13:27:58.994 GMT [4116][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50405
2024-03-16 13:27:59.059 GMT [6752][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50406
2024-03-16 13:27:59.066 GMT [6752][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:59.066 GMT [6752][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:59.069 GMT [6752][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=dns2.alt-name.pg-ssltest.test$$
2024-03-16 13:27:59.071 GMT [6752][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50406
2024-03-16 13:27:59.095 GMT [6680][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:59.096 GMT [6680][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:59.100 GMT [6680][postmaster] LOG:  background worker "logical replication launcher" (PID 7800) exited with exit code 1
2024-03-16 13:27:59.101 GMT [7480][checkpointer] LOG:  shutting down
2024-03-16 13:27:59.101 GMT [7480][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:59.104 GMT [7480][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/40C63B0, redo lsn=0/40C63B0
2024-03-16 13:27:59.108 GMT [6680][postmaster] LOG:  database system is shut down
2024-03-16 13:27:59.256 GMT [7524][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:59.256 GMT [7524][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:59.257 GMT [7524][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:59.287 GMT [4468][startup] LOG:  database system was shut down at 2024-03-16 13:27:59 GMT
2024-03-16 13:27:59.295 GMT [7524][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:59.358 GMT [6652][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50407
2024-03-16 13:27:59.365 GMT [6652][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:59.365 GMT [6652][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:59.379 GMT [6652][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-ca host=common-name.pg-ssltest.test$$
2024-03-16 13:27:59.381 GMT [6652][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50407
2024-03-16 13:27:59.464 GMT [5876][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50408
2024-03-16 13:27:59.502 GMT [7524][postmaster] LOG:  received fast shutdown request
2024-03-16 13:27:59.504 GMT [7524][postmaster] LOG:  aborting any active transactions
2024-03-16 13:27:59.506 GMT [7524][postmaster] LOG:  background worker "logical replication launcher" (PID 4704) exited with exit code 1
2024-03-16 13:27:59.507 GMT [6048][checkpointer] LOG:  shutting down
2024-03-16 13:27:59.507 GMT [6048][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:27:59.510 GMT [6048][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/40C6428, redo lsn=0/40C6428
2024-03-16 13:27:59.515 GMT [7524][postmaster] LOG:  database system is shut down
2024-03-16 13:27:59.663 GMT [2532][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:27:59.663 GMT [2532][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:27:59.664 GMT [2532][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:27:59.696 GMT [5836][startup] LOG:  database system was shut down at 2024-03-16 13:27:59 GMT
2024-03-16 13:27:59.704 GMT [2532][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:27:59.763 GMT [4240][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50409
2024-03-16 13:27:59.769 GMT [4240][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-16 13:27:59.889 GMT [6036][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50410
2024-03-16 13:27:59.896 GMT [6036][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:27:59.896 GMT [6036][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:27:59.908 GMT [6036][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=system hostaddr=127.0.0.1 sslmode=verify-full host=common-name.pg-ssltest.test$$
2024-03-16 13:27:59.910 GMT [6036][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50410
2024-03-16 13:27:59.994 GMT [7200][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50411
2024-03-16 13:28:00.036 GMT [2532][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:00.036 GMT [2532][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:00.040 GMT [2532][postmaster] LOG:  background worker "logical replication launcher" (PID 1604) exited with exit code 1
2024-03-16 13:28:00.040 GMT [7072][checkpointer] LOG:  shutting down
2024-03-16 13:28:00.040 GMT [7072][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:00.043 GMT [7072][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/40C64A0, redo lsn=0/40C64A0
2024-03-16 13:28:00.048 GMT [2532][postmaster] LOG:  database system is shut down
2024-03-16 13:28:00.198 GMT [4720][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:00.199 GMT [4720][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:00.200 GMT [4720][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:00.220 GMT [620][startup] LOG:  database system was shut down at 2024-03-16 13:28:00 GMT
2024-03-16 13:28:00.230 GMT [4720][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:00.297 GMT [5276][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50412
2024-03-16 13:28:00.304 GMT [5276][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:00.304 GMT [5276][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:00.317 GMT [5276][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca$$
2024-03-16 13:28:00.320 GMT [5276][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50412
2024-03-16 13:28:00.404 GMT [3740][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50413
2024-03-16 13:28:00.410 GMT [3740][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-16 13:28:00.465 GMT [8044][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50414
2024-03-16 13:28:00.472 GMT [8044][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-16 13:28:00.531 GMT [7120][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50415
2024-03-16 13:28:00.548 GMT [7120][client backend] [[unknown]][1/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:00.548 GMT [7120][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:00.551 GMT [7120][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-16 13:28:00.556 GMT [7120][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50415
2024-03-16 13:28:00.638 GMT [7180][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50416
2024-03-16 13:28:00.645 GMT [7180][client backend] [[unknown]][2/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:00.645 GMT [7180][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256)
2024-03-16 13:28:00.647 GMT [7180][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=require ssl_min_protocol_version=TLSv1.2 ssl_max_protocol_version=TLSv1.2$$
2024-03-16 13:28:00.650 GMT [7180][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50416
2024-03-16 13:28:00.855 GMT [4760][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50417
2024-03-16 13:28:00.862 GMT [4760][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-03-16 13:28:00.919 GMT [5444][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50418
2024-03-16 13:28:00.929 GMT [5444][client backend] [[unknown]][4/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:00.929 GMT [5444][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:00.942 GMT [5444][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_CTtr/client.key$$
2024-03-16 13:28:00.945 GMT [5444][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=certdb host=pg-loadbalancetest port=50418
2024-03-16 13:28:01.032 GMT [5096][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50419
2024-03-16 13:28:01.041 GMT [5096][client backend] [[unknown]][5/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:01.041 GMT [5096][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.044 GMT [5096][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_CTtr/client-der.key$$
2024-03-16 13:28:01.046 GMT [5096][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50419
2024-03-16 13:28:01.108 GMT [1784][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50420
2024-03-16 13:28:01.118 GMT [1784][client backend] [[unknown]][6/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:01.118 GMT [1784][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.121 GMT [1784][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_CTtr/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-03-16 13:28:01.123 GMT [1784][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50420
2024-03-16 13:28:01.173 GMT [6964][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50421
2024-03-16 13:28:01.182 GMT [6964][client backend] [[unknown]][7/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:01.183 GMT [6964][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.186 GMT [6964][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_CTtr/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-03-16 13:28:01.188 GMT [6964][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50421
2024-03-16 13:28:01.284 GMT [7764][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50422
2024-03-16 13:28:01.294 GMT [7764][client backend] [[unknown]][8/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:01.294 GMT [7764][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.297 GMT [7764][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb hostaddr=127.0.0.1 host=localhost user=ssltestuser sslcertmode=require sslcert=ssl/client.crt  sslkey=C:/cirrus/build/testrun/ssl/001_ssltests/data/tmp_test_CTtr/client.key$$
2024-03-16 13:28:01.299 GMT [7764][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50422
2024-03-16 13:28:01.360 GMT [1988][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50423
2024-03-16 13:28:01.370 GMT [1988][client backend] [[unknown]][9/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:01.370 GMT [1988][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.373 GMT [1988][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_CTtr/client.key$$
2024-03-16 13:28:01.375 GMT [1988][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50423
2024-03-16 13:28:01.466 GMT [7460][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50424
2024-03-16 13:28:01.474 GMT [7460][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-03-16 13:28:01.531 GMT [1940][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50425
2024-03-16 13:28:01.543 GMT [1940][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-16 13:28:01.593 GMT [6672][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50426
2024-03-16 13:28:01.603 GMT [6672][client backend] [[unknown]][11/1:0] LOG:  connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:8)
2024-03-16 13:28:01.603 GMT [6672][client backend] [[unknown]][11/1:0] LOG:  connection authorized: user=ssltestuser database=certdb_dn application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.616 GMT [6672][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_CTtr/client-dn.key$$
2024-03-16 13:28:01.619 GMT [6672][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50426
2024-03-16 13:28:01.701 GMT [1764][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50427
2024-03-16 13:28:01.710 GMT [1764][client backend] [[unknown]][12/1:0] LOG:  connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:9)
2024-03-16 13:28:01.710 GMT [1764][client backend] [[unknown]][12/1:0] LOG:  connection authorized: user=ssltestuser database=certdb_dn_re application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.722 GMT [1764][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_CTtr/client-dn.key$$
2024-03-16 13:28:01.724 GMT [1764][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50427
2024-03-16 13:28:01.811 GMT [5892][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50428
2024-03-16 13:28:01.820 GMT [5892][client backend] [[unknown]][13/1:0] LOG:  connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:10)
2024-03-16 13:28:01.820 GMT [5892][client backend] [[unknown]][13/1:0] LOG:  connection authorized: user=ssltestuser database=certdb_cn application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.832 GMT [5892][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_CTtr/client-dn.key$$
2024-03-16 13:28:01.834 GMT [5892][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50428
2024-03-16 13:28:01.930 GMT [4256][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50429
2024-03-16 13:28:01.939 GMT [4256][client backend] [[unknown]][14/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:01.939 GMT [4256][client backend] [[unknown]][14/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:01.942 GMT [4256][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-16 13:28:01.947 GMT [4256][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=certdb host=pg-loadbalancetest port=50429
2024-03-16 13:28:01.995 GMT [3516][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50430
2024-03-16 13:28:02.003 GMT [3516][client backend] [[unknown]][15/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:02.004 GMT [3516][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-16 13:28:02.004 GMT [3516][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-03-16 13:28:02.004 GMT [3516][client backend] [[unknown]][15/1:0] DETAIL:  Connection matched file "C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf" line 7: "hostssl certdb          all             127.0.0.1/32            cert"
2024-03-16 13:28:02.059 GMT [6588][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50431
2024-03-16 13:28:02.066 GMT [6588][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:28:02.066 GMT [6588][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: certificate revoked.
	Failed certificate data (unverified): subject "/CN=ssltestuser", serial number 2315702411956921346, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:28:02.124 GMT [5128][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50432
2024-03-16 13:28:02.132 GMT [5128][client backend] [[unknown]][16/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:4)
2024-03-16 13:28:02.132 GMT [5128][client backend] [[unknown]][16/1:0] LOG:  connection authorized: user=ssltestuser database=verifydb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:02.144 GMT [5128][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_CTtr/client.key$$
2024-03-16 13:28:02.146 GMT [5128][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50432
2024-03-16 13:28:02.237 GMT [6328][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50433
2024-03-16 13:28:02.246 GMT [6328][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-16 13:28:02.247 GMT [6328][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-03-16 13:28:02.247 GMT [6328][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-03-16 13:28:02.247 GMT [6328][client backend] [[unknown]][17/1:0] DETAIL:  Connection matched file "C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf" line 5: "hostssl verifydb        anotheruser     127.0.0.1/32            trust        clientcert=verify-full"
2024-03-16 13:28:02.309 GMT [3680][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50434
2024-03-16 13:28:02.318 GMT [3680][client backend] [[unknown]][18/1:0] LOG:  connection authenticated: user="yetanotheruser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:6)
2024-03-16 13:28:02.318 GMT [3680][client backend] [[unknown]][18/1:0] LOG:  connection authorized: user=yetanotheruser database=verifydb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:02.321 GMT [3680][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_CTtr/client.key$$
2024-03-16 13:28:02.323 GMT [3680][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50434
2024-03-16 13:28:02.348 GMT [4720][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:02.348 GMT [4720][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:02.351 GMT [4720][postmaster] LOG:  background worker "logical replication launcher" (PID 1068) exited with exit code 1
2024-03-16 13:28:02.352 GMT [5680][checkpointer] LOG:  shutting down
2024-03-16 13:28:02.352 GMT [5680][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:02.355 GMT [5680][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/40C6518, redo lsn=0/40C6518
2024-03-16 13:28:02.359 GMT [4720][postmaster] LOG:  database system is shut down
2024-03-16 13:28:02.507 GMT [4836][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:02.507 GMT [4836][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:02.509 GMT [4836][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:02.529 GMT [6040][startup] LOG:  database system was shut down at 2024-03-16 13:28:02 GMT
2024-03-16 13:28:02.537 GMT [4836][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:02.605 GMT [5620][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50435
2024-03-16 13:28:02.614 GMT [5620][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: identity="CN=ssltestuser" method=cert (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:7)
2024-03-16 13:28:02.614 GMT [5620][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=certdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:02.626 GMT [5620][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_CTtr/client.key sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 host=localhost sslmode=require sslcert=ssl/client+client_ca.crt$$
2024-03-16 13:28:02.628 GMT [5620][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb host=pg-loadbalancetest port=50435
2024-03-16 13:28:02.714 GMT [3960][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50436
2024-03-16 13:28:02.721 GMT [3960][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:28:02.721 GMT [3960][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: unable to get local issuer certificate.
	Failed certificate data (unverified): subject "/CN=ssltestuser", serial number 2315702411956921344, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:28:02.775 GMT [2936][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50437
2024-03-16 13:28:02.782 GMT [2936][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:28:02.782 GMT [2936][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: unable to get local issuer certificate.
	Failed certificate data (unverified): subject ".../CN=ssl-123456789012345678901234567890123456789012345678901234567890", serial number 2315702411956921348, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:28:02.817 GMT [4836][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:02.817 GMT [4836][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:02.821 GMT [4836][postmaster] LOG:  background worker "logical replication launcher" (PID 7456) exited with exit code 1
2024-03-16 13:28:02.821 GMT [4648][checkpointer] LOG:  shutting down
2024-03-16 13:28:02.821 GMT [4648][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:02.824 GMT [4648][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/40C6590, redo lsn=0/40C6590
2024-03-16 13:28:02.829 GMT [4836][postmaster] LOG:  database system is shut down
2024-03-16 13:28:02.976 GMT [7532][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:02.977 GMT [7532][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:02.978 GMT [7532][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:02.998 GMT [6344][startup] LOG:  database system was shut down at 2024-03-16 13:28:02 GMT
2024-03-16 13:28:03.006 GMT [7532][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:03.072 GMT [6080][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50438
2024-03-16 13:28:03.080 GMT [6080][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:28:03.080 GMT [6080][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 1: unable to get local issuer certificate.
	Failed certificate data (unverified): subject "/CN=Test CA for PostgreSQL SSL regression test client certs", serial number 2315702411956921089, issuer "/CN=Test root CA for PostgreSQL SSL regression test suite".
2024-03-16 13:28:03.112 GMT [7532][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:03.112 GMT [7532][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:03.115 GMT [7532][postmaster] LOG:  background worker "logical replication launcher" (PID 5848) exited with exit code 1
2024-03-16 13:28:03.116 GMT [4300][checkpointer] LOG:  shutting down
2024-03-16 13:28:03.116 GMT [4300][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:03.119 GMT [4300][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/40C6608, redo lsn=0/40C6608
2024-03-16 13:28:03.123 GMT [7532][postmaster] LOG:  database system is shut down
2024-03-16 13:28:03.273 GMT [7992][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:03.273 GMT [7992][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:03.275 GMT [7992][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:03.295 GMT [4556][startup] LOG:  database system was shut down at 2024-03-16 13:28:03 GMT
2024-03-16 13:28:03.302 GMT [7992][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:03.370 GMT [4680][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50439
2024-03-16 13:28:03.378 GMT [4680][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:28:03.378 GMT [4680][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: certificate revoked.
	Failed certificate data (unverified): subject "/CN=ssltestuser", serial number 2315702411956921346, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:28:03.433 GMT [460][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50440
2024-03-16 13:28:03.441 GMT [460][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-16 13:28:03.441 GMT [460][not initialized] [[unknown]][:0] DETAIL:  Client certificate verification failed at depth 0: certificate revoked.
	Failed certificate data (unverified): subject "/CN=\xce\x9f\xce\xb4\xcf\x85\xcf\x83\xcf\x83\xce\xad\xce\xb1\xcf\x82", serial number 2315702411956921349, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs".
2024-03-16 13:28:03.471 GMT [7992][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:03.471 GMT [7992][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:03.474 GMT [7992][postmaster] LOG:  background worker "logical replication launcher" (PID 5036) exited with exit code 1
2024-03-16 13:28:03.475 GMT [7464][checkpointer] LOG:  shutting down
2024-03-16 13:28:03.475 GMT [7464][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:03.478 GMT [7464][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/40C6680, redo lsn=0/40C6680
2024-03-16 13:28:03.482 GMT [7992][postmaster] LOG:  database system is shut down
2024-03-16 13:28:03.631 GMT [6604][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:03.631 GMT [6604][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:03.632 GMT [6604][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:03.654 GMT [7116][startup] LOG:  database system was shut down at 2024-03-16 13:28:03 GMT
2024-03-16 13:28:03.661 GMT [6604][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:03.732 GMT [772][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50441
2024-03-16 13:28:03.736 GMT [772][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:03.736 GMT [772][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:03.794 GMT [1448][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50442
2024-03-16 13:28:03.801 GMT [1448][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:03.801 GMT [1448][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:03.813 GMT [1448][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:03.817 GMT [1448][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50442
2024-03-16 13:28:03.882 GMT [6604][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:03.882 GMT [6604][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:03.886 GMT [6604][postmaster] LOG:  background worker "logical replication launcher" (PID 2204) exited with exit code 1
2024-03-16 13:28:03.886 GMT [6396][checkpointer] LOG:  shutting down
2024-03-16 13:28:03.886 GMT [6396][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:03.889 GMT [6396][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/40C66F8, redo lsn=0/40C66F8
2024-03-16 13:28:03.893 GMT [6604][postmaster] LOG:  database system is shut down
2024-03-16 13:28:04.041 GMT [7968][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:04.041 GMT [7968][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:04.042 GMT [7968][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:04.070 GMT [6556][startup] LOG:  database system was shut down at 2024-03-16 13:28:03 GMT
2024-03-16 13:28:04.077 GMT [7968][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:04.141 GMT [7664][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50443
2024-03-16 13:28:04.144 GMT [7664][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:04.144 GMT [7664][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:04.200 GMT [3676][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50444
2024-03-16 13:28:04.207 GMT [3676][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:04.207 GMT [3676][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:04.219 GMT [3676][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:04.222 GMT [3676][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50444
2024-03-16 13:28:04.242 GMT [7968][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:04.242 GMT [7968][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:04.246 GMT [7968][postmaster] LOG:  background worker "logical replication launcher" (PID 5408) exited with exit code 1
2024-03-16 13:28:04.246 GMT [7368][checkpointer] LOG:  shutting down
2024-03-16 13:28:04.246 GMT [7368][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:04.249 GMT [7368][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/40C6770, redo lsn=0/40C6770
2024-03-16 13:28:04.253 GMT [7968][postmaster] LOG:  database system is shut down
2024-03-16 13:28:04.402 GMT [1168][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:04.403 GMT [1168][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:04.404 GMT [1168][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:04.425 GMT [6848][startup] LOG:  database system was shut down at 2024-03-16 13:28:04 GMT
2024-03-16 13:28:04.432 GMT [1168][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:04.501 GMT [2284][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50445
2024-03-16 13:28:04.504 GMT [2284][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:04.504 GMT [2284][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:04.563 GMT [5888][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50446
2024-03-16 13:28:04.570 GMT [5888][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:04.570 GMT [5888][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:04.583 GMT [5888][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:04.586 GMT [5888][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50446
2024-03-16 13:28:04.651 GMT [1168][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:04.651 GMT [1168][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:04.659 GMT [1168][postmaster] LOG:  background worker "logical replication launcher" (PID 2104) exited with exit code 1
2024-03-16 13:28:04.659 GMT [7720][checkpointer] LOG:  shutting down
2024-03-16 13:28:04.659 GMT [7720][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:04.662 GMT [7720][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/40C67E8, redo lsn=0/40C67E8
2024-03-16 13:28:04.667 GMT [1168][postmaster] LOG:  database system is shut down
2024-03-16 13:28:04.812 GMT [7416][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:04.813 GMT [7416][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:04.814 GMT [7416][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:04.835 GMT [7836][startup] LOG:  database system was shut down at 2024-03-16 13:28:04 GMT
2024-03-16 13:28:04.843 GMT [7416][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:04.908 GMT [6944][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50447
2024-03-16 13:28:04.911 GMT [6944][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:04.912 GMT [6944][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:04.971 GMT [6752][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50448
2024-03-16 13:28:04.979 GMT [6752][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:04.979 GMT [6752][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:04.991 GMT [6752][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:04.994 GMT [6752][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50448
2024-03-16 13:28:05.057 GMT [7416][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:05.058 GMT [7416][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:05.065 GMT [7416][postmaster] LOG:  background worker "logical replication launcher" (PID 4032) exited with exit code 1
2024-03-16 13:28:05.065 GMT [1492][checkpointer] LOG:  shutting down
2024-03-16 13:28:05.065 GMT [1492][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:05.068 GMT [1492][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/40C6860, redo lsn=0/40C6860
2024-03-16 13:28:05.073 GMT [7416][postmaster] LOG:  database system is shut down
2024-03-16 13:28:05.217 GMT [2272][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:05.217 GMT [2272][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:05.218 GMT [2272][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:05.237 GMT [1328][startup] LOG:  database system was shut down at 2024-03-16 13:28:05 GMT
2024-03-16 13:28:05.245 GMT [2272][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:05.320 GMT [5856][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50449
2024-03-16 13:28:05.324 GMT [5856][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:05.324 GMT [5856][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:05.429 GMT [4632][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50450
2024-03-16 13:28:05.436 GMT [4632][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:05.436 GMT [4632][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:05.449 GMT [4632][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:05.452 GMT [4632][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50450
2024-03-16 13:28:05.494 GMT [2272][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:05.494 GMT [2272][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:05.498 GMT [2272][postmaster] LOG:  background worker "logical replication launcher" (PID 7792) exited with exit code 1
2024-03-16 13:28:05.499 GMT [4976][checkpointer] LOG:  shutting down
2024-03-16 13:28:05.499 GMT [4976][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:05.501 GMT [4976][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/40C68D8, redo lsn=0/40C68D8
2024-03-16 13:28:05.506 GMT [2272][postmaster] LOG:  database system is shut down
2024-03-16 13:28:05.655 GMT [7420][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:05.655 GMT [7420][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:05.656 GMT [7420][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:05.676 GMT [768][startup] LOG:  database system was shut down at 2024-03-16 13:28:05 GMT
2024-03-16 13:28:05.685 GMT [7420][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:05.753 GMT [5040][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50451
2024-03-16 13:28:05.757 GMT [5040][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:05.757 GMT [5040][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:05.815 GMT [3884][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50452
2024-03-16 13:28:05.822 GMT [3884][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:05.822 GMT [3884][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:05.835 GMT [3884][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:05.838 GMT [3884][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50452
2024-03-16 13:28:05.902 GMT [7420][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:05.902 GMT [7420][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:05.910 GMT [7420][postmaster] LOG:  background worker "logical replication launcher" (PID 5836) exited with exit code 1
2024-03-16 13:28:05.910 GMT [3424][checkpointer] LOG:  shutting down
2024-03-16 13:28:05.910 GMT [3424][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:05.913 GMT [3424][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/40C6950, redo lsn=0/40C6950
2024-03-16 13:28:05.917 GMT [7420][postmaster] LOG:  database system is shut down
2024-03-16 13:28:06.059 GMT [6424][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:06.060 GMT [6424][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:06.061 GMT [6424][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:06.090 GMT [7728][startup] LOG:  database system was shut down at 2024-03-16 13:28:05 GMT
2024-03-16 13:28:06.098 GMT [6424][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:06.158 GMT [6592][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50453
2024-03-16 13:28:06.161 GMT [6592][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:06.162 GMT [6592][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:06.220 GMT [6384][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50454
2024-03-16 13:28:06.227 GMT [6384][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:06.227 GMT [6384][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:06.240 GMT [6384][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:06.243 GMT [6384][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50454
2024-03-16 13:28:06.307 GMT [6424][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:06.308 GMT [6424][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:06.315 GMT [6424][postmaster] LOG:  background worker "logical replication launcher" (PID 1460) exited with exit code 1
2024-03-16 13:28:06.316 GMT [4476][checkpointer] LOG:  shutting down
2024-03-16 13:28:06.316 GMT [4476][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:06.318 GMT [4476][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/40C69C8, redo lsn=0/40C69C8
2024-03-16 13:28:06.322 GMT [6424][postmaster] LOG:  database system is shut down
2024-03-16 13:28:06.468 GMT [7272][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:06.469 GMT [7272][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:06.470 GMT [7272][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:06.491 GMT [1628][startup] LOG:  database system was shut down at 2024-03-16 13:28:06 GMT
2024-03-16 13:28:06.498 GMT [7272][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:06.568 GMT [3496][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50455
2024-03-16 13:28:06.572 GMT [3496][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:06.572 GMT [3496][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:06.632 GMT [5424][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50456
2024-03-16 13:28:06.640 GMT [5424][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:06.640 GMT [5424][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:06.652 GMT [5424][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:06.655 GMT [5424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50456
2024-03-16 13:28:06.715 GMT [7272][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:06.716 GMT [7272][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:06.721 GMT [7272][postmaster] LOG:  background worker "logical replication launcher" (PID 1536) exited with exit code 1
2024-03-16 13:28:06.721 GMT [8044][checkpointer] LOG:  shutting down
2024-03-16 13:28:06.721 GMT [8044][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:06.724 GMT [8044][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/40C6A40, redo lsn=0/40C6A40
2024-03-16 13:28:06.729 GMT [7272][postmaster] LOG:  database system is shut down
2024-03-16 13:28:06.874 GMT [6200][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-16 13:28:06.875 GMT [6200][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 64238
2024-03-16 13:28:06.876 GMT [6200][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/0FugazuNjO/.s.PGSQL.64238"
2024-03-16 13:28:06.906 GMT [3868][startup] LOG:  database system was shut down at 2024-03-16 13:28:06 GMT
2024-03-16 13:28:06.914 GMT [6200][postmaster] LOG:  database system is ready to accept connections
2024-03-16 13:28:06.970 GMT [6324][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50457
2024-03-16 13:28:06.973 GMT [6324][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-16 13:28:06.973 GMT [6324][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-16 13:28:07.033 GMT [7204][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50458
2024-03-16 13:28:07.040 GMT [7204][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-16 13:28:07.040 GMT [7204][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-16 13:28:07.052 GMT [7204][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=ocsp-good.pg-ssltest.test sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslocspstapling=0$$
2024-03-16 13:28:07.054 GMT [7204][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50458
2024-03-16 13:28:07.073 GMT [6200][postmaster] LOG:  received fast shutdown request
2024-03-16 13:28:07.073 GMT [6200][postmaster] LOG:  aborting any active transactions
2024-03-16 13:28:07.077 GMT [6200][postmaster] LOG:  background worker "logical replication launcher" (PID 5220) exited with exit code 1
2024-03-16 13:28:07.077 GMT [5444][checkpointer] LOG:  shutting down
2024-03-16 13:28:07.077 GMT [5444][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-16 13:28:07.080 GMT [5444][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/40C6AB8, redo lsn=0/40C6AB8
2024-03-16 13:28:07.085 GMT [6200][postmaster] LOG:  database system is shut down
2024-03-16 13:28:07.223 GMT [6408][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-03-16 13:28:07.223 GMT [6408][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:28:07.291](0.234s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"