[08:17:46.994](0.255s) # setting up data directory
# Checking port 51895
# Found port 51895
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=51895 host=C:/Windows/TEMP/TDq25dOw8O
Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log
[08:17:47.126](0.132s) # 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 5096
[08:17:48.761](1.635s) 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 4228
[08:17:53.407](4.646s) # 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-30 08:17:48.447 GMT [5096][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:48.448 GMT [5096][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:48.491 GMT [1216][startup] LOG:  database system was shut down at 2024-03-30 08:07:34 GMT
2024-03-30 08:17:48.546 GMT [5096][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:48.696 GMT [2860][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.698 GMT [2860][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-30 08:17:48.698 GMT [2860][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.717 GMT [2860][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-30 08:17:48.721 GMT [2860][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:48.851 GMT [7368][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.853 GMT [7368][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-30 08:17:48.853 GMT [7368][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.855 GMT [7368][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-30 08:17:48.856 GMT [7368][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:48.948 GMT [4044][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.950 GMT [4044][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-30 08:17:48.950 GMT [4044][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.952 GMT [4044][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-30 08:17:48.953 GMT [4044][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.024 GMT [5584][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.025 GMT [5584][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-30 08:17:49.025 GMT [5584][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.027 GMT [5584][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-30 08:17:49.028 GMT [5584][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.199 GMT [2812][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.200 GMT [2812][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-30 08:17:49.200 GMT [2812][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.204 GMT [2812][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-30 08:17:49.204 GMT [2812][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.340 GMT [1156][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.342 GMT [1156][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-30 08:17:49.342 GMT [1156][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.344 GMT [1156][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-30 08:17:49.706 GMT [1156][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.369 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.121 GMT [1816][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.123 GMT [1816][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-30 08:17:50.123 GMT [1816][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.125 GMT [1816][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-30 08:17:50.415 GMT [1816][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.297 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.626 GMT [6072][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.627 GMT [6072][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-30 08:17:50.627 GMT [6072][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.630 GMT [6072][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-30 08:17:50.881 GMT [6072][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.274 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.970 GMT [4924][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.971 GMT [4924][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-30 08:17:50.971 GMT [4924][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.976 GMT [4924][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-30 08:17:51.268 GMT [4924][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.302 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:51.470 GMT [1864][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:51.471 GMT [1864][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-30 08:17:51.471 GMT [1864][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:51.474 GMT [1864][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-30 08:17:51.714 GMT [1864][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.248 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:51.867 GMT [6952][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:51.869 GMT [6952][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-30 08:17:51.869 GMT [6952][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:51.871 GMT [6952][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-30 08:17:52.491 GMT [6952][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.626 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:52.717 GMT [5096][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:52.717 GMT [5096][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:52.736 GMT [5096][postmaster] LOG:  background worker "logical replication launcher" (PID 3836) exited with exit code 1
2024-03-30 08:17:52.739 GMT [5488][checkpointer] LOG:  shutting down
2024-03-30 08:17:52.739 GMT [5488][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:52.940 GMT [5488][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.193 s, sync=0.001 s, total=0.201 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407DC68, redo lsn=0/407DC68
2024-03-30 08:17:53.034 GMT [5096][postmaster] LOG:  database system is shut down
2024-03-30 08:17:53.262 GMT [4228][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:53.263 GMT [4228][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:53.264 GMT [4228][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:53.306 GMT [236][startup] LOG:  database system was shut down at 2024-03-30 08:17:52 GMT
2024-03-30 08:17:53.331 GMT [4228][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:53.452 GMT [4228][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:53.452 GMT [4228][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:53.481 GMT [4228][postmaster] LOG:  background worker "logical replication launcher" (PID 2796) exited with exit code 1
2024-03-30 08:17:53.519 GMT [3188][checkpointer] LOG:  shutting down
2024-03-30 08:17:53.520 GMT [3188][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:53.523 GMT [3188][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/407DCE0, redo lsn=0/407DCE0
2024-03-30 08:17:53.548 GMT [4228][postmaster] LOG:  database system is shut down
2024-03-30 08:17:53.865 GMT [4840][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-30 08:17:53.865 GMT [4840][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[08:17:54.018](0.611s) 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 4264
[08:17:54.508](0.490s) 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-30 08:17:48.447 GMT [5096][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:48.448 GMT [5096][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:48.491 GMT [1216][startup] LOG:  database system was shut down at 2024-03-30 08:07:34 GMT
2024-03-30 08:17:48.546 GMT [5096][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:48.696 GMT [2860][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.698 GMT [2860][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-30 08:17:48.698 GMT [2860][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.717 GMT [2860][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-30 08:17:48.721 GMT [2860][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:48.851 GMT [7368][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.853 GMT [7368][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-30 08:17:48.853 GMT [7368][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.855 GMT [7368][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-30 08:17:48.856 GMT [7368][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:48.948 GMT [4044][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.950 GMT [4044][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-30 08:17:48.950 GMT [4044][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.952 GMT [4044][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-30 08:17:48.953 GMT [4044][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.024 GMT [5584][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.025 GMT [5584][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-30 08:17:49.025 GMT [5584][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.027 GMT [5584][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-30 08:17:49.028 GMT [5584][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.199 GMT [2812][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.200 GMT [2812][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-30 08:17:49.200 GMT [2812][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.204 GMT [2812][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-30 08:17:49.204 GMT [2812][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.340 GMT [1156][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.342 GMT [1156][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-30 08:17:49.342 GMT [1156][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.344 GMT [1156][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-30 08:17:49.706 GMT [1156][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.369 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.121 GMT [1816][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.123 GMT [1816][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-30 08:17:50.123 GMT [1816][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.125 GMT [1816][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-30 08:17:50.415 GMT [1816][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.297 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.626 GMT [6072][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.627 GMT [6072][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-30 08:17:50.627 GMT [6072][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.630 GMT [6072][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-30 08:17:50.881 GMT [6072][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.274 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.970 GMT [4924][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.971 GMT [4924][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-30 08:17:50.971 GMT [4924][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.976 GMT [4924][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-30 08:17:51.268 GMT [4924][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.302 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:51.470 GMT [1864][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:51.471 GMT [1864][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-30 08:17:51.471 GMT [1864][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:51.474 GMT [1864][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-30 08:17:51.714 GMT [1864][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.248 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:51.867 GMT [6952][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:51.869 GMT [6952][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-30 08:17:51.869 GMT [6952][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:51.871 GMT [6952][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-30 08:17:52.491 GMT [6952][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.626 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:52.717 GMT [5096][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:52.717 GMT [5096][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:52.736 GMT [5096][postmaster] LOG:  background worker "logical replication launcher" (PID 3836) exited with exit code 1
2024-03-30 08:17:52.739 GMT [5488][checkpointer] LOG:  shutting down
2024-03-30 08:17:52.739 GMT [5488][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:52.940 GMT [5488][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.193 s, sync=0.001 s, total=0.201 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407DC68, redo lsn=0/407DC68
2024-03-30 08:17:53.034 GMT [5096][postmaster] LOG:  database system is shut down
2024-03-30 08:17:53.262 GMT [4228][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:53.263 GMT [4228][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:53.264 GMT [4228][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:53.306 GMT [236][startup] LOG:  database system was shut down at 2024-03-30 08:17:52 GMT
2024-03-30 08:17:53.331 GMT [4228][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:53.452 GMT [4228][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:53.452 GMT [4228][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:53.481 GMT [4228][postmaster] LOG:  background worker "logical replication launcher" (PID 2796) exited with exit code 1
2024-03-30 08:17:53.519 GMT [3188][checkpointer] LOG:  shutting down
2024-03-30 08:17:53.520 GMT [3188][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:53.523 GMT [3188][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/407DCE0, redo lsn=0/407DCE0
2024-03-30 08:17:53.548 GMT [4228][postmaster] LOG:  database system is shut down
2024-03-30 08:17:53.865 GMT [4840][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-30 08:17:53.865 GMT [4840][postmaster] LOG:  database system is shut down
2024-03-30 08:17:54.336 GMT [4264][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:54.336 GMT [4264][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:54.337 GMT [4264][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:54.390 GMT [5152][startup] LOG:  database system was shut down at 2024-03-30 08:17:53 GMT
2024-03-30 08:17:54.420 GMT [4264][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:54.534 GMT [4264][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:54.534 GMT [4264][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:54.565 GMT [4264][postmaster] LOG:  background worker "logical replication launcher" (PID 6216) exited with exit code 1
2024-03-30 08:17:54.582 GMT [7768][checkpointer] LOG:  shutting down
2024-03-30 08:17:54.583 GMT [7768][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:54.587 GMT [7768][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407DD58, redo lsn=0/407DD58
2024-03-30 08:17:54.603 GMT [4264][postmaster] LOG:  database system is shut down
2024-03-30 08:17:54.755 GMT [7780][postmaster] FATAL:  could not set SSL protocol version range
2024-03-30 08:17:54.755 GMT [7780][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-30 08:17:54.759 GMT [7780][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[08:17:54.863](0.355s) 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 6008
[08:17:55.293](0.431s) ok 5 - restart succeeds with correct SSL protocol bounds
[08:17:55.294](0.001s) # running client tests
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 3036
[08:17:56.274](0.980s) ok 6 - server doesn't accept non-SSL connections
[08:17:56.274](0.000s) ok 7 - server doesn't accept non-SSL connections: matches
[08:17:56.368](0.093s) ok 8 - connect without server root cert sslmode=require
[08:17:56.368](0.000s) ok 9 - connect without server root cert sslmode=require: no stderr
[08:17:56.430](0.062s) ok 10 - connect without server root cert sslmode=verify-ca
[08:17:56.430](0.001s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[08:17:56.519](0.089s) ok 12 - connect without server root cert sslmode=verify-full
[08:17:56.520](0.001s) ok 13 - connect without server root cert sslmode=verify-full: matches
[08:17:56.647](0.128s) ok 14 - connect with wrong server root cert sslmode=require
[08:17:56.648](0.001s) ok 15 - connect with wrong server root cert sslmode=require: matches
[08:17:56.759](0.111s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[08:17:56.760](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[08:17:56.865](0.105s) ok 18 - connect with wrong server root cert sslmode=verify-full
[08:17:56.865](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[08:17:56.943](0.078s) ok 20 - connect with server CA cert, without root CA
[08:17:56.943](0.000s) ok 21 - connect with server CA cert, without root CA: matches
[08:17:57.019](0.076s) ok 22 - connect with correct server CA cert file sslmode=require
[08:17:57.020](0.001s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[08:17:57.120](0.100s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[08:17:57.120](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[08:17:57.237](0.117s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[08:17:57.237](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[08:17:57.458](0.221s) ok 28 - cert root file that contains two certificates, order 1
[08:17:57.459](0.001s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[08:17:57.672](0.213s) ok 30 - cert root file that contains two certificates, order 2
[08:17:57.672](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[08:17:57.809](0.137s) ok 32 - connect with sslcertmode=disable
[08:17:57.809](0.000s) ok 33 - connect with sslcertmode=disable: no stderr
[08:17:57.873](0.064s) ok 34 - connect with sslcertmode=allow
[08:17:57.874](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[08:17:57.990](0.117s) ok 36 - connect with sslcertmode=require fails without a client certificate
[08:17:57.990](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[08:17:58.052](0.061s) ok 38 - sslcrl option with invalid file name
[08:17:58.052](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[08:17:58.130](0.078s) ok 40 - CRL belonging to a different CA
[08:17:58.131](0.000s) ok 41 - CRL belonging to a different CA: matches
[08:17:58.192](0.062s) ok 42 - directory CRL belonging to a different CA
[08:17:58.193](0.000s) ok 43 - directory CRL belonging to a different CA: matches
[08:17:58.326](0.133s) ok 44 - CRL with a non-revoked cert
[08:17:58.326](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[08:17:58.473](0.147s) ok 46 - directory CRL with a non-revoked cert
[08:17:58.473](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr
[08:17:58.538](0.064s) ok 48 - mismatch between host name and server certificate sslmode=require
[08:17:58.538](0.000s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[08:17:58.600](0.062s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[08:17:58.601](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[08:17:58.663](0.062s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[08:17:58.663](0.000s) ok 53 - mismatch between host name and server certificate sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 6224
[08:17:59.007](0.344s) ok 54 - IP address in the Common Name
[08:17:59.007](0.000s) ok 55 - IP address in the Common Name: no stderr
[08:17:59.070](0.063s) ok 56 - mismatch between host name and server certificate IP address
[08:17:59.070](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 5436
[08:17:59.369](0.299s) ok 58 - IP address in a dNSName
[08:17:59.369](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 5792
[08:17:59.713](0.344s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[08:17:59.714](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[08:17:59.775](0.062s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[08:17:59.776](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[08:17:59.839](0.063s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[08:17:59.839](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[08:17:59.901](0.062s) ok 66 - host name not matching with X.509 Subject Alternative Names
[08:17:59.902](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[08:17:59.964](0.062s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[08:17:59.964](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 8060
[08:18:00.324](0.360s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[08:18:00.324](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[08:18:00.385](0.062s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[08:18:00.386](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[08:18:00.448](0.062s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[08:18:00.448](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches
[08:18:00.479](0.030s) ok 76 # skip IPv6 addresses in certificates not support on this platform
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 3824
[08:18:00.823](0.345s) ok 77 - certificate with both a CN and SANs 1
[08:18:00.824](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr
[08:18:00.886](0.062s) ok 79 - certificate with both a CN and SANs 2
[08:18:00.886](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr
[08:18:00.948](0.063s) ok 81 - certificate with both a CN and SANs ignores CN
[08:18:00.949](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches
[08:18:00.978](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 6272
[08:18:01.325](0.346s) ok 84 - certificate with both an IP CN and DNS SANs matches CN
[08:18:01.325](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[08:18:01.387](0.062s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1
[08:18:01.387](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[08:18:01.450](0.062s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2
[08:18:01.450](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 6876
[08:18:01.794](0.344s) ok 90 - server certificate without CN or SANs sslmode=verify-ca
[08:18:01.794](0.001s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[08:18:01.872](0.077s) ok 92 - server certificate without CN or SANs sslmode=verify-full
[08:18:01.872](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 1820
[08:18:02.168](0.296s) ok 94 - sslrootcert=system does not connect with private CA
[08:18:02.168](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches
[08:18:02.200](0.031s) ok 96 - sslrootcert=system only accepts sslmode=verify-full
[08:18:02.200](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches
[08:18:02.309](0.109s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE
[08:18:02.310](0.001s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[08:18:02.372](0.062s) ok 100 - sslrootcert=system defaults to sslmode=verify-full
[08:18:02.372](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 7080
[08:18:02.716](0.345s) ok 102 - connects without client-side CRL
[08:18:02.717](0.000s) ok 103 - connects without client-side CRL: no stderr
[08:18:02.795](0.078s) ok 104 - does not connect with client-side CRL file
[08:18:02.796](0.001s) ok 105 - does not connect with client-side CRL file: matches
[08:18:02.873](0.077s) ok 106 - does not connect with client-side CRL directory
[08:18:02.873](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()
[08:18:02.949](0.076s) ok 108 - pg_stat_ssl view without client certificate: exit code 0
[08:18:02.949](0.000s) ok 109 - pg_stat_ssl view without client certificate: no stderr
[08:18:02.949](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches
[08:18:03.012](0.063s) ok 111 - connection success with correct range of TLS protocol versions
[08:18:03.013](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr
[08:18:03.076](0.064s) ok 113 - connection failure with incorrect range of TLS protocol versions
[08:18:03.077](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches
[08:18:03.138](0.062s) ok 115 - connection failure with an incorrect SSL protocol minimum bound
[08:18:03.139](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches
[08:18:03.201](0.062s) ok 117 - connection failure with an incorrect SSL protocol maximum bound
[08:18:03.201](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches
[08:18:03.201](0.000s) # running server tests
[08:18:03.262](0.061s) ok 119 - certificate authorization fails without client cert
[08:18:03.263](0.000s) ok 120 - certificate authorization fails without client cert: matches
[08:18:03.371](0.109s) ok 121 - certificate authorization succeeds with correct client cert in PEM format
[08:18:03.372](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[08:18:03.435](0.063s) ok 123 - certificate authorization succeeds with correct client cert in DER format
[08:18:03.435](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr
[08:18:03.498](0.062s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format
[08:18:03.498](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[08:18:03.559](0.061s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format
[08:18:03.560](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[08:18:03.622](0.063s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require
[08:18:03.622](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[08:18:03.685](0.063s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[08:18:03.685](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[08:18:03.748](0.062s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable
[08:18:03.748](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[08:18:03.810](0.062s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[08:18:03.811](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[08:18:03.920](0.109s) ok 137 - certificate authorization succeeds with DN mapping
[08:18:03.920](0.000s) ok 138 - certificate authorization succeeds with DN mapping: no stderr
[08:18:03.921](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches
[08:18:04.030](0.109s) ok 140 - certificate authorization succeeds with DN regex mapping
[08:18:04.030](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr
[08:18:04.139](0.109s) ok 142 - certificate authorization succeeds with CN mapping
[08:18:04.140](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr
[08:18:04.140](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches
[08:18:04.140](0.000s) not ok 145 # TODO & SKIP Need Pty support
[08:18:04.141](0.000s) not ok 146 # TODO & SKIP Need Pty support
[08:18:04.141](0.000s) not ok 147 # TODO & SKIP Need Pty support
[08:18:04.141](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_Q6Mk/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[08:18:04.247](0.106s) ok 149 - pg_stat_ssl with client certificate: exit code 0
[08:18:04.247](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr
[08:18:04.247](0.000s) ok 151 - pg_stat_ssl with client certificate: matches
[08:18:04.248](0.000s) ok 152 # skip Permissions check not enforced on Windows
[08:18:04.248](0.000s) ok 153 # skip Permissions check not enforced on Windows
[08:18:04.342](0.095s) ok 154 - certificate authorization fails with client cert belonging to another user
[08:18:04.343](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches
[08:18:04.405](0.062s) ok 156 - certificate authorization fails with revoked client cert
[08:18:04.405](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches
[08:18:04.406](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match
[08:18:04.514](0.109s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[08:18:04.514](0.000s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[08:18:04.515](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[08:18:04.577](0.062s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[08:18:04.577](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[08:18:04.577](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[08:18:04.640](0.062s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[08:18:04.640](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[08:18:04.641](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 3912
[08:18:04.984](0.343s) ok 168 - intermediate client certificate is provided by client
[08:18:04.984](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr
[08:18:05.046](0.061s) ok 170 - intermediate client certificate is missing
[08:18:05.046](0.000s) ok 171 - intermediate client certificate is missing: matches
[08:18:05.108](0.062s) ok 172 - logged client certificate Subjects are truncated if they're too long
[08:18:05.108](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 4528
[08:18:05.405](0.297s) ok 174 - intermediate client certificate is untrusted
[08:18:05.405](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 4004
[08:18:05.702](0.297s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory
[08:18:05.702](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[08:18:05.764](0.062s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[08:18:05.765](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 6176
[08:18:06.061](0.297s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1
[08:18:06.062](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.
[08:18:06.062](0.000s) #          got: '2'
#     expected: '0'
[08:18:06.062](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[08:18:06.062](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.
[08:18:06.062](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 51895 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: ''
[08:18:06.173](0.110s) ok 182 - connect without requesting ocsp response when sslocspstapling=0
[08:18:06.173](0.001s) ok 183 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 7360
[08:18:06.532](0.359s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1
[08:18:06.595](0.062s) ok 185 - connect without requesting ocsp response when sslocspstapling=0
[08:18:06.595](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 7032
[08:18:06.944](0.349s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1
[08:18:07.095](0.151s) ok 188 - connect without requesting ocsp response when sslocspstapling=0
[08:18:07.095](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 6436
[08:18:07.392](0.296s) ok 190 - failed with an expired ocsp response when sslocspstapling=1
[08:18:07.501](0.109s) ok 191 - connect without requesting ocsp response when sslocspstapling=0
[08:18:07.501](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 2820
[08:18:07.799](0.298s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1
[08:18:07.799](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.
[08:18:07.799](0.000s) #          got: '2'
#     expected: '0'
[08:18:07.799](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[08:18:07.800](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.
[08:18:07.800](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 51895 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: ''
[08:18:07.909](0.109s) ok 195 - connect without requesting ocsp response when sslocspstapling=0
[08:18:07.909](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 7640
[08:18:08.205](0.297s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1
[08:18:08.315](0.110s) ok 198 - connect without requesting ocsp response when sslocspstapling=0
[08:18:08.315](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 4320
[08:18:08.612](0.296s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1
[08:18:08.721](0.110s) ok 201 - connect without requesting ocsp response when sslocspstapling=0
[08:18:08.722](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 7328
[08:18:09.018](0.297s) ok 203 - failed with an expired ocsp response when sslocspstapling=1
[08:18:09.127](0.109s) ok 204 - connect without requesting ocsp response when sslocspstapling=0
[08:18:09.127](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 7384
[08:18:09.425](0.298s) ok 206 - failed with an expired ocsp response when sslocspstapling=1
[08:18:09.488](0.063s) ok 207 - connect without requesting ocsp response when sslocspstapling=0
[08:18:09.489](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-30 08:17:48.447 GMT [5096][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:48.448 GMT [5096][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:48.491 GMT [1216][startup] LOG:  database system was shut down at 2024-03-30 08:07:34 GMT
2024-03-30 08:17:48.546 GMT [5096][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:48.696 GMT [2860][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.698 GMT [2860][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-30 08:17:48.698 GMT [2860][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.717 GMT [2860][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-30 08:17:48.721 GMT [2860][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:48.851 GMT [7368][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.853 GMT [7368][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-30 08:17:48.853 GMT [7368][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.855 GMT [7368][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-30 08:17:48.856 GMT [7368][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:48.948 GMT [4044][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:48.950 GMT [4044][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-30 08:17:48.950 GMT [4044][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:48.952 GMT [4044][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-30 08:17:48.953 GMT [4044][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.024 GMT [5584][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.025 GMT [5584][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-30 08:17:49.025 GMT [5584][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.027 GMT [5584][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-30 08:17:49.028 GMT [5584][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.199 GMT [2812][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.200 GMT [2812][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-30 08:17:49.200 GMT [2812][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.204 GMT [2812][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-30 08:17:49.204 GMT [2812][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.008 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:49.340 GMT [1156][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:49.342 GMT [1156][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-30 08:17:49.342 GMT [1156][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:49.344 GMT [1156][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-30 08:17:49.706 GMT [1156][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.369 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.121 GMT [1816][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.123 GMT [1816][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-30 08:17:50.123 GMT [1816][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.125 GMT [1816][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-30 08:17:50.415 GMT [1816][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.297 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.626 GMT [6072][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.627 GMT [6072][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-30 08:17:50.627 GMT [6072][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.630 GMT [6072][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-30 08:17:50.881 GMT [6072][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.274 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:50.970 GMT [4924][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:50.971 GMT [4924][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-30 08:17:50.971 GMT [4924][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:50.976 GMT [4924][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-30 08:17:51.268 GMT [4924][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.302 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:51.470 GMT [1864][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:51.471 GMT [1864][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-30 08:17:51.471 GMT [1864][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:51.474 GMT [1864][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-30 08:17:51.714 GMT [1864][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.248 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:51.867 GMT [6952][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-30 08:17:51.869 GMT [6952][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-30 08:17:51.869 GMT [6952][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-30 08:17:51.871 GMT [6952][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-30 08:17:52.491 GMT [6952][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.626 user=SYSTEM database=postgres host=[local]
2024-03-30 08:17:52.717 GMT [5096][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:52.717 GMT [5096][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:52.736 GMT [5096][postmaster] LOG:  background worker "logical replication launcher" (PID 3836) exited with exit code 1
2024-03-30 08:17:52.739 GMT [5488][checkpointer] LOG:  shutting down
2024-03-30 08:17:52.739 GMT [5488][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:52.940 GMT [5488][checkpointer] LOG:  checkpoint complete: wrote 5536 buffers (33.8%); 0 WAL file(s) added, 0 removed, 3 recycled; write=0.193 s, sync=0.001 s, total=0.201 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/407DC68, redo lsn=0/407DC68
2024-03-30 08:17:53.034 GMT [5096][postmaster] LOG:  database system is shut down
2024-03-30 08:17:53.262 GMT [4228][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:53.263 GMT [4228][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:53.264 GMT [4228][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:53.306 GMT [236][startup] LOG:  database system was shut down at 2024-03-30 08:17:52 GMT
2024-03-30 08:17:53.331 GMT [4228][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:53.452 GMT [4228][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:53.452 GMT [4228][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:53.481 GMT [4228][postmaster] LOG:  background worker "logical replication launcher" (PID 2796) exited with exit code 1
2024-03-30 08:17:53.519 GMT [3188][checkpointer] LOG:  shutting down
2024-03-30 08:17:53.520 GMT [3188][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:53.523 GMT [3188][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/407DCE0, redo lsn=0/407DCE0
2024-03-30 08:17:53.548 GMT [4228][postmaster] LOG:  database system is shut down
2024-03-30 08:17:53.865 GMT [4840][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-30 08:17:53.865 GMT [4840][postmaster] LOG:  database system is shut down
2024-03-30 08:17:54.336 GMT [4264][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:54.336 GMT [4264][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:54.337 GMT [4264][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:54.390 GMT [5152][startup] LOG:  database system was shut down at 2024-03-30 08:17:53 GMT
2024-03-30 08:17:54.420 GMT [4264][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:54.534 GMT [4264][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:54.534 GMT [4264][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:54.565 GMT [4264][postmaster] LOG:  background worker "logical replication launcher" (PID 6216) exited with exit code 1
2024-03-30 08:17:54.582 GMT [7768][checkpointer] LOG:  shutting down
2024-03-30 08:17:54.583 GMT [7768][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:54.587 GMT [7768][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407DD58, redo lsn=0/407DD58
2024-03-30 08:17:54.603 GMT [4264][postmaster] LOG:  database system is shut down
2024-03-30 08:17:54.755 GMT [7780][postmaster] FATAL:  could not set SSL protocol version range
2024-03-30 08:17:54.755 GMT [7780][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-30 08:17:54.759 GMT [7780][postmaster] LOG:  database system is shut down
2024-03-30 08:17:55.044 GMT [6008][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:55.044 GMT [6008][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:55.046 GMT [6008][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:55.096 GMT [7888][startup] LOG:  database system was shut down at 2024-03-30 08:17:54 GMT
2024-03-30 08:17:55.158 GMT [6008][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:55.340 GMT [6008][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:55.340 GMT [6008][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:55.397 GMT [6008][postmaster] LOG:  background worker "logical replication launcher" (PID 7704) exited with exit code 1
2024-03-30 08:17:55.398 GMT [6852][checkpointer] LOG:  shutting down
2024-03-30 08:17:55.400 GMT [6852][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:55.403 GMT [6852][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407DDD0, redo lsn=0/407DDD0
2024-03-30 08:17:55.410 GMT [6008][postmaster] LOG:  database system is shut down
2024-03-30 08:17:55.646 GMT [3036][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:55.646 GMT [3036][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:55.648 GMT [3036][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:55.695 GMT [7108][startup] LOG:  database system was shut down at 2024-03-30 08:17:55 GMT
2024-03-30 08:17:55.711 GMT [3036][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:55.930 GMT [6284][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50394
2024-03-30 08:17:55.931 GMT [6284][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-30 08:17:55.931 GMT [6284][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "pg-loadbalancetest", forward lookup not checked.
2024-03-30 08:17:56.322 GMT [3540][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50396
2024-03-30 08:17:56.329 GMT [3540][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-30 08:17:56.329 GMT [3540][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-30 08:17:56.341 GMT [3540][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-30 08:17:56.343 GMT [3540][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50396
2024-03-30 08:17:56.410 GMT [5200][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50398
2024-03-30 08:17:56.418 GMT [5200][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-30 08:17:56.476 GMT [984][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50400
2024-03-30 08:17:56.488 GMT [984][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-30 08:17:56.573 GMT [3040][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50402
2024-03-30 08:17:56.579 GMT [3040][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-30 08:17:56.688 GMT [6124][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50404
2024-03-30 08:17:56.693 GMT [6124][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-30 08:17:56.803 GMT [5068][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50406
2024-03-30 08:17:56.808 GMT [5068][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-30 08:17:56.912 GMT [3896][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50408
2024-03-30 08:17:56.917 GMT [3896][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-30 08:17:57.000 GMT [960][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50410
2024-03-30 08:17:57.007 GMT [960][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-30 08:17:57.007 GMT [960][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-30 08:17:57.010 GMT [960][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-30 08:17:57.013 GMT [960][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50410
2024-03-30 08:17:57.084 GMT [5112][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50412
2024-03-30 08:17:57.091 GMT [5112][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-30 08:17:57.091 GMT [5112][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-30 08:17:57.094 GMT [5112][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-30 08:17:57.096 GMT [5112][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50412
2024-03-30 08:17:57.208 GMT [8128][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50413
2024-03-30 08:17:57.215 GMT [8128][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-30 08:17:57.215 GMT [8128][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-30 08:17:57.218 GMT [8128][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-30 08:17:57.221 GMT [8128][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50413
2024-03-30 08:17:57.321 GMT [1156][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50414
2024-03-30 08:17:57.328 GMT [1156][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-30 08:17:57.328 GMT [1156][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-30 08:17:57.331 GMT [1156][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-30 08:17:57.349 GMT [1156][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50414
2024-03-30 08:17:57.601 GMT [7140][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50415
2024-03-30 08:17:57.608 GMT [7140][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-30 08:17:57.608 GMT [7140][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-30 08:17:57.611 GMT [7140][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-30 08:17:57.615 GMT [7140][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50415
2024-03-30 08:17:57.753 GMT [6768][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50416
2024-03-30 08:17:57.760 GMT [6768][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-30 08:17:57.760 GMT [6768][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-30 08:17:57.771 GMT [6768][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-30 08:17:57.775 GMT [6768][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50416
2024-03-30 08:17:57.865 GMT [3252][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50417
2024-03-30 08:17:57.872 GMT [3252][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-30 08:17:57.872 GMT [3252][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-30 08:17:57.874 GMT [3252][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-30 08:17:57.878 GMT [3252][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50417
2024-03-30 08:17:57.927 GMT [6136][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50418
2024-03-30 08:17:57.933 GMT [6136][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-30 08:17:57.933 GMT [6136][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-30 08:17:57.947 GMT [6136][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.026 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50418
2024-03-30 08:17:58.034 GMT [7660][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50419
2024-03-30 08:17:58.041 GMT [7660][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-30 08:17:58.041 GMT [7660][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-30 08:17:58.044 GMT [7660][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-30 08:17:58.047 GMT [7660][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50419
2024-03-30 08:17:58.092 GMT [920][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50420
2024-03-30 08:17:58.097 GMT [920][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-30 08:17:58.173 GMT [6804][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50421
2024-03-30 08:17:58.178 GMT [6804][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-30 08:17:58.241 GMT [3100][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50422
2024-03-30 08:17:58.247 GMT [3100][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-30 08:17:58.247 GMT [3100][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-30 08:17:58.250 GMT [3100][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-30 08:17:58.255 GMT [3100][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50422
2024-03-30 08:17:58.414 GMT [5344][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50423
2024-03-30 08:17:58.421 GMT [5344][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-30 08:17:58.421 GMT [5344][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-30 08:17:58.423 GMT [5344][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-30 08:17:58.428 GMT [5344][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.035 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50423
2024-03-30 08:17:58.516 GMT [4280][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50424
2024-03-30 08:17:58.523 GMT [4280][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-30 08:17:58.523 GMT [4280][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-30 08:17:58.526 GMT [4280][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-30 08:17:58.528 GMT [4280][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50424
2024-03-30 08:17:58.576 GMT [5324][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50425
2024-03-30 08:17:58.583 GMT [5324][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-30 08:17:58.583 GMT [5324][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-30 08:17:58.586 GMT [5324][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-30 08:17:58.588 GMT [5324][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50425
2024-03-30 08:17:58.641 GMT [6652][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50426
2024-03-30 08:17:58.678 GMT [3036][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:58.678 GMT [3036][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:58.683 GMT [3036][postmaster] LOG:  background worker "logical replication launcher" (PID 6252) exited with exit code 1
2024-03-30 08:17:58.683 GMT [7548][checkpointer] LOG:  shutting down
2024-03-30 08:17:58.683 GMT [7548][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:58.686 GMT [7548][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/407DE48, redo lsn=0/407DE48
2024-03-30 08:17:58.691 GMT [3036][postmaster] LOG:  database system is shut down
2024-03-30 08:17:58.842 GMT [6224][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:58.842 GMT [6224][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:58.844 GMT [6224][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:58.862 GMT [4892][startup] LOG:  database system was shut down at 2024-03-30 08:17:58 GMT
2024-03-30 08:17:58.869 GMT [6224][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:58.940 GMT [3884][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50427
2024-03-30 08:17:58.947 GMT [3884][client backend] [[unknown]][0/1:0] LOG:  connection authenticated: user="ssltestuser" method=trust (C:/cirrus/build/testrun/ssl/001_ssltests/data/t_001_ssltests_primary_data/pgdata/pg_hba.conf:3)
2024-03-30 08:17:58.947 GMT [3884][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384, bits=256)
2024-03-30 08:17:58.960 GMT [3884][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SELECT $$connected with sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full host=192.0.2.1$$
2024-03-30 08:17:58.962 GMT [3884][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50427
2024-03-30 08:17:59.046 GMT [7356][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50428
2024-03-30 08:17:59.085 GMT [6224][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:59.085 GMT [6224][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:59.089 GMT [6224][postmaster] LOG:  background worker "logical replication launcher" (PID 1688) exited with exit code 1
2024-03-30 08:17:59.089 GMT [4496][checkpointer] LOG:  shutting down
2024-03-30 08:17:59.089 GMT [4496][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:59.092 GMT [4496][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/407DEC0, redo lsn=0/407DEC0
2024-03-30 08:17:59.097 GMT [6224][postmaster] LOG:  database system is shut down
2024-03-30 08:17:59.251 GMT [5436][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:59.251 GMT [5436][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:59.252 GMT [5436][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:59.279 GMT [6576][startup] LOG:  database system was shut down at 2024-03-30 08:17:59 GMT
2024-03-30 08:17:59.285 GMT [5436][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:59.344 GMT [584][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50429
2024-03-30 08:17:59.350 GMT [584][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-30 08:17:59.350 GMT [584][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-30 08:17:59.362 GMT [584][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-30 08:17:59.365 GMT [584][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50429
2024-03-30 08:17:59.383 GMT [5436][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:59.383 GMT [5436][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:59.385 GMT [5436][postmaster] LOG:  background worker "logical replication launcher" (PID 5500) exited with exit code 1
2024-03-30 08:17:59.387 GMT [4184][checkpointer] LOG:  shutting down
2024-03-30 08:17:59.387 GMT [4184][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:59.390 GMT [4184][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/407DF38, redo lsn=0/407DF38
2024-03-30 08:17:59.394 GMT [5436][postmaster] LOG:  database system is shut down
2024-03-30 08:17:59.546 GMT [5792][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:17:59.546 GMT [5792][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:17:59.547 GMT [5792][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:17:59.574 GMT [2500][startup] LOG:  database system was shut down at 2024-03-30 08:17:59 GMT
2024-03-30 08:17:59.581 GMT [5792][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:17:59.646 GMT [2508][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50430
2024-03-30 08:17:59.653 GMT [2508][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-30 08:17:59.653 GMT [2508][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-30 08:17:59.666 GMT [2508][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-30 08:17:59.669 GMT [2508][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50430
2024-03-30 08:17:59.758 GMT [4132][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50431
2024-03-30 08:17:59.766 GMT [4132][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-30 08:17:59.766 GMT [4132][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-30 08:17:59.769 GMT [4132][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-30 08:17:59.772 GMT [4132][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50431
2024-03-30 08:17:59.820 GMT [1412][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50432
2024-03-30 08:17:59.827 GMT [1412][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-30 08:17:59.827 GMT [1412][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-30 08:17:59.830 GMT [1412][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-30 08:17:59.833 GMT [1412][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50432
2024-03-30 08:17:59.883 GMT [4288][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50433
2024-03-30 08:17:59.940 GMT [5652][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50434
2024-03-30 08:17:59.979 GMT [5792][postmaster] LOG:  received fast shutdown request
2024-03-30 08:17:59.980 GMT [5792][postmaster] LOG:  aborting any active transactions
2024-03-30 08:17:59.983 GMT [5792][postmaster] LOG:  background worker "logical replication launcher" (PID 7884) exited with exit code 1
2024-03-30 08:17:59.984 GMT [2800][checkpointer] LOG:  shutting down
2024-03-30 08:17:59.984 GMT [2800][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:17:59.987 GMT [2800][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/407DFB0, redo lsn=0/407DFB0
2024-03-30 08:17:59.991 GMT [5792][postmaster] LOG:  database system is shut down
2024-03-30 08:18:00.142 GMT [8060][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:00.143 GMT [8060][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:00.144 GMT [8060][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:00.177 GMT [5128][startup] LOG:  database system was shut down at 2024-03-30 08:17:59 GMT
2024-03-30 08:18:00.187 GMT [8060][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:00.255 GMT [7604][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50435
2024-03-30 08:18:00.262 GMT [7604][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-30 08:18:00.262 GMT [7604][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-30 08:18:00.274 GMT [7604][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-30 08:18:00.277 GMT [7604][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50435
2024-03-30 08:18:00.365 GMT [5248][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50436
2024-03-30 08:18:00.422 GMT [4668][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50437
2024-03-30 08:18:00.495 GMT [8060][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:00.495 GMT [8060][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:00.500 GMT [8060][postmaster] LOG:  background worker "logical replication launcher" (PID 7324) exited with exit code 1
2024-03-30 08:18:00.500 GMT [560][checkpointer] LOG:  shutting down
2024-03-30 08:18:00.500 GMT [560][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:00.505 GMT [560][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.005 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407E040, redo lsn=0/407E040
2024-03-30 08:18:00.509 GMT [8060][postmaster] LOG:  database system is shut down
2024-03-30 08:18:00.656 GMT [3824][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:00.656 GMT [3824][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:00.657 GMT [3824][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:00.676 GMT [7528][startup] LOG:  database system was shut down at 2024-03-30 08:18:00 GMT
2024-03-30 08:18:00.683 GMT [3824][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:00.756 GMT [6380][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50438
2024-03-30 08:18:00.763 GMT [6380][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-30 08:18:00.763 GMT [6380][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-30 08:18:00.775 GMT [6380][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-30 08:18:00.777 GMT [6380][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50438
2024-03-30 08:18:00.865 GMT [5004][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50439
2024-03-30 08:18:00.871 GMT [5004][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-30 08:18:00.871 GMT [5004][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-30 08:18:00.874 GMT [5004][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-30 08:18:00.876 GMT [5004][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.018 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50439
2024-03-30 08:18:00.924 GMT [3876][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50440
2024-03-30 08:18:00.993 GMT [3824][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:00.993 GMT [3824][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:00.997 GMT [3824][postmaster] LOG:  background worker "logical replication launcher" (PID 6436) exited with exit code 1
2024-03-30 08:18:00.998 GMT [7160][checkpointer] LOG:  shutting down
2024-03-30 08:18:00.998 GMT [7160][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:01.001 GMT [7160][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/407E0B8, redo lsn=0/407E0B8
2024-03-30 08:18:01.005 GMT [3824][postmaster] LOG:  database system is shut down
2024-03-30 08:18:01.159 GMT [6272][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:01.159 GMT [6272][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:01.160 GMT [6272][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:01.187 GMT [5996][startup] LOG:  database system was shut down at 2024-03-30 08:18:00 GMT
2024-03-30 08:18:01.194 GMT [6272][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:01.254 GMT [7108][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50441
2024-03-30 08:18:01.261 GMT [7108][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-30 08:18:01.261 GMT [7108][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-30 08:18:01.273 GMT [7108][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-30 08:18:01.275 GMT [7108][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50441
2024-03-30 08:18:01.366 GMT [7744][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50442
2024-03-30 08:18:01.372 GMT [7744][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-30 08:18:01.372 GMT [7744][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-30 08:18:01.375 GMT [7744][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-30 08:18:01.377 GMT [7744][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50442
2024-03-30 08:18:01.426 GMT [1716][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50443
2024-03-30 08:18:01.433 GMT [1716][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-30 08:18:01.433 GMT [1716][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-30 08:18:01.435 GMT [1716][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-30 08:18:01.437 GMT [1716][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.017 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50443
2024-03-30 08:18:01.465 GMT [6272][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:01.465 GMT [6272][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:01.468 GMT [6272][postmaster] LOG:  background worker "logical replication launcher" (PID 5180) exited with exit code 1
2024-03-30 08:18:01.469 GMT [1524][checkpointer] LOG:  shutting down
2024-03-30 08:18:01.469 GMT [1524][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:01.472 GMT [1524][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/407E130, redo lsn=0/407E130
2024-03-30 08:18:01.476 GMT [6272][postmaster] LOG:  database system is shut down
2024-03-30 08:18:01.624 GMT [6876][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:01.625 GMT [6876][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:01.626 GMT [6876][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:01.644 GMT [4840][startup] LOG:  database system was shut down at 2024-03-30 08:18:01 GMT
2024-03-30 08:18:01.651 GMT [6876][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:01.726 GMT [7276][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50444
2024-03-30 08:18:01.732 GMT [7276][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-30 08:18:01.732 GMT [7276][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-30 08:18:01.745 GMT [7276][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-30 08:18:01.748 GMT [7276][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50444
2024-03-30 08:18:01.836 GMT [6696][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50445
2024-03-30 08:18:01.887 GMT [6876][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:01.887 GMT [6876][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:01.890 GMT [6876][postmaster] LOG:  background worker "logical replication launcher" (PID 5812) exited with exit code 1
2024-03-30 08:18:01.891 GMT [5732][checkpointer] LOG:  shutting down
2024-03-30 08:18:01.891 GMT [5732][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:01.894 GMT [5732][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/407E1A8, redo lsn=0/407E1A8
2024-03-30 08:18:01.899 GMT [6876][postmaster] LOG:  database system is shut down
2024-03-30 08:18:02.046 GMT [1820][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:02.046 GMT [1820][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:02.047 GMT [1820][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:02.065 GMT [4272][startup] LOG:  database system was shut down at 2024-03-30 08:18:01 GMT
2024-03-30 08:18:02.071 GMT [1820][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:02.143 GMT [2372][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50446
2024-03-30 08:18:02.148 GMT [2372][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-30 08:18:02.239 GMT [7460][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50447
2024-03-30 08:18:02.246 GMT [7460][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-30 08:18:02.246 GMT [7460][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-30 08:18:02.259 GMT [7460][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-30 08:18:02.261 GMT [7460][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-30 08:18:02.348 GMT [2348][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50448
2024-03-30 08:18:02.386 GMT [1820][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:02.387 GMT [1820][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:02.391 GMT [1820][postmaster] LOG:  background worker "logical replication launcher" (PID 6156) exited with exit code 1
2024-03-30 08:18:02.391 GMT [7904][checkpointer] LOG:  shutting down
2024-03-30 08:18:02.391 GMT [7904][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:02.394 GMT [7904][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/407E220, redo lsn=0/407E220
2024-03-30 08:18:02.398 GMT [1820][postmaster] LOG:  database system is shut down
2024-03-30 08:18:02.562 GMT [7080][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:02.562 GMT [7080][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:02.564 GMT [7080][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:02.584 GMT [2088][startup] LOG:  database system was shut down at 2024-03-30 08:18:02 GMT
2024-03-30 08:18:02.592 GMT [7080][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:02.650 GMT [628][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50449
2024-03-30 08:18:02.657 GMT [628][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-30 08:18:02.657 GMT [628][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-30 08:18:02.670 GMT [628][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-30 08:18:02.672 GMT [628][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-30 08:18:02.758 GMT [5384][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50450
2024-03-30 08:18:02.764 GMT [5384][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-30 08:18:02.839 GMT [5980][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50451
2024-03-30 08:18:02.846 GMT [5980][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-30 08:18:02.912 GMT [7076][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50452
2024-03-30 08:18:02.921 GMT [7076][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-30 08:18:02.921 GMT [7076][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-30 08:18:02.924 GMT [7076][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-30 08:18:02.930 GMT [7076][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50452
2024-03-30 08:18:02.996 GMT [3480][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50453
2024-03-30 08:18:03.002 GMT [3480][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-30 08:18:03.002 GMT [3480][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-30 08:18:03.005 GMT [3480][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-30 08:18:03.008 GMT [3480][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.019 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50453
2024-03-30 08:18:03.240 GMT [4940][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50454
2024-03-30 08:18:03.247 GMT [4940][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-03-30 08:18:03.302 GMT [6368][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50455
2024-03-30 08:18:03.311 GMT [6368][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-30 08:18:03.311 GMT [6368][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-30 08:18:03.324 GMT [6368][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_Q6Mk/client.key$$
2024-03-30 08:18:03.326 GMT [6368][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb host=pg-loadbalancetest port=50455
2024-03-30 08:18:03.414 GMT [1904][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50456
2024-03-30 08:18:03.423 GMT [1904][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-30 08:18:03.423 GMT [1904][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-30 08:18:03.426 GMT [1904][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_Q6Mk/client-der.key$$
2024-03-30 08:18:03.428 GMT [1904][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50456
2024-03-30 08:18:03.474 GMT [7428][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50457
2024-03-30 08:18:03.484 GMT [7428][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-30 08:18:03.484 GMT [7428][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-30 08:18:03.487 GMT [7428][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_Q6Mk/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-03-30 08:18:03.489 GMT [7428][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50457
2024-03-30 08:18:03.539 GMT [7228][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50458
2024-03-30 08:18:03.547 GMT [7228][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-30 08:18:03.547 GMT [7228][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-30 08:18:03.550 GMT [7228][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_Q6Mk/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-03-30 08:18:03.552 GMT [7228][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50458
2024-03-30 08:18:03.599 GMT [5132][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50459
2024-03-30 08:18:03.607 GMT [5132][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-30 08:18:03.607 GMT [5132][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-30 08:18:03.610 GMT [5132][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_Q6Mk/client.key$$
2024-03-30 08:18:03.612 GMT [5132][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=certdb host=pg-loadbalancetest port=50459
2024-03-30 08:18:03.662 GMT [7424][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50460
2024-03-30 08:18:03.671 GMT [7424][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-30 08:18:03.671 GMT [7424][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-30 08:18:03.674 GMT [7424][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_Q6Mk/client.key$$
2024-03-30 08:18:03.676 GMT [7424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50460
2024-03-30 08:18:03.724 GMT [6448][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50461
2024-03-30 08:18:03.731 GMT [6448][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-03-30 08:18:03.787 GMT [4168][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50462
2024-03-30 08:18:03.797 GMT [4168][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-30 08:18:03.851 GMT [1788][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50463
2024-03-30 08:18:03.859 GMT [1788][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-30 08:18:03.860 GMT [1788][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-30 08:18:03.872 GMT [1788][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_Q6Mk/client-dn.key$$
2024-03-30 08:18:03.874 GMT [1788][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50463
2024-03-30 08:18:03.962 GMT [6676][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50464
2024-03-30 08:18:03.971 GMT [6676][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-30 08:18:03.971 GMT [6676][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-30 08:18:03.984 GMT [6676][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_Q6Mk/client-dn.key$$
2024-03-30 08:18:03.986 GMT [6676][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50464
2024-03-30 08:18:04.069 GMT [812][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50465
2024-03-30 08:18:04.078 GMT [812][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-30 08:18:04.078 GMT [812][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-30 08:18:04.090 GMT [812][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_Q6Mk/client-dn.key$$
2024-03-30 08:18:04.092 GMT [812][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50465
2024-03-30 08:18:04.184 GMT [6084][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50466
2024-03-30 08:18:04.193 GMT [6084][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-30 08:18:04.193 GMT [6084][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-30 08:18:04.196 GMT [6084][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-30 08:18:04.200 GMT [6084][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=certdb host=pg-loadbalancetest port=50466
2024-03-30 08:18:04.322 GMT [6716][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50467
2024-03-30 08:18:04.331 GMT [6716][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-30 08:18:04.331 GMT [6716][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-30 08:18:04.331 GMT [6716][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-03-30 08:18:04.331 GMT [6716][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-30 08:18:04.380 GMT [2952][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50468
2024-03-30 08:18:04.387 GMT [2952][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-30 08:18:04.387 GMT [2952][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-30 08:18:04.443 GMT [6364][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50469
2024-03-30 08:18:04.452 GMT [6364][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-30 08:18:04.452 GMT [6364][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-30 08:18:04.464 GMT [6364][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_Q6Mk/client.key$$
2024-03-30 08:18:04.467 GMT [6364][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50469
2024-03-30 08:18:04.551 GMT [6912][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50470
2024-03-30 08:18:04.560 GMT [6912][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-30 08:18:04.560 GMT [6912][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-03-30 08:18:04.560 GMT [6912][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-03-30 08:18:04.560 GMT [6912][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-30 08:18:04.618 GMT [6512][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50471
2024-03-30 08:18:04.627 GMT [6512][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-30 08:18:04.627 GMT [6512][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-30 08:18:04.630 GMT [6512][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_Q6Mk/client.key$$
2024-03-30 08:18:04.632 GMT [6512][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50471
2024-03-30 08:18:04.657 GMT [7080][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:04.658 GMT [7080][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:04.661 GMT [7080][postmaster] LOG:  background worker "logical replication launcher" (PID 6124) exited with exit code 1
2024-03-30 08:18:04.662 GMT [3648][checkpointer] LOG:  shutting down
2024-03-30 08:18:04.662 GMT [3648][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:04.665 GMT [3648][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/407E298, redo lsn=0/407E298
2024-03-30 08:18:04.669 GMT [7080][postmaster] LOG:  database system is shut down
2024-03-30 08:18:04.817 GMT [3912][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:04.817 GMT [3912][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:04.818 GMT [3912][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:04.839 GMT [7548][startup] LOG:  database system was shut down at 2024-03-30 08:18:04 GMT
2024-03-30 08:18:04.846 GMT [3912][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:04.916 GMT [5260][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50472
2024-03-30 08:18:04.925 GMT [5260][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-30 08:18:04.925 GMT [5260][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-30 08:18:04.938 GMT [5260][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_Q6Mk/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-30 08:18:04.940 GMT [5260][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=certdb host=pg-loadbalancetest port=50472
2024-03-30 08:18:05.024 GMT [4580][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50473
2024-03-30 08:18:05.031 GMT [4580][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-30 08:18:05.031 GMT [4580][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-30 08:18:05.083 GMT [7376][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50474
2024-03-30 08:18:05.090 GMT [7376][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-30 08:18:05.090 GMT [7376][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-30 08:18:05.124 GMT [3912][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:05.124 GMT [3912][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:05.127 GMT [3912][postmaster] LOG:  background worker "logical replication launcher" (PID 4960) exited with exit code 1
2024-03-30 08:18:05.128 GMT [5868][checkpointer] LOG:  shutting down
2024-03-30 08:18:05.128 GMT [5868][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:05.131 GMT [5868][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/407E310, redo lsn=0/407E310
2024-03-30 08:18:05.136 GMT [3912][postmaster] LOG:  database system is shut down
2024-03-30 08:18:05.284 GMT [4528][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:05.284 GMT [4528][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:05.285 GMT [4528][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:05.308 GMT [2488][startup] LOG:  database system was shut down at 2024-03-30 08:18:05 GMT
2024-03-30 08:18:05.315 GMT [4528][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:05.381 GMT [584][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50475
2024-03-30 08:18:05.388 GMT [584][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-30 08:18:05.388 GMT [584][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-30 08:18:05.421 GMT [4528][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:05.421 GMT [4528][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:05.425 GMT [4528][postmaster] LOG:  background worker "logical replication launcher" (PID 5204) exited with exit code 1
2024-03-30 08:18:05.425 GMT [7912][checkpointer] LOG:  shutting down
2024-03-30 08:18:05.426 GMT [7912][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:05.429 GMT [7912][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/407E388, redo lsn=0/407E388
2024-03-30 08:18:05.433 GMT [4528][postmaster] LOG:  database system is shut down
2024-03-30 08:18:05.579 GMT [4004][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:05.579 GMT [4004][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:05.580 GMT [4004][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:05.598 GMT [1776][startup] LOG:  database system was shut down at 2024-03-30 08:18:05 GMT
2024-03-30 08:18:05.605 GMT [4004][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:05.684 GMT [3604][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50476
2024-03-30 08:18:05.692 GMT [3604][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-30 08:18:05.692 GMT [3604][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-30 08:18:05.738 GMT [4684][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50477
2024-03-30 08:18:05.745 GMT [4684][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-30 08:18:05.745 GMT [4684][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-30 08:18:05.779 GMT [4004][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:05.779 GMT [4004][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:05.782 GMT [4004][postmaster] LOG:  background worker "logical replication launcher" (PID 6276) exited with exit code 1
2024-03-30 08:18:05.783 GMT [2448][checkpointer] LOG:  shutting down
2024-03-30 08:18:05.783 GMT [2448][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:05.786 GMT [2448][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/407E400, redo lsn=0/407E400
2024-03-30 08:18:05.790 GMT [4004][postmaster] LOG:  database system is shut down
2024-03-30 08:18:05.939 GMT [6176][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:05.940 GMT [6176][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:05.941 GMT [6176][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:05.965 GMT [2416][startup] LOG:  database system was shut down at 2024-03-30 08:18:05 GMT
2024-03-30 08:18:05.973 GMT [6176][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:06.040 GMT [6880][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50478
2024-03-30 08:18:06.043 GMT [6880][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:06.043 GMT [6880][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:06.104 GMT [7152][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50479
2024-03-30 08:18:06.111 GMT [7152][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-30 08:18:06.111 GMT [7152][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-30 08:18:06.124 GMT [7152][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-30 08:18:06.126 GMT [7152][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50479
2024-03-30 08:18:06.189 GMT [6176][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:06.189 GMT [6176][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:06.195 GMT [6176][postmaster] LOG:  background worker "logical replication launcher" (PID 8184) exited with exit code 1
2024-03-30 08:18:06.196 GMT [1568][checkpointer] LOG:  shutting down
2024-03-30 08:18:06.196 GMT [1568][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:06.199 GMT [1568][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/407E478, redo lsn=0/407E478
2024-03-30 08:18:06.204 GMT [6176][postmaster] LOG:  database system is shut down
2024-03-30 08:18:06.404 GMT [7360][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:06.404 GMT [7360][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:06.405 GMT [7360][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:06.424 GMT [3848][startup] LOG:  database system was shut down at 2024-03-30 08:18:06 GMT
2024-03-30 08:18:06.431 GMT [7360][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:06.508 GMT [8164][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50480
2024-03-30 08:18:06.511 GMT [8164][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:06.512 GMT [8164][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:06.570 GMT [5704][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50481
2024-03-30 08:18:06.576 GMT [5704][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-30 08:18:06.576 GMT [5704][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-30 08:18:06.589 GMT [5704][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-30 08:18:06.591 GMT [5704][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50481
2024-03-30 08:18:06.610 GMT [7360][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:06.610 GMT [7360][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:06.613 GMT [7360][postmaster] LOG:  background worker "logical replication launcher" (PID 7064) exited with exit code 1
2024-03-30 08:18:06.614 GMT [7332][checkpointer] LOG:  shutting down
2024-03-30 08:18:06.614 GMT [7332][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:06.617 GMT [7332][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/407E4F0, redo lsn=0/407E4F0
2024-03-30 08:18:06.621 GMT [7360][postmaster] LOG:  database system is shut down
2024-03-30 08:18:06.768 GMT [7032][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:06.769 GMT [7032][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:06.770 GMT [7032][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:06.787 GMT [6852][startup] LOG:  database system was shut down at 2024-03-30 08:18:06 GMT
2024-03-30 08:18:06.794 GMT [7032][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:06.867 GMT [5492][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50482
2024-03-30 08:18:06.870 GMT [5492][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:06.870 GMT [5492][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:07.007 GMT [4444][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50483
2024-03-30 08:18:07.014 GMT [4444][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-30 08:18:07.014 GMT [4444][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-30 08:18:07.026 GMT [4444][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-30 08:18:07.038 GMT [4444][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.039 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50483
2024-03-30 08:18:07.111 GMT [7032][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:07.112 GMT [7032][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:07.118 GMT [7032][postmaster] LOG:  background worker "logical replication launcher" (PID 2476) exited with exit code 1
2024-03-30 08:18:07.118 GMT [7808][checkpointer] LOG:  shutting down
2024-03-30 08:18:07.118 GMT [7808][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:07.121 GMT [7808][checkpointer] LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/407E568, redo lsn=0/407E568
2024-03-30 08:18:07.125 GMT [7032][postmaster] LOG:  database system is shut down
2024-03-30 08:18:07.270 GMT [6436][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:07.270 GMT [6436][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:07.271 GMT [6436][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:07.289 GMT [1240][startup] LOG:  database system was shut down at 2024-03-30 08:18:07 GMT
2024-03-30 08:18:07.296 GMT [6436][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:07.370 GMT [3512][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50484
2024-03-30 08:18:07.373 GMT [3512][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:07.373 GMT [3512][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:07.430 GMT [4056][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50485
2024-03-30 08:18:07.437 GMT [4056][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-30 08:18:07.437 GMT [4056][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-30 08:18:07.450 GMT [4056][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-30 08:18:07.453 GMT [4056][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50485
2024-03-30 08:18:07.517 GMT [6436][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:07.517 GMT [6436][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:07.521 GMT [6436][postmaster] LOG:  background worker "logical replication launcher" (PID 7500) exited with exit code 1
2024-03-30 08:18:07.521 GMT [7236][checkpointer] LOG:  shutting down
2024-03-30 08:18:07.521 GMT [7236][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:07.524 GMT [7236][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/407E5E0, redo lsn=0/407E5E0
2024-03-30 08:18:07.528 GMT [6436][postmaster] LOG:  database system is shut down
2024-03-30 08:18:07.673 GMT [2820][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:07.673 GMT [2820][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:07.674 GMT [2820][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:07.691 GMT [5688][startup] LOG:  database system was shut down at 2024-03-30 08:18:07 GMT
2024-03-30 08:18:07.698 GMT [2820][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:07.775 GMT [2696][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50486
2024-03-30 08:18:07.778 GMT [2696][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:07.778 GMT [2696][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:07.838 GMT [7800][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50487
2024-03-30 08:18:07.845 GMT [7800][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-30 08:18:07.845 GMT [7800][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-30 08:18:07.857 GMT [7800][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-30 08:18:07.859 GMT [7800][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50487
2024-03-30 08:18:07.923 GMT [2820][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:07.923 GMT [2820][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:07.926 GMT [2820][postmaster] LOG:  background worker "logical replication launcher" (PID 7636) exited with exit code 1
2024-03-30 08:18:07.926 GMT [6284][checkpointer] LOG:  shutting down
2024-03-30 08:18:07.926 GMT [6284][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:07.929 GMT [6284][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/407E658, redo lsn=0/407E658
2024-03-30 08:18:07.933 GMT [2820][postmaster] LOG:  database system is shut down
2024-03-30 08:18:08.080 GMT [7640][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:08.081 GMT [7640][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:08.082 GMT [7640][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:08.099 GMT [5884][startup] LOG:  database system was shut down at 2024-03-30 08:18:07 GMT
2024-03-30 08:18:08.106 GMT [7640][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:08.186 GMT [272][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50488
2024-03-30 08:18:08.189 GMT [272][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:08.189 GMT [272][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:08.246 GMT [6784][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50489
2024-03-30 08:18:08.252 GMT [6784][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-30 08:18:08.252 GMT [6784][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-30 08:18:08.264 GMT [6784][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-30 08:18:08.267 GMT [6784][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50489
2024-03-30 08:18:08.331 GMT [7640][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:08.331 GMT [7640][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:08.335 GMT [7640][postmaster] LOG:  background worker "logical replication launcher" (PID 6960) exited with exit code 1
2024-03-30 08:18:08.336 GMT [1520][checkpointer] LOG:  shutting down
2024-03-30 08:18:08.336 GMT [1520][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:08.339 GMT [1520][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/407E6D0, redo lsn=0/407E6D0
2024-03-30 08:18:08.343 GMT [7640][postmaster] LOG:  database system is shut down
2024-03-30 08:18:08.492 GMT [4320][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:08.492 GMT [4320][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:08.494 GMT [4320][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:08.512 GMT [4436][startup] LOG:  database system was shut down at 2024-03-30 08:18:08 GMT
2024-03-30 08:18:08.518 GMT [4320][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:08.588 GMT [7732][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50490
2024-03-30 08:18:08.591 GMT [7732][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:08.592 GMT [7732][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:08.650 GMT [3116][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50491
2024-03-30 08:18:08.656 GMT [3116][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-30 08:18:08.656 GMT [3116][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-30 08:18:08.670 GMT [3116][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-30 08:18:08.673 GMT [3116][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50491
2024-03-30 08:18:08.737 GMT [4320][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:08.737 GMT [4320][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:08.740 GMT [4320][postmaster] LOG:  background worker "logical replication launcher" (PID 6988) exited with exit code 1
2024-03-30 08:18:08.741 GMT [5756][checkpointer] LOG:  shutting down
2024-03-30 08:18:08.741 GMT [5756][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:08.744 GMT [5756][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/407E748, redo lsn=0/407E748
2024-03-30 08:18:08.749 GMT [4320][postmaster] LOG:  database system is shut down
2024-03-30 08:18:08.895 GMT [7328][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:08.895 GMT [7328][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:08.896 GMT [7328][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:08.914 GMT [7600][startup] LOG:  database system was shut down at 2024-03-30 08:18:08 GMT
2024-03-30 08:18:08.921 GMT [7328][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:08.996 GMT [6172][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50492
2024-03-30 08:18:08.999 GMT [6172][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:08.999 GMT [6172][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:09.061 GMT [6584][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50493
2024-03-30 08:18:09.068 GMT [6584][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-30 08:18:09.068 GMT [6584][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-30 08:18:09.079 GMT [6584][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-30 08:18:09.082 GMT [6584][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50493
2024-03-30 08:18:09.144 GMT [7328][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:09.144 GMT [7328][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:09.148 GMT [7328][postmaster] LOG:  background worker "logical replication launcher" (PID 3836) exited with exit code 1
2024-03-30 08:18:09.148 GMT [5152][checkpointer] LOG:  shutting down
2024-03-30 08:18:09.148 GMT [5152][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:09.151 GMT [5152][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/407E7C0, redo lsn=0/407E7C0
2024-03-30 08:18:09.155 GMT [7328][postmaster] LOG:  database system is shut down
2024-03-30 08:18:09.300 GMT [7384][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-30 08:18:09.300 GMT [7384][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 51895
2024-03-30 08:18:09.301 GMT [7384][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/TDq25dOw8O/.s.PGSQL.51895"
2024-03-30 08:18:09.330 GMT [1756][startup] LOG:  database system was shut down at 2024-03-30 08:18:09 GMT
2024-03-30 08:18:09.337 GMT [7384][postmaster] LOG:  database system is ready to accept connections
2024-03-30 08:18:09.404 GMT [2316][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50494
2024-03-30 08:18:09.407 GMT [2316][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-30 08:18:09.408 GMT [2316][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-30 08:18:09.464 GMT [3468][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50495
2024-03-30 08:18:09.471 GMT [3468][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-30 08:18:09.471 GMT [3468][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-30 08:18:09.484 GMT [3468][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-30 08:18:09.486 GMT [3468][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50495
2024-03-30 08:18:09.504 GMT [7384][postmaster] LOG:  received fast shutdown request
2024-03-30 08:18:09.504 GMT [7384][postmaster] LOG:  aborting any active transactions
2024-03-30 08:18:09.507 GMT [7384][postmaster] LOG:  background worker "logical replication launcher" (PID 5132) exited with exit code 1
2024-03-30 08:18:09.508 GMT [3192][checkpointer] LOG:  shutting down
2024-03-30 08:18:09.508 GMT [3192][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-30 08:18:09.510 GMT [3192][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/407E838, redo lsn=0/407E838
2024-03-30 08:18:09.515 GMT [7384][postmaster] LOG:  database system is shut down
2024-03-30 08:18:09.655 GMT [5420][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-03-30 08:18:09.655 GMT [5420][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[08:18:09.723](0.234s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"