[14:19:46.896](0.218s) # setting up data directory
# Checking port 53152
# Found port 53152
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=53152 host=C:/Windows/TEMP/xPPUNt3cft
Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log
[14:19:47.034](0.138s) # 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 5268
[14:19:49.294](2.260s) 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 5292
[14:19:53.316](4.022s) # 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-18 14:19:48.993 GMT [5268][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:48.994 GMT [5268][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:49.025 GMT [7528][startup] LOG:  database system was shut down at 2024-03-18 14:10:12 GMT
2024-03-18 14:19:49.074 GMT [5268][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:49.234 GMT [8112][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.236 GMT [8112][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-18 14:19:49.236 GMT [8112][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.259 GMT [8112][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-18 14:19:49.262 GMT [8112][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.396 GMT [3976][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.397 GMT [3976][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-18 14:19:49.397 GMT [3976][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.400 GMT [3976][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-18 14:19:49.401 GMT [3976][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.534 GMT [7856][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.535 GMT [7856][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-18 14:19:49.535 GMT [7856][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.537 GMT [7856][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-18 14:19:49.538 GMT [7856][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.620 GMT [6132][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.621 GMT [6132][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-18 14:19:49.621 GMT [6132][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.623 GMT [6132][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-18 14:19:49.624 GMT [6132][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.715 GMT [5092][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.716 GMT [5092][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-18 14:19:49.716 GMT [5092][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.718 GMT [5092][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-18 14:19:49.720 GMT [5092][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.775 GMT [1948][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.776 GMT [1948][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-18 14:19:49.776 GMT [1948][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.778 GMT [1948][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-18 14:19:49.959 GMT [1948][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.187 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:50.159 GMT [3032][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:50.185 GMT [3032][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-18 14:19:50.185 GMT [3032][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:50.199 GMT [3032][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-18 14:19:50.524 GMT [3032][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.380 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:50.712 GMT [3376][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:50.713 GMT [3376][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-18 14:19:50.713 GMT [3376][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:50.716 GMT [3376][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-18 14:19:50.980 GMT [3376][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.271 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:51.075 GMT [6976][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:51.076 GMT [6976][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-18 14:19:51.076 GMT [6976][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:51.079 GMT [6976][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-18 14:19:51.409 GMT [6976][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.337 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:51.608 GMT [5688][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:51.609 GMT [5688][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-18 14:19:51.609 GMT [5688][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:51.612 GMT [5688][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-18 14:19:51.878 GMT [5688][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.274 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:52.135 GMT [5904][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:52.136 GMT [5904][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-18 14:19:52.136 GMT [5904][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:52.138 GMT [5904][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-18 14:19:52.361 GMT [5904][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.230 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:52.517 GMT [5268][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:52.517 GMT [5268][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:52.609 GMT [5268][postmaster] LOG:  background worker "logical replication launcher" (PID 1188) exited with exit code 1
2024-03-18 14:19:52.609 GMT [4960][checkpointer] LOG:  shutting down
2024-03-18 14:19:52.609 GMT [4960][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:52.874 GMT [4960][checkpointer] LOG:  checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.255 s, sync=0.001 s, total=0.265 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-18 14:19:52.950 GMT [5268][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.201 GMT [5292][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:53.202 GMT [5292][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:53.204 GMT [5292][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:53.227 GMT [3376][startup] LOG:  database system was shut down at 2024-03-18 14:19:52 GMT
2024-03-18 14:19:53.247 GMT [5292][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:53.336 GMT [5292][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:53.336 GMT [5292][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:53.344 GMT [5292][postmaster] LOG:  background worker "logical replication launcher" (PID 1548) exited with exit code 1
2024-03-18 14:19:53.345 GMT [1280][checkpointer] LOG:  shutting down
2024-03-18 14:19:53.345 GMT [1280][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:53.348 GMT [1280][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.003 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-18 14:19:53.360 GMT [5292][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.602 GMT [7468][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-18 14:19:53.602 GMT [7468][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[14:19:53.671](0.355s) 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 5332
[14:19:54.052](0.381s) 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-18 14:19:48.993 GMT [5268][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:48.994 GMT [5268][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:49.025 GMT [7528][startup] LOG:  database system was shut down at 2024-03-18 14:10:12 GMT
2024-03-18 14:19:49.074 GMT [5268][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:49.234 GMT [8112][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.236 GMT [8112][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-18 14:19:49.236 GMT [8112][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.259 GMT [8112][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-18 14:19:49.262 GMT [8112][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.396 GMT [3976][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.397 GMT [3976][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-18 14:19:49.397 GMT [3976][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.400 GMT [3976][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-18 14:19:49.401 GMT [3976][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.534 GMT [7856][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.535 GMT [7856][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-18 14:19:49.535 GMT [7856][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.537 GMT [7856][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-18 14:19:49.538 GMT [7856][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.620 GMT [6132][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.621 GMT [6132][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-18 14:19:49.621 GMT [6132][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.623 GMT [6132][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-18 14:19:49.624 GMT [6132][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.715 GMT [5092][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.716 GMT [5092][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-18 14:19:49.716 GMT [5092][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.718 GMT [5092][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-18 14:19:49.720 GMT [5092][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.775 GMT [1948][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.776 GMT [1948][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-18 14:19:49.776 GMT [1948][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.778 GMT [1948][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-18 14:19:49.959 GMT [1948][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.187 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:50.159 GMT [3032][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:50.185 GMT [3032][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-18 14:19:50.185 GMT [3032][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:50.199 GMT [3032][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-18 14:19:50.524 GMT [3032][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.380 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:50.712 GMT [3376][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:50.713 GMT [3376][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-18 14:19:50.713 GMT [3376][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:50.716 GMT [3376][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-18 14:19:50.980 GMT [3376][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.271 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:51.075 GMT [6976][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:51.076 GMT [6976][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-18 14:19:51.076 GMT [6976][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:51.079 GMT [6976][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-18 14:19:51.409 GMT [6976][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.337 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:51.608 GMT [5688][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:51.609 GMT [5688][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-18 14:19:51.609 GMT [5688][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:51.612 GMT [5688][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-18 14:19:51.878 GMT [5688][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.274 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:52.135 GMT [5904][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:52.136 GMT [5904][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-18 14:19:52.136 GMT [5904][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:52.138 GMT [5904][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-18 14:19:52.361 GMT [5904][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.230 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:52.517 GMT [5268][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:52.517 GMT [5268][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:52.609 GMT [5268][postmaster] LOG:  background worker "logical replication launcher" (PID 1188) exited with exit code 1
2024-03-18 14:19:52.609 GMT [4960][checkpointer] LOG:  shutting down
2024-03-18 14:19:52.609 GMT [4960][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:52.874 GMT [4960][checkpointer] LOG:  checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.255 s, sync=0.001 s, total=0.265 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-18 14:19:52.950 GMT [5268][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.201 GMT [5292][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:53.202 GMT [5292][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:53.204 GMT [5292][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:53.227 GMT [3376][startup] LOG:  database system was shut down at 2024-03-18 14:19:52 GMT
2024-03-18 14:19:53.247 GMT [5292][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:53.336 GMT [5292][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:53.336 GMT [5292][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:53.344 GMT [5292][postmaster] LOG:  background worker "logical replication launcher" (PID 1548) exited with exit code 1
2024-03-18 14:19:53.345 GMT [1280][checkpointer] LOG:  shutting down
2024-03-18 14:19:53.345 GMT [1280][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:53.348 GMT [1280][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.003 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-18 14:19:53.360 GMT [5292][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.602 GMT [7468][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-18 14:19:53.602 GMT [7468][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.921 GMT [5332][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:53.922 GMT [5332][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:53.923 GMT [5332][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:53.953 GMT [4032][startup] LOG:  database system was shut down at 2024-03-18 14:19:53 GMT
2024-03-18 14:19:53.980 GMT [5332][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:54.076 GMT [5332][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:54.076 GMT [5332][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:54.089 GMT [5332][postmaster] LOG:  background worker "logical replication launcher" (PID 6020) exited with exit code 1
2024-03-18 14:19:54.094 GMT [7420][checkpointer] LOG:  shutting down
2024-03-18 14:19:54.495 GMT [7420][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:54.500 GMT [7420][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.406 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-18 14:19:54.537 GMT [5332][postmaster] LOG:  database system is shut down
2024-03-18 14:19:54.720 GMT [4964][postmaster] FATAL:  could not set SSL protocol version range
2024-03-18 14:19:54.720 GMT [4964][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-18 14:19:54.720 GMT [4964][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[14:19:54.833](0.781s) 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 900
[14:19:55.073](0.240s) ok 5 - restart succeeds with correct SSL protocol bounds
[14:19:55.073](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 3812
[14:19:55.523](0.449s) ok 6 - server doesn't accept non-SSL connections
[14:19:55.523](0.000s) ok 7 - server doesn't accept non-SSL connections: matches
[14:19:55.601](0.078s) ok 8 - connect without server root cert sslmode=require
[14:19:55.602](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr
[14:19:55.665](0.063s) ok 10 - connect without server root cert sslmode=verify-ca
[14:19:55.665](0.000s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[14:19:55.872](0.207s) ok 12 - connect without server root cert sslmode=verify-full
[14:19:55.872](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches
[14:19:55.981](0.109s) ok 14 - connect with wrong server root cert sslmode=require
[14:19:55.981](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches
[14:19:56.054](0.073s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[14:19:56.054](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[14:19:56.134](0.080s) ok 18 - connect with wrong server root cert sslmode=verify-full
[14:19:56.135](0.001s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[14:19:56.238](0.103s) ok 20 - connect with server CA cert, without root CA
[14:19:56.239](0.000s) ok 21 - connect with server CA cert, without root CA: matches
[14:19:56.321](0.082s) ok 22 - connect with correct server CA cert file sslmode=require
[14:19:56.321](0.000s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[14:19:56.443](0.122s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[14:19:56.444](0.001s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[14:19:56.542](0.098s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[14:19:56.542](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[14:19:56.663](0.121s) ok 28 - cert root file that contains two certificates, order 1
[14:19:56.664](0.001s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[14:19:56.790](0.126s) ok 30 - cert root file that contains two certificates, order 2
[14:19:56.790](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[14:19:56.916](0.126s) ok 32 - connect with sslcertmode=disable
[14:19:56.916](0.000s) ok 33 - connect with sslcertmode=disable: no stderr
[14:19:57.039](0.122s) ok 34 - connect with sslcertmode=allow
[14:19:57.039](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[14:19:57.241](0.203s) ok 36 - connect with sslcertmode=require fails without a client certificate
[14:19:57.242](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[14:19:57.333](0.091s) ok 38 - sslcrl option with invalid file name
[14:19:57.333](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[14:19:57.404](0.071s) ok 40 - CRL belonging to a different CA
[14:19:57.404](0.000s) ok 41 - CRL belonging to a different CA: matches
[14:19:57.477](0.073s) ok 42 - directory CRL belonging to a different CA
[14:19:57.478](0.001s) ok 43 - directory CRL belonging to a different CA: matches
[14:19:57.537](0.059s) ok 44 - CRL with a non-revoked cert
[14:19:57.537](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[14:19:57.600](0.063s) ok 46 - directory CRL with a non-revoked cert
[14:19:57.601](0.001s) ok 47 - directory CRL with a non-revoked cert: no stderr
[14:19:57.661](0.060s) ok 48 - mismatch between host name and server certificate sslmode=require
[14:19:57.661](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[14:19:57.725](0.063s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[14:19:57.725](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[14:19:57.836](0.111s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[14:19:57.836](0.001s) ok 53 - mismatch between host name and server certificate sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 1636
[14:19:58.180](0.343s) ok 54 - IP address in the Common Name
[14:19:58.180](0.000s) ok 55 - IP address in the Common Name: no stderr
[14:19:58.242](0.062s) ok 56 - mismatch between host name and server certificate IP address
[14:19:58.242](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 6504
[14:19:58.619](0.377s) ok 58 - IP address in a dNSName
[14:19:58.619](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 8016
[14:19:58.965](0.346s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[14:19:58.966](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[14:19:59.026](0.060s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[14:19:59.026](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[14:19:59.089](0.063s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[14:19:59.089](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[14:19:59.152](0.063s) ok 66 - host name not matching with X.509 Subject Alternative Names
[14:19:59.152](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[14:19:59.215](0.063s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[14:19:59.215](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 1796
[14:19:59.560](0.344s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[14:19:59.560](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[14:19:59.622](0.062s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[14:19:59.622](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[14:19:59.683](0.061s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[14:19:59.684](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches
[14:19:59.714](0.031s) 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 3900
[14:20:00.090](0.376s) ok 77 - certificate with both a CN and SANs 1
[14:20:00.091](0.001s) ok 78 - certificate with both a CN and SANs 1: no stderr
[14:20:00.152](0.062s) ok 79 - certificate with both a CN and SANs 2
[14:20:00.153](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr
[14:20:00.216](0.063s) ok 81 - certificate with both a CN and SANs ignores CN
[14:20:00.216](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches
[14:20:00.246](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 6296
[14:20:00.593](0.347s) ok 84 - certificate with both an IP CN and DNS SANs matches CN
[14:20:00.593](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[14:20:00.656](0.062s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1
[14:20:00.656](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[14:20:00.718](0.062s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2
[14:20:00.718](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 7724
[14:20:01.061](0.343s) ok 90 - server certificate without CN or SANs sslmode=verify-ca
[14:20:01.061](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[14:20:01.123](0.062s) ok 92 - server certificate without CN or SANs sslmode=verify-full
[14:20:01.123](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 2480
[14:20:01.421](0.297s) ok 94 - sslrootcert=system does not connect with private CA
[14:20:01.421](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches
[14:20:01.454](0.033s) ok 96 - sslrootcert=system only accepts sslmode=verify-full
[14:20:01.454](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches
[14:20:01.561](0.107s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE
[14:20:01.562](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[14:20:01.624](0.062s) ok 100 - sslrootcert=system defaults to sslmode=verify-full
[14:20:01.624](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 940
[14:20:01.969](0.344s) ok 102 - connects without client-side CRL
[14:20:01.969](0.000s) ok 103 - connects without client-side CRL: no stderr
[14:20:02.031](0.062s) ok 104 - does not connect with client-side CRL file
[14:20:02.031](0.000s) ok 105 - does not connect with client-side CRL file: matches
[14:20:02.093](0.062s) ok 106 - does not connect with client-side CRL directory
[14:20:02.093](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()
[14:20:02.154](0.061s) ok 108 - pg_stat_ssl view without client certificate: exit code 0
[14:20:02.154](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr
[14:20:02.155](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches
[14:20:02.218](0.064s) ok 111 - connection success with correct range of TLS protocol versions
[14:20:02.219](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr
[14:20:02.249](0.031s) ok 113 - connection failure with incorrect range of TLS protocol versions
[14:20:02.250](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches
[14:20:02.281](0.031s) ok 115 - connection failure with an incorrect SSL protocol minimum bound
[14:20:02.281](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches
[14:20:02.312](0.031s) ok 117 - connection failure with an incorrect SSL protocol maximum bound
[14:20:02.312](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches
[14:20:02.313](0.000s) # running server tests
[14:20:02.375](0.062s) ok 119 - certificate authorization fails without client cert
[14:20:02.375](0.000s) ok 120 - certificate authorization fails without client cert: matches
[14:20:02.484](0.109s) ok 121 - certificate authorization succeeds with correct client cert in PEM format
[14:20:02.484](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[14:20:02.547](0.062s) ok 123 - certificate authorization succeeds with correct client cert in DER format
[14:20:02.547](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr
[14:20:02.672](0.125s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format
[14:20:02.672](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[14:20:02.734](0.062s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format
[14:20:02.735](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[14:20:02.797](0.062s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require
[14:20:02.797](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[14:20:02.859](0.062s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[14:20:02.859](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[14:20:02.922](0.062s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable
[14:20:02.922](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[14:20:02.984](0.062s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[14:20:02.985](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[14:20:03.093](0.109s) ok 137 - certificate authorization succeeds with DN mapping
[14:20:03.094](0.001s) ok 138 - certificate authorization succeeds with DN mapping: no stderr
[14:20:03.095](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches
[14:20:03.204](0.109s) ok 140 - certificate authorization succeeds with DN regex mapping
[14:20:03.204](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr
[14:20:03.313](0.109s) ok 142 - certificate authorization succeeds with CN mapping
[14:20:03.314](0.001s) ok 143 - certificate authorization succeeds with CN mapping: no stderr
[14:20:03.315](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches
[14:20:03.315](0.000s) not ok 145 # TODO & SKIP Need Pty support
[14:20:03.315](0.000s) not ok 146 # TODO & SKIP Need Pty support
[14:20:03.315](0.000s) not ok 147 # TODO & SKIP Need Pty support
[14:20:03.316](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_mGmC/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[14:20:03.421](0.105s) ok 149 - pg_stat_ssl with client certificate: exit code 0
[14:20:03.421](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr
[14:20:03.421](0.000s) ok 151 - pg_stat_ssl with client certificate: matches
[14:20:03.421](0.000s) ok 152 # skip Permissions check not enforced on Windows
[14:20:03.421](0.000s) ok 153 # skip Permissions check not enforced on Windows
[14:20:03.485](0.064s) ok 154 - certificate authorization fails with client cert belonging to another user
[14:20:03.485](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches
[14:20:03.595](0.109s) ok 156 - certificate authorization fails with revoked client cert
[14:20:03.595](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches
[14:20:03.596](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match
[14:20:03.708](0.112s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[14:20:03.708](0.001s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[14:20:03.710](0.002s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[14:20:03.814](0.104s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[14:20:03.815](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[14:20:03.815](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[14:20:03.876](0.061s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[14:20:03.876](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[14:20:03.877](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 7464
[14:20:04.220](0.344s) ok 168 - intermediate client certificate is provided by client
[14:20:04.221](0.001s) ok 169 - intermediate client certificate is provided by client: no stderr
[14:20:04.286](0.065s) ok 170 - intermediate client certificate is missing
[14:20:04.286](0.000s) ok 171 - intermediate client certificate is missing: matches
[14:20:04.346](0.060s) ok 172 - logged client certificate Subjects are truncated if they're too long
[14:20:04.347](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 3456
[14:20:04.642](0.296s) ok 174 - intermediate client certificate is untrusted
[14:20:04.642](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 6524
[14:20:05.127](0.484s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory
[14:20:05.127](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[14:20:05.189](0.062s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[14:20:05.189](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 4348
[14:20:05.502](0.312s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1
[14:20:05.502](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.
[14:20:05.502](0.000s) #          got: '2'
#     expected: '0'
[14:20:05.502](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[14:20:05.503](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.
[14:20:05.503](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 53152 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: ''
[14:20:05.612](0.110s) ok 182 - connect without requesting ocsp response when sslocspstapling=0
[14:20:05.613](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 5696
[14:20:05.909](0.296s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1
[14:20:06.019](0.110s) ok 185 - connect without requesting ocsp response when sslocspstapling=0
[14:20:06.019](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 6408
[14:20:06.315](0.296s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1
[14:20:06.425](0.109s) ok 188 - connect without requesting ocsp response when sslocspstapling=0
[14:20:06.425](0.001s) 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 5820
[14:20:06.721](0.295s) ok 190 - failed with an expired ocsp response when sslocspstapling=1
[14:20:06.784](0.063s) ok 191 - connect without requesting ocsp response when sslocspstapling=0
[14:20:06.784](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 8064
[14:20:07.081](0.297s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1
[14:20:07.081](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.
[14:20:07.081](0.000s) #          got: '2'
#     expected: '0'
[14:20:07.081](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[14:20:07.082](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.
[14:20:07.082](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 53152 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: ''
[14:20:07.192](0.110s) ok 195 - connect without requesting ocsp response when sslocspstapling=0
[14:20:07.192](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 1676
[14:20:07.488](0.296s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1
[14:20:07.598](0.110s) ok 198 - connect without requesting ocsp response when sslocspstapling=0
[14:20:07.598](0.000s) ok 199 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 8008
[14:20:07.894](0.296s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1
[14:20:07.957](0.063s) ok 201 - connect without requesting ocsp response when sslocspstapling=0
[14:20:07.958](0.000s) ok 202 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 6564
[14:20:08.255](0.298s) ok 203 - failed with an expired ocsp response when sslocspstapling=1
[14:20:08.318](0.063s) ok 204 - connect without requesting ocsp response when sslocspstapling=0
[14:20:08.318](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 1060
[14:20:08.614](0.296s) ok 206 - failed with an expired ocsp response when sslocspstapling=1
[14:20:08.678](0.063s) ok 207 - connect without requesting ocsp response when sslocspstapling=0
[14:20:08.678](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-18 14:19:48.993 GMT [5268][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:48.994 GMT [5268][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:49.025 GMT [7528][startup] LOG:  database system was shut down at 2024-03-18 14:10:12 GMT
2024-03-18 14:19:49.074 GMT [5268][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:49.234 GMT [8112][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.236 GMT [8112][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-18 14:19:49.236 GMT [8112][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.259 GMT [8112][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-18 14:19:49.262 GMT [8112][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.396 GMT [3976][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.397 GMT [3976][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-18 14:19:49.397 GMT [3976][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.400 GMT [3976][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-18 14:19:49.401 GMT [3976][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.534 GMT [7856][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.535 GMT [7856][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-18 14:19:49.535 GMT [7856][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.537 GMT [7856][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-18 14:19:49.538 GMT [7856][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.620 GMT [6132][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.621 GMT [6132][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-18 14:19:49.621 GMT [6132][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.623 GMT [6132][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-18 14:19:49.624 GMT [6132][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.715 GMT [5092][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.716 GMT [5092][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-18 14:19:49.716 GMT [5092][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.718 GMT [5092][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-18 14:19:49.720 GMT [5092][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:49.775 GMT [1948][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:49.776 GMT [1948][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-18 14:19:49.776 GMT [1948][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:49.778 GMT [1948][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-18 14:19:49.959 GMT [1948][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.187 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:50.159 GMT [3032][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:50.185 GMT [3032][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-18 14:19:50.185 GMT [3032][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:50.199 GMT [3032][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-18 14:19:50.524 GMT [3032][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.380 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:50.712 GMT [3376][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:50.713 GMT [3376][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-18 14:19:50.713 GMT [3376][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:50.716 GMT [3376][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-18 14:19:50.980 GMT [3376][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.271 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:51.075 GMT [6976][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:51.076 GMT [6976][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-18 14:19:51.076 GMT [6976][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:51.079 GMT [6976][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-18 14:19:51.409 GMT [6976][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.337 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:51.608 GMT [5688][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:51.609 GMT [5688][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-18 14:19:51.609 GMT [5688][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:51.612 GMT [5688][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-18 14:19:51.878 GMT [5688][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.274 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:52.135 GMT [5904][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-18 14:19:52.136 GMT [5904][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-18 14:19:52.136 GMT [5904][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-18 14:19:52.138 GMT [5904][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-18 14:19:52.361 GMT [5904][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.230 user=SYSTEM database=postgres host=[local]
2024-03-18 14:19:52.517 GMT [5268][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:52.517 GMT [5268][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:52.609 GMT [5268][postmaster] LOG:  background worker "logical replication launcher" (PID 1188) exited with exit code 1
2024-03-18 14:19:52.609 GMT [4960][checkpointer] LOG:  shutting down
2024-03-18 14:19:52.609 GMT [4960][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:52.874 GMT [4960][checkpointer] LOG:  checkpoint complete: wrote 5566 buffers (34.0%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.255 s, sync=0.001 s, total=0.265 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-18 14:19:52.950 GMT [5268][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.201 GMT [5292][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:53.202 GMT [5292][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:53.204 GMT [5292][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:53.227 GMT [3376][startup] LOG:  database system was shut down at 2024-03-18 14:19:52 GMT
2024-03-18 14:19:53.247 GMT [5292][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:53.336 GMT [5292][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:53.336 GMT [5292][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:53.344 GMT [5292][postmaster] LOG:  background worker "logical replication launcher" (PID 1548) exited with exit code 1
2024-03-18 14:19:53.345 GMT [1280][checkpointer] LOG:  shutting down
2024-03-18 14:19:53.345 GMT [1280][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:53.348 GMT [1280][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.003 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-18 14:19:53.360 GMT [5292][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.602 GMT [7468][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-18 14:19:53.602 GMT [7468][postmaster] LOG:  database system is shut down
2024-03-18 14:19:53.921 GMT [5332][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:53.922 GMT [5332][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:53.923 GMT [5332][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:53.953 GMT [4032][startup] LOG:  database system was shut down at 2024-03-18 14:19:53 GMT
2024-03-18 14:19:53.980 GMT [5332][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:54.076 GMT [5332][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:54.076 GMT [5332][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:54.089 GMT [5332][postmaster] LOG:  background worker "logical replication launcher" (PID 6020) exited with exit code 1
2024-03-18 14:19:54.094 GMT [7420][checkpointer] LOG:  shutting down
2024-03-18 14:19:54.495 GMT [7420][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:54.500 GMT [7420][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.406 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-18 14:19:54.537 GMT [5332][postmaster] LOG:  database system is shut down
2024-03-18 14:19:54.720 GMT [4964][postmaster] FATAL:  could not set SSL protocol version range
2024-03-18 14:19:54.720 GMT [4964][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-18 14:19:54.720 GMT [4964][postmaster] LOG:  database system is shut down
2024-03-18 14:19:54.975 GMT [900][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:54.976 GMT [900][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:54.977 GMT [900][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:55.013 GMT [6004][startup] LOG:  database system was shut down at 2024-03-18 14:19:54 GMT
2024-03-18 14:19:55.023 GMT [900][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:55.109 GMT [900][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:55.110 GMT [900][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:55.121 GMT [900][postmaster] LOG:  background worker "logical replication launcher" (PID 4608) exited with exit code 1
2024-03-18 14:19:55.121 GMT [2168][checkpointer] LOG:  shutting down
2024-03-18 14:19:55.122 GMT [2168][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:55.126 GMT [2168][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/40C6068, redo lsn=0/40C6068
2024-03-18 14:19:55.132 GMT [900][postmaster] LOG:  database system is shut down
2024-03-18 14:19:55.316 GMT [3812][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:55.316 GMT [3812][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:55.317 GMT [3812][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:55.357 GMT [6352][startup] LOG:  database system was shut down at 2024-03-18 14:19:55 GMT
2024-03-18 14:19:55.366 GMT [3812][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:55.494 GMT [3692][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50345
2024-03-18 14:19:55.495 GMT [3692][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-18 14:19:55.495 GMT [3692][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "pg-loadbalancetest", forward lookup not checked.
2024-03-18 14:19:55.564 GMT [4540][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50347
2024-03-18 14:19:55.571 GMT [4540][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-18 14:19:55.571 GMT [4540][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-18 14:19:55.582 GMT [4540][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-18 14:19:55.586 GMT [4540][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50347
2024-03-18 14:19:55.643 GMT [7868][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50350
2024-03-18 14:19:55.652 GMT [7868][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:19:55.705 GMT [1960][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50352
2024-03-18 14:19:55.729 GMT [1960][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:19:55.951 GMT [4968][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50354
2024-03-18 14:19:55.957 GMT [4968][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:19:56.027 GMT [7072][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50357
2024-03-18 14:19:56.032 GMT [7072][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:19:56.099 GMT [3260][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50359
2024-03-18 14:19:56.105 GMT [3260][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:19:56.188 GMT [5500][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50361
2024-03-18 14:19:56.194 GMT [5500][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:19:56.286 GMT [6540][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50363
2024-03-18 14:19:56.293 GMT [6540][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-18 14:19:56.293 GMT [6540][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-18 14:19:56.296 GMT [6540][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-18 14:19:56.299 GMT [6540][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50363
2024-03-18 14:19:56.383 GMT [5688][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50365
2024-03-18 14:19:56.390 GMT [5688][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-18 14:19:56.390 GMT [5688][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-18 14:19:56.393 GMT [5688][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-18 14:19:56.397 GMT [5688][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50365
2024-03-18 14:19:56.505 GMT [6580][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50367
2024-03-18 14:19:56.512 GMT [6580][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-18 14:19:56.512 GMT [6580][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-18 14:19:56.515 GMT [6580][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-18 14:19:56.519 GMT [6580][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50367
2024-03-18 14:19:56.605 GMT [6592][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50369
2024-03-18 14:19:56.611 GMT [6592][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-18 14:19:56.611 GMT [6592][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-18 14:19:56.614 GMT [6592][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-18 14:19:56.617 GMT [6592][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50369
2024-03-18 14:19:56.711 GMT [4584][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50371
2024-03-18 14:19:56.718 GMT [4584][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-18 14:19:56.718 GMT [4584][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-18 14:19:56.721 GMT [4584][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-18 14:19:56.723 GMT [4584][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50371
2024-03-18 14:19:56.848 GMT [5268][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50374
2024-03-18 14:19:56.856 GMT [5268][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-18 14:19:56.856 GMT [5268][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-18 14:19:56.858 GMT [5268][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-18 14:19:56.862 GMT [5268][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50374
2024-03-18 14:19:56.977 GMT [3852][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50375
2024-03-18 14:19:56.983 GMT [3852][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-18 14:19:56.983 GMT [3852][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-18 14:19:56.986 GMT [3852][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-18 14:19:56.990 GMT [3852][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50375
2024-03-18 14:19:57.080 GMT [2168][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50377
2024-03-18 14:19:57.087 GMT [2168][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-18 14:19:57.087 GMT [2168][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-18 14:19:57.222 GMT [2168][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.148 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50377
2024-03-18 14:19:57.310 GMT [2996][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50379
2024-03-18 14:19:57.317 GMT [2996][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-18 14:19:57.317 GMT [2996][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-18 14:19:57.320 GMT [2996][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-18 14:19:57.323 GMT [2996][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50379
2024-03-18 14:19:57.375 GMT [1052][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50380
2024-03-18 14:19:57.380 GMT [1052][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:19:57.451 GMT [4408][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50381
2024-03-18 14:19:57.457 GMT [4408][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:19:57.523 GMT [8028][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50382
2024-03-18 14:19:57.530 GMT [8028][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-18 14:19:57.530 GMT [8028][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-18 14:19:57.533 GMT [8028][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-18 14:19:57.536 GMT [8028][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50382
2024-03-18 14:19:57.579 GMT [7812][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50383
2024-03-18 14:19:57.586 GMT [7812][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-18 14:19:57.586 GMT [7812][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-18 14:19:57.589 GMT [7812][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-18 14:19:57.592 GMT [7812][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50383
2024-03-18 14:19:57.645 GMT [4752][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50384
2024-03-18 14:19:57.652 GMT [4752][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-18 14:19:57.652 GMT [4752][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-18 14:19:57.655 GMT [4752][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-18 14:19:57.658 GMT [4752][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50384
2024-03-18 14:19:57.704 GMT [4824][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50385
2024-03-18 14:19:57.710 GMT [4824][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-18 14:19:57.710 GMT [4824][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-18 14:19:57.713 GMT [4824][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-18 14:19:57.717 GMT [4824][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50385
2024-03-18 14:19:57.769 GMT [6248][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50386
2024-03-18 14:19:57.856 GMT [3812][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:57.856 GMT [3812][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:57.864 GMT [3812][postmaster] LOG:  background worker "logical replication launcher" (PID 5468) exited with exit code 1
2024-03-18 14:19:57.866 GMT [7104][checkpointer] LOG:  shutting down
2024-03-18 14:19:57.866 GMT [7104][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:57.870 GMT [7104][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-18 14:19:57.875 GMT [3812][postmaster] LOG:  database system is shut down
2024-03-18 14:19:58.010 GMT [1636][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:58.011 GMT [1636][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:58.012 GMT [1636][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:58.035 GMT [1564][startup] LOG:  database system was shut down at 2024-03-18 14:19:57 GMT
2024-03-18 14:19:58.044 GMT [1636][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:58.119 GMT [5624][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50387
2024-03-18 14:19:58.125 GMT [5624][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-18 14:19:58.125 GMT [5624][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-18 14:19:58.137 GMT [5624][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-18 14:19:58.141 GMT [5624][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50387
2024-03-18 14:19:58.222 GMT [2640][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50388
2024-03-18 14:19:58.260 GMT [1636][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:58.260 GMT [1636][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:58.265 GMT [1636][postmaster] LOG:  background worker "logical replication launcher" (PID 5024) exited with exit code 1
2024-03-18 14:19:58.266 GMT [7716][checkpointer] LOG:  shutting down
2024-03-18 14:19:58.267 GMT [7716][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:58.270 GMT [7716][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-18 14:19:58.275 GMT [1636][postmaster] LOG:  database system is shut down
2024-03-18 14:19:58.419 GMT [6504][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:58.420 GMT [6504][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:58.421 GMT [6504][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:58.439 GMT [3604][startup] LOG:  database system was shut down at 2024-03-18 14:19:58 GMT
2024-03-18 14:19:58.447 GMT [6504][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:58.556 GMT [3784][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50389
2024-03-18 14:19:58.563 GMT [3784][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-18 14:19:58.563 GMT [3784][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-18 14:19:58.576 GMT [3784][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-18 14:19:58.580 GMT [3784][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50389
2024-03-18 14:19:58.637 GMT [6504][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:58.637 GMT [6504][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:58.643 GMT [6504][postmaster] LOG:  background worker "logical replication launcher" (PID 2724) exited with exit code 1
2024-03-18 14:19:58.643 GMT [6768][checkpointer] LOG:  shutting down
2024-03-18 14:19:58.643 GMT [6768][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:58.646 GMT [6768][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/40C61D0, redo lsn=0/40C61D0
2024-03-18 14:19:58.651 GMT [6504][postmaster] LOG:  database system is shut down
2024-03-18 14:19:58.794 GMT [8016][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:58.795 GMT [8016][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:58.796 GMT [8016][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:58.822 GMT [7448][startup] LOG:  database system was shut down at 2024-03-18 14:19:58 GMT
2024-03-18 14:19:58.829 GMT [8016][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:58.895 GMT [4788][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50390
2024-03-18 14:19:58.901 GMT [4788][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-18 14:19:58.901 GMT [4788][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-18 14:19:58.914 GMT [4788][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-18 14:19:58.917 GMT [4788][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50390
2024-03-18 14:19:59.007 GMT [7092][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50391
2024-03-18 14:19:59.014 GMT [7092][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-18 14:19:59.014 GMT [7092][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-18 14:19:59.016 GMT [7092][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-18 14:19:59.020 GMT [7092][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50391
2024-03-18 14:19:59.068 GMT [4860][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50392
2024-03-18 14:19:59.075 GMT [4860][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-18 14:19:59.075 GMT [4860][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-18 14:19:59.077 GMT [4860][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-18 14:19:59.082 GMT [4860][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50392
2024-03-18 14:19:59.127 GMT [7652][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50393
2024-03-18 14:19:59.189 GMT [2808][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50394
2024-03-18 14:19:59.231 GMT [8016][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:59.231 GMT [8016][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:59.236 GMT [8016][postmaster] LOG:  background worker "logical replication launcher" (PID 7508) exited with exit code 1
2024-03-18 14:19:59.236 GMT [7908][checkpointer] LOG:  shutting down
2024-03-18 14:19:59.236 GMT [7908][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:59.239 GMT [7908][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/40C6248, redo lsn=0/40C6248
2024-03-18 14:19:59.244 GMT [8016][postmaster] LOG:  database system is shut down
2024-03-18 14:19:59.389 GMT [1796][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:59.390 GMT [1796][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:59.391 GMT [1796][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:59.416 GMT [5844][startup] LOG:  database system was shut down at 2024-03-18 14:19:59 GMT
2024-03-18 14:19:59.423 GMT [1796][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:19:59.489 GMT [6792][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50395
2024-03-18 14:19:59.496 GMT [6792][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-18 14:19:59.496 GMT [6792][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-18 14:19:59.508 GMT [6792][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-18 14:19:59.512 GMT [6792][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50395
2024-03-18 14:19:59.597 GMT [7788][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50396
2024-03-18 14:19:59.660 GMT [4696][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50397
2024-03-18 14:19:59.730 GMT [1796][postmaster] LOG:  received fast shutdown request
2024-03-18 14:19:59.731 GMT [1796][postmaster] LOG:  aborting any active transactions
2024-03-18 14:19:59.734 GMT [1796][postmaster] LOG:  background worker "logical replication launcher" (PID 2588) exited with exit code 1
2024-03-18 14:19:59.735 GMT [6532][checkpointer] LOG:  shutting down
2024-03-18 14:19:59.736 GMT [6532][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:19:59.738 GMT [6532][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/40C62C0, redo lsn=0/40C62C0
2024-03-18 14:19:59.742 GMT [1796][postmaster] LOG:  database system is shut down
2024-03-18 14:19:59.934 GMT [3900][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:19:59.935 GMT [3900][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:19:59.936 GMT [3900][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:19:59.955 GMT [4804][startup] LOG:  database system was shut down at 2024-03-18 14:19:59 GMT
2024-03-18 14:19:59.962 GMT [3900][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:00.021 GMT [6020][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50398
2024-03-18 14:20:00.027 GMT [6020][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-18 14:20:00.027 GMT [6020][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-18 14:20:00.039 GMT [6020][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-18 14:20:00.042 GMT [6020][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50398
2024-03-18 14:20:00.132 GMT [7352][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50399
2024-03-18 14:20:00.139 GMT [7352][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-18 14:20:00.139 GMT [7352][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-18 14:20:00.142 GMT [7352][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-18 14:20:00.144 GMT [7352][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50399
2024-03-18 14:20:00.189 GMT [3840][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50400
2024-03-18 14:20:00.261 GMT [3900][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:00.262 GMT [3900][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:00.266 GMT [3900][postmaster] LOG:  background worker "logical replication launcher" (PID 1248) exited with exit code 1
2024-03-18 14:20:00.267 GMT [7764][checkpointer] LOG:  shutting down
2024-03-18 14:20:00.268 GMT [7764][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:00.270 GMT [7764][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-18 14:20:00.274 GMT [3900][postmaster] LOG:  database system is shut down
2024-03-18 14:20:00.418 GMT [6296][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:00.419 GMT [6296][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:00.420 GMT [6296][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:00.439 GMT [7420][startup] LOG:  database system was shut down at 2024-03-18 14:20:00 GMT
2024-03-18 14:20:00.446 GMT [6296][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:00.525 GMT [7620][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50401
2024-03-18 14:20:00.531 GMT [7620][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-18 14:20:00.531 GMT [7620][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-18 14:20:00.544 GMT [7620][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-18 14:20:00.547 GMT [7620][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50401
2024-03-18 14:20:00.633 GMT [1188][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50402
2024-03-18 14:20:00.639 GMT [1188][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-18 14:20:00.639 GMT [1188][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-18 14:20:00.642 GMT [1188][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-18 14:20:00.645 GMT [1188][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50402
2024-03-18 14:20:00.696 GMT [5884][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50403
2024-03-18 14:20:00.703 GMT [5884][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-18 14:20:00.703 GMT [5884][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-18 14:20:00.705 GMT [5884][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-18 14:20:00.707 GMT [5884][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50403
2024-03-18 14:20:00.733 GMT [6296][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:00.733 GMT [6296][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:00.737 GMT [6296][postmaster] LOG:  background worker "logical replication launcher" (PID 5576) exited with exit code 1
2024-03-18 14:20:00.738 GMT [5800][checkpointer] LOG:  shutting down
2024-03-18 14:20:00.738 GMT [5800][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:00.741 GMT [5800][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-18 14:20:00.745 GMT [6296][postmaster] LOG:  database system is shut down
2024-03-18 14:20:00.892 GMT [7724][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:00.892 GMT [7724][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:00.893 GMT [7724][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:00.911 GMT [404][startup] LOG:  database system was shut down at 2024-03-18 14:20:00 GMT
2024-03-18 14:20:00.917 GMT [7724][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:00.992 GMT [1824][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50404
2024-03-18 14:20:00.998 GMT [1824][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-18 14:20:00.998 GMT [1824][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-18 14:20:01.010 GMT [1824][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-18 14:20:01.013 GMT [1824][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50404
2024-03-18 14:20:01.101 GMT [6624][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50405
2024-03-18 14:20:01.140 GMT [7724][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:01.140 GMT [7724][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:01.144 GMT [7724][postmaster] LOG:  background worker "logical replication launcher" (PID 6440) exited with exit code 1
2024-03-18 14:20:01.144 GMT [5760][checkpointer] LOG:  shutting down
2024-03-18 14:20:01.144 GMT [5760][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:01.147 GMT [5760][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/40C6428, redo lsn=0/40C6428
2024-03-18 14:20:01.151 GMT [7724][postmaster] LOG:  database system is shut down
2024-03-18 14:20:01.303 GMT [2480][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:01.304 GMT [2480][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:01.305 GMT [2480][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:01.337 GMT [5796][startup] LOG:  database system was shut down at 2024-03-18 14:20:01 GMT
2024-03-18 14:20:01.345 GMT [2480][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:01.399 GMT [1640][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50406
2024-03-18 14:20:01.405 GMT [1640][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-18 14:20:01.498 GMT [4744][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50407
2024-03-18 14:20:01.505 GMT [4744][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-18 14:20:01.505 GMT [4744][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-18 14:20:01.520 GMT [4744][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-18 14:20:01.522 GMT [4744][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50407
2024-03-18 14:20:01.602 GMT [2632][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50408
2024-03-18 14:20:01.640 GMT [2480][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:01.640 GMT [2480][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:01.644 GMT [2480][postmaster] LOG:  background worker "logical replication launcher" (PID 652) exited with exit code 1
2024-03-18 14:20:01.644 GMT [6716][checkpointer] LOG:  shutting down
2024-03-18 14:20:01.644 GMT [6716][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:01.647 GMT [6716][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/40C64A0, redo lsn=0/40C64A0
2024-03-18 14:20:01.651 GMT [2480][postmaster] LOG:  database system is shut down
2024-03-18 14:20:01.799 GMT [940][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:01.800 GMT [940][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:01.801 GMT [940][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:01.821 GMT [3216][startup] LOG:  database system was shut down at 2024-03-18 14:20:01 GMT
2024-03-18 14:20:01.828 GMT [940][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:01.900 GMT [2996][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50409
2024-03-18 14:20:01.907 GMT [2996][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-18 14:20:01.907 GMT [2996][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-18 14:20:01.919 GMT [2996][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-18 14:20:01.922 GMT [2996][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50409
2024-03-18 14:20:02.008 GMT [3432][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50410
2024-03-18 14:20:02.014 GMT [3432][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-18 14:20:02.069 GMT [7252][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50411
2024-03-18 14:20:02.076 GMT [7252][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-18 14:20:02.129 GMT [6544][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50412
2024-03-18 14:20:02.135 GMT [6544][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-18 14:20:02.135 GMT [6544][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-18 14:20:02.138 GMT [6544][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-18 14:20:02.143 GMT [6544][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50412
2024-03-18 14:20:02.195 GMT [796][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50413
2024-03-18 14:20:02.202 GMT [796][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-18 14:20:02.202 GMT [796][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-18 14:20:02.204 GMT [796][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-18 14:20:02.206 GMT [796][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.017 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50413
2024-03-18 14:20:02.352 GMT [2628][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50414
2024-03-18 14:20:02.358 GMT [2628][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-03-18 14:20:02.416 GMT [6856][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50415
2024-03-18 14:20:02.424 GMT [6856][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-18 14:20:02.424 GMT [6856][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-18 14:20:02.437 GMT [6856][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_mGmC/client.key$$
2024-03-18 14:20:02.440 GMT [6856][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb host=pg-loadbalancetest port=50415
2024-03-18 14:20:02.526 GMT [5228][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50416
2024-03-18 14:20:02.534 GMT [5228][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-18 14:20:02.534 GMT [5228][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-18 14:20:02.537 GMT [5228][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_mGmC/client-der.key$$
2024-03-18 14:20:02.539 GMT [5228][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50416
2024-03-18 14:20:02.615 GMT [6060][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50417
2024-03-18 14:20:02.625 GMT [6060][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-18 14:20:02.625 GMT [6060][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-18 14:20:02.628 GMT [6060][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_mGmC/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-03-18 14:20:02.630 GMT [6060][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50417
2024-03-18 14:20:02.712 GMT [4932][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50418
2024-03-18 14:20:02.721 GMT [4932][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-18 14:20:02.721 GMT [4932][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-18 14:20:02.724 GMT [4932][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_mGmC/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-03-18 14:20:02.726 GMT [4932][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50418
2024-03-18 14:20:02.774 GMT [1120][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50419
2024-03-18 14:20:02.783 GMT [1120][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-18 14:20:02.783 GMT [1120][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-18 14:20:02.786 GMT [1120][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_mGmC/client.key$$
2024-03-18 14:20:02.788 GMT [1120][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50419
2024-03-18 14:20:02.836 GMT [6868][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50420
2024-03-18 14:20:02.844 GMT [6868][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-18 14:20:02.844 GMT [6868][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-18 14:20:02.847 GMT [6868][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_mGmC/client.key$$
2024-03-18 14:20:02.849 GMT [6868][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50420
2024-03-18 14:20:02.895 GMT [4760][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50421
2024-03-18 14:20:02.901 GMT [4760][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-03-18 14:20:02.960 GMT [7760][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50422
2024-03-18 14:20:02.970 GMT [7760][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-18 14:20:03.023 GMT [7372][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50423
2024-03-18 14:20:03.031 GMT [7372][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-18 14:20:03.031 GMT [7372][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-18 14:20:03.043 GMT [7372][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_mGmC/client-dn.key$$
2024-03-18 14:20:03.046 GMT [7372][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50423
2024-03-18 14:20:03.135 GMT [4740][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50424
2024-03-18 14:20:03.144 GMT [4740][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-18 14:20:03.144 GMT [4740][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-18 14:20:03.155 GMT [4740][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_mGmC/client-dn.key$$
2024-03-18 14:20:03.157 GMT [4740][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50424
2024-03-18 14:20:03.244 GMT [4440][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50425
2024-03-18 14:20:03.252 GMT [4440][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-18 14:20:03.252 GMT [4440][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-18 14:20:03.265 GMT [4440][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_mGmC/client-dn.key$$
2024-03-18 14:20:03.267 GMT [4440][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50425
2024-03-18 14:20:03.362 GMT [3448][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50426
2024-03-18 14:20:03.371 GMT [3448][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-18 14:20:03.371 GMT [3448][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-18 14:20:03.374 GMT [3448][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-18 14:20:03.378 GMT [3448][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=certdb host=pg-loadbalancetest port=50426
2024-03-18 14:20:03.460 GMT [4928][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50427
2024-03-18 14:20:03.469 GMT [4928][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-18 14:20:03.469 GMT [4928][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-18 14:20:03.469 GMT [4928][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-03-18 14:20:03.469 GMT [4928][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-18 14:20:03.527 GMT [2700][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50428
2024-03-18 14:20:03.541 GMT [2700][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:20:03.541 GMT [2700][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-18 14:20:03.636 GMT [976][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50429
2024-03-18 14:20:03.644 GMT [976][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-18 14:20:03.644 GMT [976][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-18 14:20:03.656 GMT [976][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_mGmC/client.key$$
2024-03-18 14:20:03.658 GMT [976][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50429
2024-03-18 14:20:03.751 GMT [2872][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50430
2024-03-18 14:20:03.760 GMT [2872][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-18 14:20:03.760 GMT [2872][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-03-18 14:20:03.760 GMT [2872][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-03-18 14:20:03.760 GMT [2872][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-18 14:20:03.858 GMT [1132][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50431
2024-03-18 14:20:03.867 GMT [1132][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-18 14:20:03.867 GMT [1132][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-18 14:20:03.870 GMT [1132][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_mGmC/client.key$$
2024-03-18 14:20:03.872 GMT [1132][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50431
2024-03-18 14:20:03.891 GMT [940][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:03.891 GMT [940][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:03.894 GMT [940][postmaster] LOG:  background worker "logical replication launcher" (PID 4512) exited with exit code 1
2024-03-18 14:20:03.895 GMT [4328][checkpointer] LOG:  shutting down
2024-03-18 14:20:03.895 GMT [4328][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:03.898 GMT [4328][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-18 14:20:03.902 GMT [940][postmaster] LOG:  database system is shut down
2024-03-18 14:20:04.050 GMT [7464][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:04.050 GMT [7464][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:04.051 GMT [7464][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:04.070 GMT [3600][startup] LOG:  database system was shut down at 2024-03-18 14:20:03 GMT
2024-03-18 14:20:04.077 GMT [7464][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:04.150 GMT [4724][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50432
2024-03-18 14:20:04.158 GMT [4724][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-18 14:20:04.158 GMT [4724][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-18 14:20:04.170 GMT [4724][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_mGmC/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-18 14:20:04.172 GMT [4724][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb host=pg-loadbalancetest port=50432
2024-03-18 14:20:04.259 GMT [2804][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50433
2024-03-18 14:20:04.266 GMT [2804][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:20:04.266 GMT [2804][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-18 14:20:04.322 GMT [2848][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50434
2024-03-18 14:20:04.330 GMT [2848][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:20:04.330 GMT [2848][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-18 14:20:04.362 GMT [7464][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:04.362 GMT [7464][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:04.365 GMT [7464][postmaster] LOG:  background worker "logical replication launcher" (PID 6480) exited with exit code 1
2024-03-18 14:20:04.366 GMT [3292][checkpointer] LOG:  shutting down
2024-03-18 14:20:04.366 GMT [3292][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:04.369 GMT [3292][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-18 14:20:04.373 GMT [7464][postmaster] LOG:  database system is shut down
2024-03-18 14:20:04.522 GMT [3456][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:04.522 GMT [3456][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:04.523 GMT [3456][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:04.543 GMT [7664][startup] LOG:  database system was shut down at 2024-03-18 14:20:04 GMT
2024-03-18 14:20:04.550 GMT [3456][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:04.618 GMT [1500][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50435
2024-03-18 14:20:04.626 GMT [1500][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:20:04.626 GMT [1500][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-18 14:20:04.657 GMT [3456][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:04.657 GMT [3456][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:04.660 GMT [3456][postmaster] LOG:  background worker "logical replication launcher" (PID 6244) exited with exit code 1
2024-03-18 14:20:04.661 GMT [6548][checkpointer] LOG:  shutting down
2024-03-18 14:20:04.661 GMT [6548][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:04.664 GMT [6548][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-18 14:20:04.668 GMT [3456][postmaster] LOG:  database system is shut down
2024-03-18 14:20:04.907 GMT [6524][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:04.907 GMT [6524][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:04.908 GMT [6524][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:04.928 GMT [832][startup] LOG:  database system was shut down at 2024-03-18 14:20:04 GMT
2024-03-18 14:20:04.943 GMT [6524][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:05.093 GMT [6400][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50436
2024-03-18 14:20:05.101 GMT [6400][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:20:05.101 GMT [6400][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-18 14:20:05.167 GMT [7652][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50437
2024-03-18 14:20:05.175 GMT [7652][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-18 14:20:05.175 GMT [7652][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-18 14:20:05.205 GMT [6524][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:05.205 GMT [6524][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:05.210 GMT [6524][postmaster] LOG:  background worker "logical replication launcher" (PID 7704) exited with exit code 1
2024-03-18 14:20:05.210 GMT [5828][checkpointer] LOG:  shutting down
2024-03-18 14:20:05.210 GMT [5828][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:05.213 GMT [5828][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-18 14:20:05.217 GMT [6524][postmaster] LOG:  database system is shut down
2024-03-18 14:20:05.371 GMT [4348][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:05.372 GMT [4348][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:05.372 GMT [4348][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:05.392 GMT [7264][startup] LOG:  database system was shut down at 2024-03-18 14:20:05 GMT
2024-03-18 14:20:05.398 GMT [4348][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:05.479 GMT [3816][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50438
2024-03-18 14:20:05.482 GMT [3816][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:05.482 GMT [3816][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:05.544 GMT [6792][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50439
2024-03-18 14:20:05.551 GMT [6792][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-18 14:20:05.551 GMT [6792][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-18 14:20:05.563 GMT [6792][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-18 14:20:05.566 GMT [6792][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50439
2024-03-18 14:20:05.628 GMT [4348][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:05.628 GMT [4348][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:05.633 GMT [4348][postmaster] LOG:  background worker "logical replication launcher" (PID 8020) exited with exit code 1
2024-03-18 14:20:05.633 GMT [1472][checkpointer] LOG:  shutting down
2024-03-18 14:20:05.633 GMT [1472][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:05.636 GMT [1472][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-18 14:20:05.640 GMT [4348][postmaster] LOG:  database system is shut down
2024-03-18 14:20:05.787 GMT [5696][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:05.787 GMT [5696][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:05.788 GMT [5696][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:05.819 GMT [4284][startup] LOG:  database system was shut down at 2024-03-18 14:20:05 GMT
2024-03-18 14:20:05.827 GMT [5696][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:05.887 GMT [5636][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50440
2024-03-18 14:20:05.891 GMT [5636][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:05.891 GMT [5636][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:05.950 GMT [6900][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50441
2024-03-18 14:20:05.957 GMT [6900][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-18 14:20:05.957 GMT [6900][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-18 14:20:05.970 GMT [6900][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-18 14:20:05.972 GMT [6900][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50441
2024-03-18 14:20:06.036 GMT [5696][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:06.036 GMT [5696][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:06.042 GMT [5696][postmaster] LOG:  background worker "logical replication launcher" (PID 3144) exited with exit code 1
2024-03-18 14:20:06.042 GMT [2424][checkpointer] LOG:  shutting down
2024-03-18 14:20:06.042 GMT [2424][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:06.045 GMT [2424][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-18 14:20:06.050 GMT [5696][postmaster] LOG:  database system is shut down
2024-03-18 14:20:06.197 GMT [6408][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:06.197 GMT [6408][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:06.199 GMT [6408][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:06.225 GMT [1400][startup] LOG:  database system was shut down at 2024-03-18 14:20:06 GMT
2024-03-18 14:20:06.232 GMT [6408][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:06.296 GMT [1248][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50442
2024-03-18 14:20:06.299 GMT [1248][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:06.300 GMT [1248][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:06.355 GMT [400][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50443
2024-03-18 14:20:06.361 GMT [400][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-18 14:20:06.361 GMT [400][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-18 14:20:06.374 GMT [400][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-18 14:20:06.377 GMT [400][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50443
2024-03-18 14:20:06.443 GMT [6408][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:06.443 GMT [6408][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:06.450 GMT [6408][postmaster] LOG:  background worker "logical replication launcher" (PID 3760) exited with exit code 1
2024-03-18 14:20:06.450 GMT [7424][checkpointer] LOG:  shutting down
2024-03-18 14:20:06.450 GMT [7424][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:06.452 GMT [7424][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-18 14:20:06.457 GMT [6408][postmaster] LOG:  database system is shut down
2024-03-18 14:20:06.596 GMT [5820][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:06.596 GMT [5820][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:06.597 GMT [5820][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:06.615 GMT [3152][startup] LOG:  database system was shut down at 2024-03-18 14:20:06 GMT
2024-03-18 14:20:06.622 GMT [5820][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:06.703 GMT [2460][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50444
2024-03-18 14:20:06.706 GMT [2460][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:06.707 GMT [2460][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:06.760 GMT [1692][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50445
2024-03-18 14:20:06.766 GMT [1692][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-18 14:20:06.766 GMT [1692][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-18 14:20:06.778 GMT [1692][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-18 14:20:06.782 GMT [1692][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50445
2024-03-18 14:20:06.800 GMT [5820][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:06.800 GMT [5820][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:06.804 GMT [5820][postmaster] LOG:  background worker "logical replication launcher" (PID 1188) exited with exit code 1
2024-03-18 14:20:06.805 GMT [820][checkpointer] LOG:  shutting down
2024-03-18 14:20:06.805 GMT [820][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:06.808 GMT [820][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/40C6860, redo lsn=0/40C6860
2024-03-18 14:20:06.812 GMT [5820][postmaster] LOG:  database system is shut down
2024-03-18 14:20:06.956 GMT [8064][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:06.957 GMT [8064][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:06.958 GMT [8064][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:06.984 GMT [404][startup] LOG:  database system was shut down at 2024-03-18 14:20:06 GMT
2024-03-18 14:20:06.991 GMT [8064][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:07.062 GMT [7340][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50446
2024-03-18 14:20:07.064 GMT [7340][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:07.065 GMT [7340][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:07.122 GMT [6860][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50447
2024-03-18 14:20:07.129 GMT [6860][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-18 14:20:07.129 GMT [6860][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-18 14:20:07.140 GMT [6860][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-18 14:20:07.143 GMT [6860][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50447
2024-03-18 14:20:07.208 GMT [8064][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:07.208 GMT [8064][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:07.212 GMT [8064][postmaster] LOG:  background worker "logical replication launcher" (PID 1824) exited with exit code 1
2024-03-18 14:20:07.212 GMT [7612][checkpointer] LOG:  shutting down
2024-03-18 14:20:07.212 GMT [7612][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:07.215 GMT [7612][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-18 14:20:07.219 GMT [8064][postmaster] LOG:  database system is shut down
2024-03-18 14:20:07.364 GMT [1676][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:07.365 GMT [1676][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:07.366 GMT [1676][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:07.387 GMT [6332][startup] LOG:  database system was shut down at 2024-03-18 14:20:07 GMT
2024-03-18 14:20:07.394 GMT [1676][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:07.464 GMT [5740][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50448
2024-03-18 14:20:07.467 GMT [5740][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:07.467 GMT [5740][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:07.528 GMT [3848][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50449
2024-03-18 14:20:07.534 GMT [3848][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-18 14:20:07.534 GMT [3848][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-18 14:20:07.545 GMT [3848][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-18 14:20:07.550 GMT [3848][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50449
2024-03-18 14:20:07.613 GMT [1676][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:07.613 GMT [1676][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:07.616 GMT [1676][postmaster] LOG:  background worker "logical replication launcher" (PID 4924) exited with exit code 1
2024-03-18 14:20:07.617 GMT [5796][checkpointer] LOG:  shutting down
2024-03-18 14:20:07.617 GMT [5796][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:07.620 GMT [5796][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-18 14:20:07.624 GMT [1676][postmaster] LOG:  database system is shut down
2024-03-18 14:20:07.771 GMT [8008][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:07.772 GMT [8008][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:07.773 GMT [8008][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:07.793 GMT [4812][startup] LOG:  database system was shut down at 2024-03-18 14:20:07 GMT
2024-03-18 14:20:07.799 GMT [8008][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:07.871 GMT [7320][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50450
2024-03-18 14:20:07.874 GMT [7320][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:07.874 GMT [7320][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:07.931 GMT [1548][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50451
2024-03-18 14:20:07.937 GMT [1548][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-18 14:20:07.937 GMT [1548][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-18 14:20:07.948 GMT [1548][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-18 14:20:07.951 GMT [1548][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50451
2024-03-18 14:20:07.972 GMT [8008][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:07.973 GMT [8008][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:07.976 GMT [8008][postmaster] LOG:  background worker "logical replication launcher" (PID 700) exited with exit code 1
2024-03-18 14:20:07.976 GMT [3780][checkpointer] LOG:  shutting down
2024-03-18 14:20:07.977 GMT [3780][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:07.979 GMT [3780][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-18 14:20:07.983 GMT [8008][postmaster] LOG:  database system is shut down
2024-03-18 14:20:08.128 GMT [6564][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:08.128 GMT [6564][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:08.129 GMT [6564][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:08.155 GMT [6196][startup] LOG:  database system was shut down at 2024-03-18 14:20:07 GMT
2024-03-18 14:20:08.162 GMT [6564][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:08.229 GMT [2976][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50452
2024-03-18 14:20:08.232 GMT [2976][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:08.232 GMT [2976][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:08.293 GMT [5728][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50453
2024-03-18 14:20:08.299 GMT [5728][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-18 14:20:08.299 GMT [5728][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-18 14:20:08.311 GMT [5728][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-18 14:20:08.314 GMT [5728][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50453
2024-03-18 14:20:08.333 GMT [6564][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:08.333 GMT [6564][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:08.337 GMT [6564][postmaster] LOG:  background worker "logical replication launcher" (PID 2408) exited with exit code 1
2024-03-18 14:20:08.337 GMT [6584][checkpointer] LOG:  shutting down
2024-03-18 14:20:08.337 GMT [6584][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:08.340 GMT [6584][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/40C6A40, redo lsn=0/40C6A40
2024-03-18 14:20:08.344 GMT [6564][postmaster] LOG:  database system is shut down
2024-03-18 14:20:08.492 GMT [1060][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-18 14:20:08.492 GMT [1060][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 53152
2024-03-18 14:20:08.493 GMT [1060][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/xPPUNt3cft/.s.PGSQL.53152"
2024-03-18 14:20:08.513 GMT [3264][startup] LOG:  database system was shut down at 2024-03-18 14:20:08 GMT
2024-03-18 14:20:08.519 GMT [1060][postmaster] LOG:  database system is ready to accept connections
2024-03-18 14:20:08.588 GMT [6932][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50454
2024-03-18 14:20:08.591 GMT [6932][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-18 14:20:08.591 GMT [6932][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-18 14:20:08.651 GMT [5440][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50455
2024-03-18 14:20:08.657 GMT [5440][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-18 14:20:08.657 GMT [5440][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-18 14:20:08.670 GMT [5440][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-18 14:20:08.673 GMT [5440][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50455
2024-03-18 14:20:08.694 GMT [1060][postmaster] LOG:  received fast shutdown request
2024-03-18 14:20:08.694 GMT [1060][postmaster] LOG:  aborting any active transactions
2024-03-18 14:20:08.697 GMT [1060][postmaster] LOG:  background worker "logical replication launcher" (PID 6388) exited with exit code 1
2024-03-18 14:20:08.698 GMT [4428][checkpointer] LOG:  shutting down
2024-03-18 14:20:08.698 GMT [4428][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-18 14:20:08.701 GMT [4428][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-18 14:20:08.705 GMT [1060][postmaster] LOG:  database system is shut down
2024-03-18 14:20:08.844 GMT [4740][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-03-18 14:20:08.844 GMT [4740][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[14:20:08.912](0.235s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"