[13:58:35.400](0.154s) # setting up data directory
# Checking port 63919
# Found port 63919
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=63919 host=C:/Windows/TEMP/Gn9eQm77zV
Log file: C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log
[13:58:35.540](0.140s) # 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 7364
[13:58:37.452](1.912s) 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 8116
[13:58:42.788](5.336s) # 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-22 13:58:36.881 GMT [7364][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:36.882 GMT [7364][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:36.980 GMT [7128][startup] LOG:  database system was shut down at 2024-03-22 13:47:57 GMT
2024-03-22 13:58:37.033 GMT [7364][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:37.344 GMT [4956][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.346 GMT [4956][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-22 13:58:37.346 GMT [4956][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.374 GMT [4956][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-22 13:58:37.381 GMT [4956][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.040 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.647 GMT [1400][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.648 GMT [1400][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-22 13:58:37.648 GMT [1400][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.651 GMT [1400][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-22 13:58:37.652 GMT [1400][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.792 GMT [7548][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.794 GMT [7548][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-22 13:58:37.794 GMT [7548][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.797 GMT [7548][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-22 13:58:37.798 GMT [7548][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.941 GMT [3628][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.943 GMT [3628][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-22 13:58:37.943 GMT [3628][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.965 GMT [3628][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-22 13:58:37.967 GMT [3628][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:38.508 GMT [6400][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:38.509 GMT [6400][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-22 13:58:38.509 GMT [6400][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:38.511 GMT [6400][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-22 13:58:38.512 GMT [6400][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:38.716 GMT [3424][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:38.717 GMT [3424][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-22 13:58:38.717 GMT [3424][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:38.720 GMT [3424][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-22 13:58:38.944 GMT [3424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.231 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:39.060 GMT [6968][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:39.061 GMT [6968][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-22 13:58:39.061 GMT [6968][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:39.064 GMT [6968][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-22 13:58:39.294 GMT [6968][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.237 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:39.617 GMT [7436][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:39.618 GMT [7436][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-22 13:58:39.618 GMT [7436][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:39.621 GMT [7436][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-22 13:58:39.884 GMT [7436][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.270 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:40.062 GMT [4684][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:40.064 GMT [4684][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-22 13:58:40.064 GMT [4684][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:40.067 GMT [4684][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-22 13:58:40.412 GMT [4684][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.353 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:40.550 GMT [4264][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:40.552 GMT [4264][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-22 13:58:40.552 GMT [4264][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:40.596 GMT [4264][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-22 13:58:40.800 GMT [4264][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.253 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:41.092 GMT [7652][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:41.093 GMT [7652][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-22 13:58:41.093 GMT [7652][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:41.113 GMT [7652][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-22 13:58:41.476 GMT [7652][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.387 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:41.558 GMT [7364][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:41.559 GMT [7364][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:41.576 GMT [7364][postmaster] LOG:  background worker "logical replication launcher" (PID 6584) exited with exit code 1
2024-03-22 13:58:41.582 GMT [7636][checkpointer] LOG:  shutting down
2024-03-22 13:58:41.582 GMT [7636][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:41.784 GMT [7636][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.203 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/4080918, redo lsn=0/4080918
2024-03-22 13:58:41.855 GMT [7364][postmaster] LOG:  database system is shut down
2024-03-22 13:58:42.252 GMT [8116][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:42.252 GMT [8116][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:42.253 GMT [8116][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:42.707 GMT [1020][startup] LOG:  database system was shut down at 2024-03-22 13:58:41 GMT
2024-03-22 13:58:42.752 GMT [8116][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:42.821 GMT [8116][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:42.822 GMT [8116][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:42.843 GMT [8116][postmaster] LOG:  background worker "logical replication launcher" (PID 7756) exited with exit code 1
2024-03-22 13:58:42.843 GMT [3660][checkpointer] LOG:  shutting down
2024-03-22 13:58:42.843 GMT [3660][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:42.846 GMT [3660][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/4080990, redo lsn=0/4080990
2024-03-22 13:58:42.860 GMT [8116][postmaster] LOG:  database system is shut down
2024-03-22 13:58:43.108 GMT [6984][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-22 13:58:43.108 GMT [6984][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:58:43.183](0.395s) 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 5172
[13:58:43.619](0.436s) 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-22 13:58:36.881 GMT [7364][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:36.882 GMT [7364][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:36.980 GMT [7128][startup] LOG:  database system was shut down at 2024-03-22 13:47:57 GMT
2024-03-22 13:58:37.033 GMT [7364][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:37.344 GMT [4956][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.346 GMT [4956][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-22 13:58:37.346 GMT [4956][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.374 GMT [4956][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-22 13:58:37.381 GMT [4956][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.040 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.647 GMT [1400][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.648 GMT [1400][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-22 13:58:37.648 GMT [1400][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.651 GMT [1400][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-22 13:58:37.652 GMT [1400][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.792 GMT [7548][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.794 GMT [7548][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-22 13:58:37.794 GMT [7548][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.797 GMT [7548][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-22 13:58:37.798 GMT [7548][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.941 GMT [3628][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.943 GMT [3628][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-22 13:58:37.943 GMT [3628][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.965 GMT [3628][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-22 13:58:37.967 GMT [3628][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:38.508 GMT [6400][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:38.509 GMT [6400][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-22 13:58:38.509 GMT [6400][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:38.511 GMT [6400][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-22 13:58:38.512 GMT [6400][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:38.716 GMT [3424][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:38.717 GMT [3424][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-22 13:58:38.717 GMT [3424][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:38.720 GMT [3424][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-22 13:58:38.944 GMT [3424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.231 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:39.060 GMT [6968][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:39.061 GMT [6968][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-22 13:58:39.061 GMT [6968][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:39.064 GMT [6968][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-22 13:58:39.294 GMT [6968][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.237 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:39.617 GMT [7436][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:39.618 GMT [7436][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-22 13:58:39.618 GMT [7436][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:39.621 GMT [7436][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-22 13:58:39.884 GMT [7436][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.270 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:40.062 GMT [4684][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:40.064 GMT [4684][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-22 13:58:40.064 GMT [4684][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:40.067 GMT [4684][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-22 13:58:40.412 GMT [4684][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.353 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:40.550 GMT [4264][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:40.552 GMT [4264][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-22 13:58:40.552 GMT [4264][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:40.596 GMT [4264][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-22 13:58:40.800 GMT [4264][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.253 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:41.092 GMT [7652][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:41.093 GMT [7652][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-22 13:58:41.093 GMT [7652][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:41.113 GMT [7652][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-22 13:58:41.476 GMT [7652][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.387 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:41.558 GMT [7364][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:41.559 GMT [7364][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:41.576 GMT [7364][postmaster] LOG:  background worker "logical replication launcher" (PID 6584) exited with exit code 1
2024-03-22 13:58:41.582 GMT [7636][checkpointer] LOG:  shutting down
2024-03-22 13:58:41.582 GMT [7636][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:41.784 GMT [7636][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.203 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/4080918, redo lsn=0/4080918
2024-03-22 13:58:41.855 GMT [7364][postmaster] LOG:  database system is shut down
2024-03-22 13:58:42.252 GMT [8116][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:42.252 GMT [8116][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:42.253 GMT [8116][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:42.707 GMT [1020][startup] LOG:  database system was shut down at 2024-03-22 13:58:41 GMT
2024-03-22 13:58:42.752 GMT [8116][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:42.821 GMT [8116][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:42.822 GMT [8116][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:42.843 GMT [8116][postmaster] LOG:  background worker "logical replication launcher" (PID 7756) exited with exit code 1
2024-03-22 13:58:42.843 GMT [3660][checkpointer] LOG:  shutting down
2024-03-22 13:58:42.843 GMT [3660][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:42.846 GMT [3660][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/4080990, redo lsn=0/4080990
2024-03-22 13:58:42.860 GMT [8116][postmaster] LOG:  database system is shut down
2024-03-22 13:58:43.108 GMT [6984][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-22 13:58:43.108 GMT [6984][postmaster] LOG:  database system is shut down
2024-03-22 13:58:43.438 GMT [5172][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:43.444 GMT [5172][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:43.469 GMT [5172][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:43.522 GMT [4808][startup] LOG:  database system was shut down at 2024-03-22 13:58:42 GMT
2024-03-22 13:58:43.537 GMT [5172][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:43.653 GMT [5172][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:43.654 GMT [5172][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:43.665 GMT [5172][postmaster] LOG:  background worker "logical replication launcher" (PID 2284) exited with exit code 1
2024-03-22 13:58:43.665 GMT [1636][checkpointer] LOG:  shutting down
2024-03-22 13:58:43.665 GMT [1636][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:43.669 GMT [1636][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/4080A08, redo lsn=0/4080A08
2024-03-22 13:58:43.695 GMT [5172][postmaster] LOG:  database system is shut down
2024-03-22 13:58:43.878 GMT [4816][postmaster] FATAL:  could not set SSL protocol version range
2024-03-22 13:58:43.878 GMT [4816][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-22 13:58:43.878 GMT [4816][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:58:43.991](0.372s) 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 2336
[13:58:44.372](0.380s) ok 5 - restart succeeds with correct SSL protocol bounds
[13:58:44.372](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 4644
[13:58:45.028](0.656s) ok 6 - server doesn't accept non-SSL connections
[13:58:45.028](0.000s) ok 7 - server doesn't accept non-SSL connections: matches
[13:58:46.294](1.265s) ok 8 - connect without server root cert sslmode=require
[13:58:46.294](0.001s) ok 9 - connect without server root cert sslmode=require: no stderr
[13:58:46.462](0.167s) ok 10 - connect without server root cert sslmode=verify-ca
[13:58:46.462](0.001s) ok 11 - connect without server root cert sslmode=verify-ca: matches
[13:58:46.695](0.232s) ok 12 - connect without server root cert sslmode=verify-full
[13:58:46.695](0.000s) ok 13 - connect without server root cert sslmode=verify-full: matches
[13:58:46.794](0.099s) ok 14 - connect with wrong server root cert sslmode=require
[13:58:46.794](0.000s) ok 15 - connect with wrong server root cert sslmode=require: matches
[13:58:46.917](0.123s) ok 16 - connect with wrong server root cert sslmode=verify-ca
[13:58:46.918](0.000s) ok 17 - connect with wrong server root cert sslmode=verify-ca: matches
[13:58:46.996](0.078s) ok 18 - connect with wrong server root cert sslmode=verify-full
[13:58:46.996](0.000s) ok 19 - connect with wrong server root cert sslmode=verify-full: matches
[13:58:47.112](0.116s) ok 20 - connect with server CA cert, without root CA
[13:58:47.112](0.000s) ok 21 - connect with server CA cert, without root CA: matches
[13:58:47.212](0.100s) ok 22 - connect with correct server CA cert file sslmode=require
[13:58:47.212](0.001s) ok 23 - connect with correct server CA cert file sslmode=require: no stderr
[13:58:47.342](0.129s) ok 24 - connect with correct server CA cert file sslmode=verify-ca
[13:58:47.342](0.000s) ok 25 - connect with correct server CA cert file sslmode=verify-ca: no stderr
[13:58:47.609](0.268s) ok 26 - connect with correct server CA cert file sslmode=verify-full
[13:58:47.610](0.000s) ok 27 - connect with correct server CA cert file sslmode=verify-full: no stderr
[13:58:47.711](0.101s) ok 28 - cert root file that contains two certificates, order 1
[13:58:47.711](0.000s) ok 29 - cert root file that contains two certificates, order 1: no stderr
[13:58:47.891](0.180s) ok 30 - cert root file that contains two certificates, order 2
[13:58:47.892](0.000s) ok 31 - cert root file that contains two certificates, order 2: no stderr
[13:58:48.034](0.142s) ok 32 - connect with sslcertmode=disable
[13:58:48.034](0.000s) ok 33 - connect with sslcertmode=disable: no stderr
[13:58:48.202](0.168s) ok 34 - connect with sslcertmode=allow
[13:58:48.202](0.000s) ok 35 - connect with sslcertmode=allow: no stderr
[13:58:48.348](0.146s) ok 36 - connect with sslcertmode=require fails without a client certificate
[13:58:48.348](0.000s) ok 37 - connect with sslcertmode=require fails without a client certificate: matches
[13:58:48.533](0.185s) ok 38 - sslcrl option with invalid file name
[13:58:48.533](0.000s) ok 39 - sslcrl option with invalid file name: no stderr
[13:58:48.651](0.117s) ok 40 - CRL belonging to a different CA
[13:58:48.651](0.000s) ok 41 - CRL belonging to a different CA: matches
[13:58:48.843](0.192s) ok 42 - directory CRL belonging to a different CA
[13:58:48.843](0.000s) ok 43 - directory CRL belonging to a different CA: matches
[13:58:48.957](0.114s) ok 44 - CRL with a non-revoked cert
[13:58:48.957](0.000s) ok 45 - CRL with a non-revoked cert: no stderr
[13:58:49.049](0.092s) ok 46 - directory CRL with a non-revoked cert
[13:58:49.049](0.000s) ok 47 - directory CRL with a non-revoked cert: no stderr
[13:58:49.140](0.091s) ok 48 - mismatch between host name and server certificate sslmode=require
[13:58:49.141](0.001s) ok 49 - mismatch between host name and server certificate sslmode=require: no stderr
[13:58:49.295](0.154s) ok 50 - mismatch between host name and server certificate sslmode=verify-ca
[13:58:49.295](0.000s) ok 51 - mismatch between host name and server certificate sslmode=verify-ca: no stderr
[13:58:49.357](0.062s) ok 52 - mismatch between host name and server certificate sslmode=verify-full
[13:58:49.357](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 7396
[13:58:49.722](0.365s) ok 54 - IP address in the Common Name
[13:58:49.723](0.001s) ok 55 - IP address in the Common Name: no stderr
[13:58:49.832](0.108s) ok 56 - mismatch between host name and server certificate IP address
[13:58:49.832](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 5784
[13:58:50.191](0.359s) ok 58 - IP address in a dNSName
[13:58:50.191](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 3812
[13:58:50.535](0.344s) ok 60 - host name matching with X.509 Subject Alternative Names 1
[13:58:50.536](0.000s) ok 61 - host name matching with X.509 Subject Alternative Names 1: no stderr
[13:58:50.660](0.124s) ok 62 - host name matching with X.509 Subject Alternative Names 2
[13:58:50.660](0.000s) ok 63 - host name matching with X.509 Subject Alternative Names 2: no stderr
[13:58:50.769](0.109s) ok 64 - host name matching with X.509 Subject Alternative Names wildcard
[13:58:50.769](0.000s) ok 65 - host name matching with X.509 Subject Alternative Names wildcard: no stderr
[13:58:50.831](0.062s) ok 66 - host name not matching with X.509 Subject Alternative Names
[13:58:50.831](0.000s) ok 67 - host name not matching with X.509 Subject Alternative Names: matches
[13:58:50.941](0.109s) ok 68 - host name not matching with X.509 Subject Alternative Names wildcard
[13:58:50.941](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 7620
[13:58:51.285](0.344s) ok 70 - host name matching with a single X.509 Subject Alternative Name
[13:58:51.286](0.000s) ok 71 - host name matching with a single X.509 Subject Alternative Name: no stderr
[13:58:51.347](0.062s) ok 72 - host name not matching with a single X.509 Subject Alternative Name
[13:58:51.348](0.000s) ok 73 - host name not matching with a single X.509 Subject Alternative Name: matches
[13:58:51.410](0.062s) ok 74 - host name not matching with a single X.509 Subject Alternative Name wildcard
[13:58:51.410](0.000s) ok 75 - host name not matching with a single X.509 Subject Alternative Name wildcard: matches
[13:58:51.440](0.029s) ok 76 # skip IPv6 addresses in certificates not support on this platform
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 1672
[13:58:51.785](0.345s) ok 77 - certificate with both a CN and SANs 1
[13:58:51.785](0.000s) ok 78 - certificate with both a CN and SANs 1: no stderr
[13:58:51.849](0.064s) ok 79 - certificate with both a CN and SANs 2
[13:58:51.849](0.000s) ok 80 - certificate with both a CN and SANs 2: no stderr
[13:58:51.958](0.109s) ok 81 - certificate with both a CN and SANs ignores CN
[13:58:51.959](0.000s) ok 82 - certificate with both a CN and SANs ignores CN: matches
[13:58:51.987](0.029s) 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 5240
[13:58:52.334](0.347s) ok 84 - certificate with both an IP CN and DNS SANs matches CN
[13:58:52.334](0.000s) ok 85 - certificate with both an IP CN and DNS SANs matches CN: no stderr
[13:58:52.397](0.062s) ok 86 - certificate with both an IP CN and DNS SANs matches SAN 1
[13:58:52.397](0.000s) ok 87 - certificate with both an IP CN and DNS SANs matches SAN 1: no stderr
[13:58:52.507](0.110s) ok 88 - certificate with both an IP CN and DNS SANs matches SAN 2
[13:58:52.508](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 8156
[13:58:52.852](0.344s) ok 90 - server certificate without CN or SANs sslmode=verify-ca
[13:58:52.852](0.000s) ok 91 - server certificate without CN or SANs sslmode=verify-ca: no stderr
[13:58:52.961](0.109s) ok 92 - server certificate without CN or SANs sslmode=verify-full
[13:58:52.961](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 2160
[13:58:53.311](0.350s) ok 94 - sslrootcert=system does not connect with private CA
[13:58:53.311](0.000s) ok 95 - sslrootcert=system does not connect with private CA: matches
[13:58:53.369](0.057s) ok 96 - sslrootcert=system only accepts sslmode=verify-full
[13:58:53.369](0.000s) ok 97 - sslrootcert=system only accepts sslmode=verify-full: matches
[13:58:53.478](0.109s) ok 98 - sslrootcert=system connects with overridden SSL_CERT_FILE
[13:58:53.478](0.000s) ok 99 - sslrootcert=system connects with overridden SSL_CERT_FILE: no stderr
[13:58:53.586](0.108s) ok 100 - sslrootcert=system defaults to sslmode=verify-full
[13:58:53.587](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 3160
[13:58:53.947](0.360s) ok 102 - connects without client-side CRL
[13:58:53.947](0.000s) ok 103 - connects without client-side CRL: no stderr
[13:58:54.056](0.108s) ok 104 - does not connect with client-side CRL file
[13:58:54.056](0.000s) ok 105 - does not connect with client-side CRL file: matches
[13:58:54.168](0.111s) ok 106 - does not connect with client-side CRL directory
[13:58:54.168](0.001s) ok 107 - does not connect with client-side CRL directory: matches
# Running: psql -X -A -F , -P null=_null_ -d sslkey=invalid sslcert=invalid sslrootcert=invalid sslcrl=invalid sslcrldir=invalid user=ssltestuser dbname=trustdb hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=invalid -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[13:58:54.273](0.104s) ok 108 - pg_stat_ssl view without client certificate: exit code 0
[13:58:54.274](0.001s) ok 109 - pg_stat_ssl view without client certificate: no stderr
[13:58:54.274](0.000s) ok 110 - pg_stat_ssl view without client certificate: matches
[13:58:54.384](0.110s) ok 111 - connection success with correct range of TLS protocol versions
[13:58:54.385](0.000s) ok 112 - connection success with correct range of TLS protocol versions: no stderr
[13:58:54.447](0.062s) ok 113 - connection failure with incorrect range of TLS protocol versions
[13:58:54.447](0.000s) ok 114 - connection failure with incorrect range of TLS protocol versions: matches
[13:58:54.510](0.062s) ok 115 - connection failure with an incorrect SSL protocol minimum bound
[13:58:54.510](0.000s) ok 116 - connection failure with an incorrect SSL protocol minimum bound: matches
[13:58:54.571](0.062s) ok 117 - connection failure with an incorrect SSL protocol maximum bound
[13:58:54.572](0.000s) ok 118 - connection failure with an incorrect SSL protocol maximum bound: matches
[13:58:54.572](0.000s) # running server tests
[13:58:54.679](0.107s) ok 119 - certificate authorization fails without client cert
[13:58:54.679](0.000s) ok 120 - certificate authorization fails without client cert: matches
[13:58:54.788](0.109s) ok 121 - certificate authorization succeeds with correct client cert in PEM format
[13:58:54.788](0.000s) ok 122 - certificate authorization succeeds with correct client cert in PEM format: no stderr
[13:58:54.853](0.065s) ok 123 - certificate authorization succeeds with correct client cert in DER format
[13:58:54.853](0.000s) ok 124 - certificate authorization succeeds with correct client cert in DER format: no stderr
[13:58:54.960](0.107s) ok 125 - certificate authorization succeeds with correct client cert in encrypted PEM format
[13:58:54.961](0.000s) ok 126 - certificate authorization succeeds with correct client cert in encrypted PEM format: no stderr
[13:58:55.070](0.110s) ok 127 - certificate authorization succeeds with correct client cert in encrypted DER format
[13:58:55.071](0.000s) ok 128 - certificate authorization succeeds with correct client cert in encrypted DER format: no stderr
[13:58:55.181](0.110s) ok 129 - certificate authorization succeeds with correct client cert and sslcertmode=require
[13:58:55.181](0.000s) ok 130 - certificate authorization succeeds with correct client cert and sslcertmode=require: no stderr
[13:58:55.290](0.109s) ok 131 - certificate authorization succeeds with correct client cert and sslcertmode=allow
[13:58:55.291](0.000s) ok 132 - certificate authorization succeeds with correct client cert and sslcertmode=allow: no stderr
[13:58:55.401](0.111s) ok 133 - certificate authorization fails with correct client cert and sslcertmode=disable
[13:58:55.402](0.000s) ok 134 - certificate authorization fails with correct client cert and sslcertmode=disable: matches
[13:58:55.509](0.107s) ok 135 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format
[13:58:55.509](0.000s) ok 136 - certificate authorization fails with correct client cert and wrong password in encrypted PEM format: matches
[13:58:55.618](0.109s) ok 137 - certificate authorization succeeds with DN mapping
[13:58:55.618](0.000s) ok 138 - certificate authorization succeeds with DN mapping: no stderr
[13:58:55.619](0.001s) ok 139 - certificate authorization succeeds with DN mapping: log matches
[13:58:55.728](0.109s) ok 140 - certificate authorization succeeds with DN regex mapping
[13:58:55.728](0.000s) ok 141 - certificate authorization succeeds with DN regex mapping: no stderr
[13:58:55.837](0.109s) ok 142 - certificate authorization succeeds with CN mapping
[13:58:55.838](0.000s) ok 143 - certificate authorization succeeds with CN mapping: no stderr
[13:58:55.838](0.001s) ok 144 - certificate authorization succeeds with CN mapping: log matches
[13:58:55.839](0.001s) not ok 145 # TODO & SKIP Need Pty support
[13:58:55.839](0.001s) not ok 146 # TODO & SKIP Need Pty support
[13:58:55.840](0.000s) not ok 147 # TODO & SKIP Need Pty support
[13:58:55.840](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_Rkmj/client.key -c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
[13:58:55.960](0.120s) ok 149 - pg_stat_ssl with client certificate: exit code 0
[13:58:55.961](0.000s) ok 150 - pg_stat_ssl with client certificate: no stderr
[13:58:55.961](0.000s) ok 151 - pg_stat_ssl with client certificate: matches
[13:58:55.961](0.000s) ok 152 # skip Permissions check not enforced on Windows
[13:58:55.962](0.000s) ok 153 # skip Permissions check not enforced on Windows
[13:58:56.089](0.127s) ok 154 - certificate authorization fails with client cert belonging to another user
[13:58:56.089](0.000s) ok 155 - certificate authorization fails with client cert belonging to another user: matches
[13:58:56.196](0.108s) ok 156 - certificate authorization fails with revoked client cert
[13:58:56.197](0.000s) ok 157 - certificate authorization fails with revoked client cert: matches
[13:58:56.197](0.001s) ok 158 - certificate authorization fails with revoked client cert: log does not match
[13:58:56.306](0.108s) ok 159 - auth_option clientcert=verify-full succeeds with matching username and Common Name
[13:58:56.307](0.001s) ok 160 - auth_option clientcert=verify-full succeeds with matching username and Common Name: no stderr
[13:58:56.308](0.001s) ok 161 - auth_option clientcert=verify-full succeeds with matching username and Common Name: log matches
[13:58:56.415](0.108s) ok 162 - auth_option clientcert=verify-full fails with mismatching username and Common Name
[13:58:56.416](0.000s) ok 163 - auth_option clientcert=verify-full fails with mismatching username and Common Name: matches
[13:58:56.416](0.001s) ok 164 - auth_option clientcert=verify-full fails with mismatching username and Common Name: log does not match
[13:58:56.525](0.109s) ok 165 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name
[13:58:56.526](0.000s) ok 166 - auth_option clientcert=verify-ca succeeds with mismatching username and Common Name: no stderr
[13:58:56.526](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 3728
[13:58:56.868](0.342s) ok 168 - intermediate client certificate is provided by client
[13:58:56.869](0.000s) ok 169 - intermediate client certificate is provided by client: no stderr
[13:58:56.977](0.109s) ok 170 - intermediate client certificate is missing
[13:58:56.978](0.000s) ok 171 - intermediate client certificate is missing: matches
[13:58:57.088](0.110s) ok 172 - logged client certificate Subjects are truncated if they're too long
[13:58:57.088](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 7868
[13:58:57.432](0.344s) ok 174 - intermediate client certificate is untrusted
[13:58:57.432](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 7432
[13:58:57.775](0.343s) ok 176 - certificate authorization fails with revoked client cert with server-side CRL directory
[13:58:57.775](0.000s) ok 177 - certificate authorization fails with revoked client cert with server-side CRL directory: matches
[13:58:57.885](0.110s) ok 178 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory
[13:58:57.886](0.001s) ok 179 - certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory: matches
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 4028
[13:58:58.231](0.345s) not ok 180 - connect with valid stapled ocsp response when sslocspstapling=1
[13:58:58.231](0.001s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923.
[13:58:58.231](0.000s) #          got: '2'
#     expected: '0'
[13:58:58.232](0.000s) not ok 181 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[13:58:58.232](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 923.
[13:58:58.232](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 63919 failed: server closed the connection unexpectedly
# 	This probably means the server terminated abnormally
# 	before or while processing the request.
# SSL SYSCALL error: Connection reset by peer (0x00002746/10054)'
#     expected: ''
[13:58:58.342](0.110s) ok 182 - connect without requesting ocsp response when sslocspstapling=0
[13:58:58.342](0.000s) ok 183 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 5912
[13:58:58.685](0.343s) ok 184 - failed with a revoked ocsp response when sslocspstapling=1
[13:58:58.810](0.125s) ok 185 - connect without requesting ocsp response when sslocspstapling=0
[13:58:58.810](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 6100
[13:58:59.106](0.296s) ok 187 - failed with a revoked ocsp response when sslocspstapling=1
[13:58:59.215](0.110s) ok 188 - connect without requesting ocsp response when sslocspstapling=0
[13:58:59.216](0.000s) ok 189 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 1844
[13:58:59.513](0.297s) ok 190 - failed with an expired ocsp response when sslocspstapling=1
[13:58:59.623](0.110s) ok 191 - connect without requesting ocsp response when sslocspstapling=0
[13:58:59.624](0.001s) ok 192 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 2144
[13:58:59.967](0.343s) not ok 193 - connect with valid stapled ocsp response when sslocspstapling=1
[13:58:59.967](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001.
[13:58:59.967](0.000s) #          got: '2'
#     expected: '0'
[13:58:59.967](0.000s) not ok 194 - connect with valid stapled ocsp response when sslocspstapling=1: no stderr
[13:58:59.968](0.000s) #   Failed test 'connect with valid stapled ocsp response when sslocspstapling=1: no stderr'
#   at C:/cirrus/src/test/ssl/t/001_ssltests.pl line 1001.
[13:58:59.968](0.000s) #          got: 'psql: error: connection to server at "127.0.0.1", port 63919 failed: server closed the connection unexpectedly
# 	This probably means the server terminated abnormally
# 	before or while processing the request.
# SSL SYSCALL error: Connection reset by peer (0x00002746/10054)'
#     expected: ''
[13:59:00.076](0.109s) ok 195 - connect without requesting ocsp response when sslocspstapling=0
[13:59:00.077](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 6740
[13:59:00.374](0.298s) ok 197 - failed with a revoked ocsp response when sslocspstapling=1
[13:59:00.484](0.110s) ok 198 - connect without requesting ocsp response when sslocspstapling=0
[13:59:00.485](0.001s) ok 199 - connect without requesting ocsp response when sslocspstapling=0: no stderr
### Restarting node "primary"
# Running: pg_ctl -w -D C:\cirrus\build/testrun/ssl/001_ssltests\data/t_001_ssltests_primary_data/pgdata -l C:\cirrus\build/testrun/ssl/001_ssltests\log/001_ssltests_primary.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 4392
[13:59:00.779](0.295s) ok 200 - failed with a revoked ocsp response when sslocspstapling=1
[13:59:00.889](0.110s) ok 201 - connect without requesting ocsp response when sslocspstapling=0
[13:59:00.890](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 5348
[13:59:01.186](0.296s) ok 203 - failed with an expired ocsp response when sslocspstapling=1
[13:59:01.295](0.109s) ok 204 - connect without requesting ocsp response when sslocspstapling=0
[13:59:01.295](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 4820
[13:59:01.750](0.455s) ok 206 - failed with an expired ocsp response when sslocspstapling=1
[13:59:01.859](0.109s) ok 207 - connect without requesting ocsp response when sslocspstapling=0
[13:59:01.859](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-22 13:58:36.881 GMT [7364][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:36.882 GMT [7364][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:36.980 GMT [7128][startup] LOG:  database system was shut down at 2024-03-22 13:47:57 GMT
2024-03-22 13:58:37.033 GMT [7364][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:37.344 GMT [4956][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.346 GMT [4956][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-22 13:58:37.346 GMT [4956][client backend] [[unknown]][0/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.374 GMT [4956][client backend] [001_ssltests.pl][0/2:0] LOG:  statement: SHOW ssl_library
2024-03-22 13:58:37.381 GMT [4956][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.040 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.647 GMT [1400][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.648 GMT [1400][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-22 13:58:37.648 GMT [1400][client backend] [[unknown]][1/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.651 GMT [1400][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: CREATE USER ssltestuser
2024-03-22 13:58:37.652 GMT [1400][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.792 GMT [7548][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.794 GMT [7548][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-22 13:58:37.794 GMT [7548][client backend] [[unknown]][2/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.797 GMT [7548][client backend] [001_ssltests.pl][2/2:0] LOG:  statement: CREATE USER md5testuser
2024-03-22 13:58:37.798 GMT [7548][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.010 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:37.941 GMT [3628][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:37.943 GMT [3628][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-22 13:58:37.943 GMT [3628][client backend] [[unknown]][3/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:37.965 GMT [3628][client backend] [001_ssltests.pl][3/2:0] LOG:  statement: CREATE USER anotheruser
2024-03-22 13:58:37.967 GMT [3628][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:38.508 GMT [6400][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:38.509 GMT [6400][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-22 13:58:38.509 GMT [6400][client backend] [[unknown]][4/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:38.511 GMT [6400][client backend] [001_ssltests.pl][4/2:0] LOG:  statement: CREATE USER yetanotheruser
2024-03-22 13:58:38.512 GMT [6400][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.007 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:38.716 GMT [3424][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:38.717 GMT [3424][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-22 13:58:38.717 GMT [3424][client backend] [[unknown]][5/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:38.720 GMT [3424][client backend] [001_ssltests.pl][5/2:0] LOG:  statement: CREATE DATABASE trustdb
2024-03-22 13:58:38.944 GMT [3424][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.231 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:39.060 GMT [6968][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:39.061 GMT [6968][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-22 13:58:39.061 GMT [6968][client backend] [[unknown]][6/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:39.064 GMT [6968][client backend] [001_ssltests.pl][6/2:0] LOG:  statement: CREATE DATABASE certdb
2024-03-22 13:58:39.294 GMT [6968][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.237 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:39.617 GMT [7436][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:39.618 GMT [7436][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-22 13:58:39.618 GMT [7436][client backend] [[unknown]][7/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:39.621 GMT [7436][client backend] [001_ssltests.pl][7/2:0] LOG:  statement: CREATE DATABASE certdb_dn
2024-03-22 13:58:39.884 GMT [7436][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.270 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:40.062 GMT [4684][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:40.064 GMT [4684][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-22 13:58:40.064 GMT [4684][client backend] [[unknown]][8/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:40.067 GMT [4684][client backend] [001_ssltests.pl][8/2:0] LOG:  statement: CREATE DATABASE certdb_dn_re
2024-03-22 13:58:40.412 GMT [4684][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.353 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:40.550 GMT [4264][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:40.552 GMT [4264][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-22 13:58:40.552 GMT [4264][client backend] [[unknown]][9/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:40.596 GMT [4264][client backend] [001_ssltests.pl][9/2:0] LOG:  statement: CREATE DATABASE certdb_cn
2024-03-22 13:58:40.800 GMT [4264][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.253 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:41.092 GMT [7652][not initialized] [[unknown]][:0] LOG:  connection received: host=[local]
2024-03-22 13:58:41.093 GMT [7652][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-22 13:58:41.093 GMT [7652][client backend] [[unknown]][10/1:0] LOG:  connection authorized: user=SYSTEM database=postgres application_name=001_ssltests.pl
2024-03-22 13:58:41.113 GMT [7652][client backend] [001_ssltests.pl][10/2:0] LOG:  statement: CREATE DATABASE verifydb
2024-03-22 13:58:41.476 GMT [7652][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.387 user=SYSTEM database=postgres host=[local]
2024-03-22 13:58:41.558 GMT [7364][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:41.559 GMT [7364][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:41.576 GMT [7364][postmaster] LOG:  background worker "logical replication launcher" (PID 6584) exited with exit code 1
2024-03-22 13:58:41.582 GMT [7636][checkpointer] LOG:  shutting down
2024-03-22 13:58:41.582 GMT [7636][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:41.784 GMT [7636][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.203 s; sync files=0, longest=0.000 s, average=0.000 s; distance=44563 kB, estimate=44563 kB; lsn=0/4080918, redo lsn=0/4080918
2024-03-22 13:58:41.855 GMT [7364][postmaster] LOG:  database system is shut down
2024-03-22 13:58:42.252 GMT [8116][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:42.252 GMT [8116][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:42.253 GMT [8116][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:42.707 GMT [1020][startup] LOG:  database system was shut down at 2024-03-22 13:58:41 GMT
2024-03-22 13:58:42.752 GMT [8116][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:42.821 GMT [8116][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:42.822 GMT [8116][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:42.843 GMT [8116][postmaster] LOG:  background worker "logical replication launcher" (PID 7756) exited with exit code 1
2024-03-22 13:58:42.843 GMT [3660][checkpointer] LOG:  shutting down
2024-03-22 13:58:42.843 GMT [3660][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:42.846 GMT [3660][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/4080990, redo lsn=0/4080990
2024-03-22 13:58:42.860 GMT [8116][postmaster] LOG:  database system is shut down
2024-03-22 13:58:43.108 GMT [6984][postmaster] FATAL:  could not load private key file "server-password.key": bad decrypt
2024-03-22 13:58:43.108 GMT [6984][postmaster] LOG:  database system is shut down
2024-03-22 13:58:43.438 GMT [5172][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:43.444 GMT [5172][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:43.469 GMT [5172][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:43.522 GMT [4808][startup] LOG:  database system was shut down at 2024-03-22 13:58:42 GMT
2024-03-22 13:58:43.537 GMT [5172][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:43.653 GMT [5172][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:43.654 GMT [5172][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:43.665 GMT [5172][postmaster] LOG:  background worker "logical replication launcher" (PID 2284) exited with exit code 1
2024-03-22 13:58:43.665 GMT [1636][checkpointer] LOG:  shutting down
2024-03-22 13:58:43.665 GMT [1636][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:43.669 GMT [1636][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/4080A08, redo lsn=0/4080A08
2024-03-22 13:58:43.695 GMT [5172][postmaster] LOG:  database system is shut down
2024-03-22 13:58:43.878 GMT [4816][postmaster] FATAL:  could not set SSL protocol version range
2024-03-22 13:58:43.878 GMT [4816][postmaster] DETAIL:  ssl_min_protocol_version cannot be higher than ssl_max_protocol_version
2024-03-22 13:58:43.878 GMT [4816][postmaster] LOG:  database system is shut down
2024-03-22 13:58:44.204 GMT [2336][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:44.204 GMT [2336][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:44.205 GMT [2336][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:44.249 GMT [4364][startup] LOG:  database system was shut down at 2024-03-22 13:58:43 GMT
2024-03-22 13:58:44.264 GMT [2336][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:44.401 GMT [2336][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:44.401 GMT [2336][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:44.407 GMT [2336][postmaster] LOG:  background worker "logical replication launcher" (PID 5684) exited with exit code 1
2024-03-22 13:58:44.407 GMT [3756][checkpointer] LOG:  shutting down
2024-03-22 13:58:44.407 GMT [3756][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:44.410 GMT [3756][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/4080A80, redo lsn=0/4080A80
2024-03-22 13:58:44.416 GMT [2336][postmaster] LOG:  database system is shut down
2024-03-22 13:58:44.695 GMT [4644][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:44.695 GMT [4644][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:44.699 GMT [4644][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:44.722 GMT [4332][startup] LOG:  database system was shut down at 2024-03-22 13:58:44 GMT
2024-03-22 13:58:44.763 GMT [4644][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:44.967 GMT [3824][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50388
2024-03-22 13:58:44.968 GMT [3824][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-22 13:58:44.968 GMT [3824][client backend] [[unknown]][0/1:0] DETAIL:  Client IP address resolved to "pg-loadbalancetest", forward lookup not checked.
2024-03-22 13:58:45.089 GMT [3884][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50390
2024-03-22 13:58:45.103 GMT [3884][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-22 13:58:45.103 GMT [3884][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-22 13:58:45.131 GMT [3884][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-22 13:58:45.136 GMT [3884][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.054 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50390
2024-03-22 13:58:46.415 GMT [6852][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50392
2024-03-22 13:58:46.436 GMT [6852][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-22 13:58:46.531 GMT [844][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50395
2024-03-22 13:58:46.595 GMT [844][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-22 13:58:46.760 GMT [4128][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50397
2024-03-22 13:58:46.765 GMT [4128][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-22 13:58:46.848 GMT [3856][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50400
2024-03-22 13:58:46.854 GMT [3856][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-22 13:58:46.963 GMT [1148][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50403
2024-03-22 13:58:46.969 GMT [1148][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-22 13:58:47.042 GMT [1844][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50405
2024-03-22 13:58:47.047 GMT [1844][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-22 13:58:47.163 GMT [3080][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50407
2024-03-22 13:58:47.171 GMT [3080][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-22 13:58:47.171 GMT [3080][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-22 13:58:47.174 GMT [3080][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-22 13:58:47.180 GMT [3080][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50407
2024-03-22 13:58:47.294 GMT [3844][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50409
2024-03-22 13:58:47.301 GMT [3844][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-22 13:58:47.301 GMT [3844][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-22 13:58:47.304 GMT [3844][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-22 13:58:47.306 GMT [3844][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.028 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50409
2024-03-22 13:58:47.513 GMT [956][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50412
2024-03-22 13:58:47.521 GMT [956][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-22 13:58:47.521 GMT [956][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-22 13:58:47.524 GMT [956][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-22 13:58:47.527 GMT [956][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-22 13:58:47.667 GMT [6168][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50414
2024-03-22 13:58:47.674 GMT [6168][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-22 13:58:47.674 GMT [6168][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-22 13:58:47.677 GMT [6168][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-22 13:58:47.681 GMT [6168][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50414
2024-03-22 13:58:47.792 GMT [6452][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50416
2024-03-22 13:58:47.799 GMT [6452][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-22 13:58:47.799 GMT [6452][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-22 13:58:47.801 GMT [6452][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-22 13:58:47.806 GMT [6452][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50416
2024-03-22 13:58:48.002 GMT [4684][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50418
2024-03-22 13:58:48.010 GMT [4684][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-22 13:58:48.010 GMT [4684][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-22 13:58:48.013 GMT [4684][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-22 13:58:48.016 GMT [4684][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50418
2024-03-22 13:58:48.150 GMT [2568][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50420
2024-03-22 13:58:48.158 GMT [2568][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-22 13:58:48.158 GMT [2568][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-22 13:58:48.161 GMT [2568][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-22 13:58:48.164 GMT [2568][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50420
2024-03-22 13:58:48.287 GMT [4940][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50421
2024-03-22 13:58:48.294 GMT [4940][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-22 13:58:48.294 GMT [4940][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-22 13:58:48.308 GMT [4940][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.043 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50421
2024-03-22 13:58:48.472 GMT [5140][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50424
2024-03-22 13:58:48.479 GMT [5140][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-22 13:58:48.479 GMT [5140][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-22 13:58:48.483 GMT [5140][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-22 13:58:48.486 GMT [5140][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50424
2024-03-22 13:58:48.630 GMT [8088][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50426
2024-03-22 13:58:48.636 GMT [8088][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-22 13:58:48.750 GMT [1400][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50427
2024-03-22 13:58:48.757 GMT [1400][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-22 13:58:48.917 GMT [4488][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50429
2024-03-22 13:58:48.927 GMT [4488][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-22 13:58:48.927 GMT [4488][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-22 13:58:48.930 GMT [4488][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-22 13:58:48.934 GMT [4488][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50429
2024-03-22 13:58:49.021 GMT [8104][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50431
2024-03-22 13:58:49.028 GMT [8104][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-22 13:58:49.028 GMT [8104][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-22 13:58:49.031 GMT [8104][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-22 13:58:49.034 GMT [8104][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50431
2024-03-22 13:58:49.127 GMT [4524][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50433
2024-03-22 13:58:49.134 GMT [4524][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-22 13:58:49.134 GMT [4524][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-22 13:58:49.137 GMT [4524][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-22 13:58:49.140 GMT [4524][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50433
2024-03-22 13:58:49.213 GMT [5984][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50434
2024-03-22 13:58:49.220 GMT [5984][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-22 13:58:49.220 GMT [5984][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-22 13:58:49.249 GMT [5984][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-22 13:58:49.251 GMT [5984][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.045 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50434
2024-03-22 13:58:49.346 GMT [6384][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50436
2024-03-22 13:58:49.381 GMT [4644][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:49.381 GMT [4644][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:49.385 GMT [4644][postmaster] LOG:  background worker "logical replication launcher" (PID 1360) exited with exit code 1
2024-03-22 13:58:49.387 GMT [4264][checkpointer] LOG:  shutting down
2024-03-22 13:58:49.387 GMT [4264][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:49.390 GMT [4264][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/4080AF8, redo lsn=0/4080AF8
2024-03-22 13:58:49.396 GMT [4644][postmaster] LOG:  database system is shut down
2024-03-22 13:58:49.546 GMT [7396][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:49.547 GMT [7396][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:49.548 GMT [7396][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:49.576 GMT [6052][startup] LOG:  database system was shut down at 2024-03-22 13:58:49 GMT
2024-03-22 13:58:49.588 GMT [7396][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:49.681 GMT [5608][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50437
2024-03-22 13:58:49.688 GMT [5608][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-22 13:58:49.689 GMT [5608][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-22 13:58:49.702 GMT [5608][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-22 13:58:49.705 GMT [5608][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50437
2024-03-22 13:58:49.773 GMT [6796][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50438
2024-03-22 13:58:49.851 GMT [7396][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:49.851 GMT [7396][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:49.857 GMT [7396][postmaster] LOG:  background worker "logical replication launcher" (PID 7108) exited with exit code 1
2024-03-22 13:58:49.858 GMT [3996][checkpointer] LOG:  shutting down
2024-03-22 13:58:49.859 GMT [3996][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:49.862 GMT [3996][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/4080B70, redo lsn=0/4080B70
2024-03-22 13:58:49.868 GMT [7396][postmaster] LOG:  database system is shut down
2024-03-22 13:58:50.019 GMT [5784][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:50.020 GMT [5784][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:50.021 GMT [5784][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:50.046 GMT [8176][startup] LOG:  database system was shut down at 2024-03-22 13:58:49 GMT
2024-03-22 13:58:50.056 GMT [5784][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:50.137 GMT [7936][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50439
2024-03-22 13:58:50.145 GMT [7936][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-22 13:58:50.145 GMT [7936][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-22 13:58:50.160 GMT [7936][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-22 13:58:50.165 GMT [7936][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.036 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50439
2024-03-22 13:58:50.211 GMT [5784][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:50.211 GMT [5784][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:50.216 GMT [5784][postmaster] LOG:  background worker "logical replication launcher" (PID 6072) exited with exit code 1
2024-03-22 13:58:50.217 GMT [276][checkpointer] LOG:  shutting down
2024-03-22 13:58:50.217 GMT [276][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:50.220 GMT [276][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/4080BE8, redo lsn=0/4080BE8
2024-03-22 13:58:50.226 GMT [5784][postmaster] LOG:  database system is shut down
2024-03-22 13:58:50.376 GMT [3812][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:50.377 GMT [3812][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:50.378 GMT [3812][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:50.403 GMT [572][startup] LOG:  database system was shut down at 2024-03-22 13:58:50 GMT
2024-03-22 13:58:50.412 GMT [3812][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:50.480 GMT [8128][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50440
2024-03-22 13:58:50.488 GMT [8128][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-22 13:58:50.488 GMT [8128][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-22 13:58:50.502 GMT [8128][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-22 13:58:50.506 GMT [8128][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50440
2024-03-22 13:58:50.602 GMT [7244][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50441
2024-03-22 13:58:50.611 GMT [7244][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-22 13:58:50.611 GMT [7244][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-22 13:58:50.614 GMT [7244][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-22 13:58:50.617 GMT [7244][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50441
2024-03-22 13:58:50.711 GMT [5852][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50442
2024-03-22 13:58:50.719 GMT [5852][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-22 13:58:50.719 GMT [5852][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-22 13:58:50.722 GMT [5852][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-22 13:58:50.726 GMT [5852][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50442
2024-03-22 13:58:50.813 GMT [4408][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50443
2024-03-22 13:58:50.879 GMT [3868][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50444
2024-03-22 13:58:50.960 GMT [3812][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:50.960 GMT [3812][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:50.965 GMT [3812][postmaster] LOG:  background worker "logical replication launcher" (PID 3248) exited with exit code 1
2024-03-22 13:58:50.966 GMT [7332][checkpointer] LOG:  shutting down
2024-03-22 13:58:50.966 GMT [7332][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:50.969 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.004 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB; lsn=0/4080C60, redo lsn=0/4080C60
2024-03-22 13:58:50.975 GMT [3812][postmaster] LOG:  database system is shut down
2024-03-22 13:58:51.123 GMT [7620][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:51.123 GMT [7620][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:51.125 GMT [7620][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:51.147 GMT [2264][startup] LOG:  database system was shut down at 2024-03-22 13:58:50 GMT
2024-03-22 13:58:51.155 GMT [7620][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:51.225 GMT [1708][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50445
2024-03-22 13:58:51.232 GMT [1708][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-22 13:58:51.232 GMT [1708][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-22 13:58:51.247 GMT [1708][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-22 13:58:51.249 GMT [1708][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.032 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50445
2024-03-22 13:58:51.329 GMT [5752][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50446
2024-03-22 13:58:51.391 GMT [480][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50447
2024-03-22 13:58:51.458 GMT [7620][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:51.459 GMT [7620][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:51.462 GMT [7620][postmaster] LOG:  background worker "logical replication launcher" (PID 4720) exited with exit code 1
2024-03-22 13:58:51.463 GMT [4356][checkpointer] LOG:  shutting down
2024-03-22 13:58:51.463 GMT [4356][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:51.467 GMT [4356][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/4080CD8, redo lsn=0/4080CD8
2024-03-22 13:58:51.473 GMT [7620][postmaster] LOG:  database system is shut down
2024-03-22 13:58:51.625 GMT [1672][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:51.626 GMT [1672][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:51.627 GMT [1672][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:51.648 GMT [5048][startup] LOG:  database system was shut down at 2024-03-22 13:58:51 GMT
2024-03-22 13:58:51.657 GMT [1672][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:51.724 GMT [5972][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50448
2024-03-22 13:58:51.731 GMT [5972][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-22 13:58:51.731 GMT [5972][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-22 13:58:51.744 GMT [5972][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-22 13:58:51.747 GMT [5972][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50448
2024-03-22 13:58:51.827 GMT [4256][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50449
2024-03-22 13:58:51.836 GMT [4256][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-22 13:58:51.836 GMT [4256][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-22 13:58:51.839 GMT [4256][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-22 13:58:51.842 GMT [4256][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50449
2024-03-22 13:58:51.897 GMT [6236][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50450
2024-03-22 13:58:52.010 GMT [1672][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:52.010 GMT [1672][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:52.014 GMT [1672][postmaster] LOG:  background worker "logical replication launcher" (PID 6504) exited with exit code 1
2024-03-22 13:58:52.015 GMT [2316][checkpointer] LOG:  shutting down
2024-03-22 13:58:52.015 GMT [2316][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:52.019 GMT [2316][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/4080D50, redo lsn=0/4080D50
2024-03-22 13:58:52.024 GMT [1672][postmaster] LOG:  database system is shut down
2024-03-22 13:58:52.172 GMT [5240][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:52.173 GMT [5240][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:52.174 GMT [5240][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:52.194 GMT [2196][startup] LOG:  database system was shut down at 2024-03-22 13:58:52 GMT
2024-03-22 13:58:52.202 GMT [5240][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:52.276 GMT [2452][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50451
2024-03-22 13:58:52.284 GMT [2452][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-22 13:58:52.284 GMT [2452][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-22 13:58:52.297 GMT [2452][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-22 13:58:52.300 GMT [2452][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50451
2024-03-22 13:58:52.380 GMT [7052][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50452
2024-03-22 13:58:52.388 GMT [7052][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-22 13:58:52.388 GMT [7052][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-22 13:58:52.391 GMT [7052][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-22 13:58:52.394 GMT [7052][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.020 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50452
2024-03-22 13:58:52.445 GMT [7576][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50453
2024-03-22 13:58:52.454 GMT [7576][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-22 13:58:52.454 GMT [7576][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-22 13:58:52.457 GMT [7576][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-22 13:58:52.460 GMT [7576][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50453
2024-03-22 13:58:52.526 GMT [5240][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:52.527 GMT [5240][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:52.532 GMT [5240][postmaster] LOG:  background worker "logical replication launcher" (PID 3264) exited with exit code 1
2024-03-22 13:58:52.532 GMT [4664][checkpointer] LOG:  shutting down
2024-03-22 13:58:52.532 GMT [4664][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:52.535 GMT [4664][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/4080DC8, redo lsn=0/4080DC8
2024-03-22 13:58:52.540 GMT [5240][postmaster] LOG:  database system is shut down
2024-03-22 13:58:52.693 GMT [8156][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:52.694 GMT [8156][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:52.695 GMT [8156][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:52.714 GMT [5032][startup] LOG:  database system was shut down at 2024-03-22 13:58:52 GMT
2024-03-22 13:58:52.721 GMT [8156][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:52.789 GMT [1792][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50454
2024-03-22 13:58:52.797 GMT [1792][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-22 13:58:52.797 GMT [1792][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-22 13:58:52.809 GMT [1792][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-22 13:58:52.813 GMT [1792][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50454
2024-03-22 13:58:52.901 GMT [2464][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50455
2024-03-22 13:58:52.981 GMT [8156][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:52.982 GMT [8156][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:52.985 GMT [8156][postmaster] LOG:  background worker "logical replication launcher" (PID 3124) exited with exit code 1
2024-03-22 13:58:52.986 GMT [4572][checkpointer] LOG:  shutting down
2024-03-22 13:58:52.986 GMT [4572][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:52.989 GMT [4572][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/4080E40, redo lsn=0/4080E40
2024-03-22 13:58:52.994 GMT [8156][postmaster] LOG:  database system is shut down
2024-03-22 13:58:53.139 GMT [2160][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:53.140 GMT [2160][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:53.141 GMT [2160][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:53.159 GMT [1912][startup] LOG:  database system was shut down at 2024-03-22 13:58:52 GMT
2024-03-22 13:58:53.167 GMT [2160][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:53.243 GMT [1272][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50456
2024-03-22 13:58:53.249 GMT [1272][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: tlsv1 alert unknown ca
2024-03-22 13:58:53.415 GMT [7968][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50458
2024-03-22 13:58:53.422 GMT [7968][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-22 13:58:53.422 GMT [7968][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-22 13:58:53.435 GMT [7968][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-22 13:58:53.438 GMT [7968][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50458
2024-03-22 13:58:53.524 GMT [6172][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50459
2024-03-22 13:58:53.606 GMT [2160][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:53.606 GMT [2160][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:53.611 GMT [2160][postmaster] LOG:  background worker "logical replication launcher" (PID 6444) exited with exit code 1
2024-03-22 13:58:53.611 GMT [7364][checkpointer] LOG:  shutting down
2024-03-22 13:58:53.611 GMT [7364][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:53.615 GMT [7364][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/4080EB8, redo lsn=0/4080EB8
2024-03-22 13:58:53.621 GMT [2160][postmaster] LOG:  database system is shut down
2024-03-22 13:58:53.767 GMT [3160][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:53.767 GMT [3160][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:53.768 GMT [3160][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:53.792 GMT [5568][startup] LOG:  database system was shut down at 2024-03-22 13:58:53 GMT
2024-03-22 13:58:53.801 GMT [3160][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:53.880 GMT [5792][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50460
2024-03-22 13:58:53.888 GMT [5792][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-22 13:58:53.888 GMT [5792][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-22 13:58:53.902 GMT [5792][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-22 13:58:53.906 GMT [5792][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50460
2024-03-22 13:58:54.004 GMT [6700][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50461
2024-03-22 13:58:54.010 GMT [6700][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-22 13:58:54.103 GMT [5140][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50462
2024-03-22 13:58:54.110 GMT [5140][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: sslv3 alert certificate revoked
2024-03-22 13:58:54.216 GMT [4792][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50463
2024-03-22 13:58:54.224 GMT [4792][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-22 13:58:54.224 GMT [4792][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-22 13:58:54.227 GMT [4792][client backend] [001_ssltests.pl][1/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-22 13:58:54.232 GMT [4792][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50463
2024-03-22 13:58:54.327 GMT [6648][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50464
2024-03-22 13:58:54.335 GMT [6648][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-22 13:58:54.335 GMT [6648][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-22 13:58:54.338 GMT [6648][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-22 13:58:54.341 GMT [6648][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.022 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50464
2024-03-22 13:58:54.623 GMT [6400][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50465
2024-03-22 13:58:54.631 GMT [6400][client backend] [[unknown]][3/1:0] FATAL:  connection requires a valid client certificate
2024-03-22 13:58:54.730 GMT [7280][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50467
2024-03-22 13:58:54.739 GMT [7280][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-22 13:58:54.739 GMT [7280][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-22 13:58:54.753 GMT [7280][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_Rkmj/client.key$$
2024-03-22 13:58:54.756 GMT [7280][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb host=pg-loadbalancetest port=50467
2024-03-22 13:58:54.835 GMT [3368][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50469
2024-03-22 13:58:54.846 GMT [3368][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-22 13:58:54.846 GMT [3368][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-22 13:58:54.849 GMT [3368][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_Rkmj/client-der.key$$
2024-03-22 13:58:54.852 GMT [3368][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.023 user=ssltestuser database=certdb host=pg-loadbalancetest port=50469
2024-03-22 13:58:54.904 GMT [8116][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50470
2024-03-22 13:58:54.915 GMT [8116][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-22 13:58:54.915 GMT [8116][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-22 13:58:54.918 GMT [8116][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_Rkmj/client-encrypted-pem.key sslpassword='dUmmyP^#+'$$
2024-03-22 13:58:54.921 GMT [8116][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=certdb host=pg-loadbalancetest port=50470
2024-03-22 13:58:55.012 GMT [5900][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50471
2024-03-22 13:58:55.022 GMT [5900][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-22 13:58:55.022 GMT [5900][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-22 13:58:55.026 GMT [5900][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_Rkmj/client-encrypted-der.key sslpassword='dUmmyP^#+'$$
2024-03-22 13:58:55.028 GMT [5900][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=certdb host=pg-loadbalancetest port=50471
2024-03-22 13:58:55.120 GMT [3656][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50473
2024-03-22 13:58:55.129 GMT [3656][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-22 13:58:55.129 GMT [3656][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-22 13:58:55.132 GMT [3656][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_Rkmj/client.key$$
2024-03-22 13:58:55.135 GMT [3656][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.021 user=ssltestuser database=certdb host=pg-loadbalancetest port=50473
2024-03-22 13:58:55.228 GMT [4172][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50474
2024-03-22 13:58:55.238 GMT [4172][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-22 13:58:55.238 GMT [4172][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-22 13:58:55.241 GMT [4172][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_Rkmj/client.key$$
2024-03-22 13:58:55.245 GMT [4172][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=ssltestuser database=certdb host=pg-loadbalancetest port=50474
2024-03-22 13:58:55.341 GMT [1392][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50475
2024-03-22 13:58:55.349 GMT [1392][client backend] [[unknown]][10/1:0] FATAL:  connection requires a valid client certificate
2024-03-22 13:58:55.452 GMT [5384][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50476
2024-03-22 13:58:55.467 GMT [5384][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: EOF detected
2024-03-22 13:58:55.558 GMT [4264][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50478
2024-03-22 13:58:55.569 GMT [4264][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-22 13:58:55.569 GMT [4264][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-22 13:58:55.582 GMT [4264][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_Rkmj/client-dn.key$$
2024-03-22 13:58:55.585 GMT [4264][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb_dn host=pg-loadbalancetest port=50478
2024-03-22 13:58:55.669 GMT [404][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50479
2024-03-22 13:58:55.680 GMT [404][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-22 13:58:55.680 GMT [404][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-22 13:58:55.694 GMT [404][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_Rkmj/client-dn.key$$
2024-03-22 13:58:55.698 GMT [404][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.038 user=ssltestuser database=certdb_dn_re host=pg-loadbalancetest port=50479
2024-03-22 13:58:55.780 GMT [1260][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50480
2024-03-22 13:58:55.790 GMT [1260][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-22 13:58:55.790 GMT [1260][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-22 13:58:55.802 GMT [1260][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_Rkmj/client-dn.key$$
2024-03-22 13:58:55.807 GMT [1260][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.035 user=ssltestuser database=certdb_cn host=pg-loadbalancetest port=50480
2024-03-22 13:58:55.897 GMT [3820][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50481
2024-03-22 13:58:55.907 GMT [3820][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-22 13:58:55.907 GMT [3820][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-22 13:58:55.910 GMT [3820][client backend] [001_ssltests.pl][14/2:0] LOG:  statement: SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2024-03-22 13:58:55.916 GMT [3820][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.027 user=ssltestuser database=certdb host=pg-loadbalancetest port=50481
2024-03-22 13:58:56.009 GMT [436][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50482
2024-03-22 13:58:56.019 GMT [436][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-22 13:58:56.019 GMT [436][client backend] [[unknown]][15/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-22 13:58:56.019 GMT [436][client backend] [[unknown]][15/1:0] FATAL:  certificate authentication failed for user "anotheruser"
2024-03-22 13:58:56.019 GMT [436][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-22 13:58:56.136 GMT [3876][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50483
2024-03-22 13:58:56.144 GMT [3876][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-22 13:58:56.144 GMT [3876][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-22 13:58:56.247 GMT [6692][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50484
2024-03-22 13:58:56.258 GMT [6692][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-22 13:58:56.258 GMT [6692][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-22 13:58:56.270 GMT [6692][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_Rkmj/client.key$$
2024-03-22 13:58:56.274 GMT [6692][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.037 user=ssltestuser database=verifydb host=pg-loadbalancetest port=50484
2024-03-22 13:58:56.357 GMT [4496][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50485
2024-03-22 13:58:56.367 GMT [4496][client backend] [[unknown]][17/1:0] LOG:  provided user name (anotheruser) and authenticated user name (ssltestuser) do not match
2024-03-22 13:58:56.367 GMT [4496][client backend] [[unknown]][17/1:0] LOG:  certificate validation (clientcert=verify-full) failed for user "anotheruser": CN mismatch
2024-03-22 13:58:56.367 GMT [4496][client backend] [[unknown]][17/1:0] FATAL:  "trust" authentication failed for user "anotheruser"
2024-03-22 13:58:56.367 GMT [4496][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-22 13:58:56.467 GMT [6884][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50486
2024-03-22 13:58:56.477 GMT [6884][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-22 13:58:56.477 GMT [6884][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-22 13:58:56.480 GMT [6884][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_Rkmj/client.key$$
2024-03-22 13:58:56.483 GMT [6884][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.024 user=yetanotheruser database=verifydb host=pg-loadbalancetest port=50486
2024-03-22 13:58:56.544 GMT [3160][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:56.545 GMT [3160][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:56.549 GMT [3160][postmaster] LOG:  background worker "logical replication launcher" (PID 672) exited with exit code 1
2024-03-22 13:58:56.550 GMT [2064][checkpointer] LOG:  shutting down
2024-03-22 13:58:56.550 GMT [2064][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:56.554 GMT [2064][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/4080F30, redo lsn=0/4080F30
2024-03-22 13:58:56.560 GMT [3160][postmaster] LOG:  database system is shut down
2024-03-22 13:58:56.708 GMT [3728][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:56.708 GMT [3728][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:56.710 GMT [3728][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:56.734 GMT [4852][startup] LOG:  database system was shut down at 2024-03-22 13:58:56 GMT
2024-03-22 13:58:56.743 GMT [3728][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:56.807 GMT [7680][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50487
2024-03-22 13:58:56.817 GMT [7680][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-22 13:58:56.817 GMT [7680][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-22 13:58:56.830 GMT [7680][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_Rkmj/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-22 13:58:56.834 GMT [7680][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.034 user=ssltestuser database=certdb host=pg-loadbalancetest port=50487
2024-03-22 13:58:56.914 GMT [7288][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50488
2024-03-22 13:58:56.922 GMT [7288][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-22 13:58:56.922 GMT [7288][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-22 13:58:57.027 GMT [676][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50489
2024-03-22 13:58:57.036 GMT [676][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-22 13:58:57.036 GMT [676][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-22 13:58:57.108 GMT [3728][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:57.108 GMT [3728][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:57.111 GMT [3728][postmaster] LOG:  background worker "logical replication launcher" (PID 1064) exited with exit code 1
2024-03-22 13:58:57.112 GMT [1312][checkpointer] LOG:  shutting down
2024-03-22 13:58:57.113 GMT [1312][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:57.116 GMT [1312][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/4080FA8, redo lsn=0/4080FA8
2024-03-22 13:58:57.120 GMT [3728][postmaster] LOG:  database system is shut down
2024-03-22 13:58:57.267 GMT [7868][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:57.267 GMT [7868][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:57.269 GMT [7868][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:57.289 GMT [7356][startup] LOG:  database system was shut down at 2024-03-22 13:58:57 GMT
2024-03-22 13:58:57.297 GMT [7868][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:57.373 GMT [7608][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50490
2024-03-22 13:58:57.382 GMT [7608][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-22 13:58:57.382 GMT [7608][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-22 13:58:57.452 GMT [7868][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:57.453 GMT [7868][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:57.457 GMT [7868][postmaster] LOG:  background worker "logical replication launcher" (PID 6468) exited with exit code 1
2024-03-22 13:58:57.457 GMT [7760][checkpointer] LOG:  shutting down
2024-03-22 13:58:57.458 GMT [7760][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:57.461 GMT [7760][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/4081020, redo lsn=0/4081020
2024-03-22 13:58:57.465 GMT [7868][postmaster] LOG:  database system is shut down
2024-03-22 13:58:57.619 GMT [7432][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:57.620 GMT [7432][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:57.621 GMT [7432][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:57.645 GMT [6376][startup] LOG:  database system was shut down at 2024-03-22 13:58:57 GMT
2024-03-22 13:58:57.654 GMT [7432][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:57.722 GMT [3748][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50491
2024-03-22 13:58:57.730 GMT [3748][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-22 13:58:57.730 GMT [3748][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-22 13:58:57.822 GMT [1988][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50492
2024-03-22 13:58:57.831 GMT [1988][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: certificate verify failed
2024-03-22 13:58:57.831 GMT [1988][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-22 13:58:57.907 GMT [7432][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:57.907 GMT [7432][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:57.913 GMT [7432][postmaster] LOG:  background worker "logical replication launcher" (PID 480) exited with exit code 1
2024-03-22 13:58:57.913 GMT [2192][checkpointer] LOG:  shutting down
2024-03-22 13:58:57.914 GMT [2192][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:57.917 GMT [2192][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/4081098, redo lsn=0/4081098
2024-03-22 13:58:57.923 GMT [7432][postmaster] LOG:  database system is shut down
2024-03-22 13:58:58.070 GMT [4028][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:58.070 GMT [4028][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:58.071 GMT [4028][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:58.092 GMT [2776][startup] LOG:  database system was shut down at 2024-03-22 13:58:57 GMT
2024-03-22 13:58:58.104 GMT [4028][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:58.178 GMT [6992][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50493
2024-03-22 13:58:58.182 GMT [6992][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:58:58.182 GMT [6992][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:58:58.287 GMT [5124][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50494
2024-03-22 13:58:58.295 GMT [5124][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-22 13:58:58.295 GMT [5124][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-22 13:58:58.308 GMT [5124][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-22 13:58:58.316 GMT [5124][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.037 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50494
2024-03-22 13:58:58.366 GMT [4028][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:58.366 GMT [4028][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:58.372 GMT [4028][postmaster] LOG:  background worker "logical replication launcher" (PID 1680) exited with exit code 1
2024-03-22 13:58:58.372 GMT [1540][checkpointer] LOG:  shutting down
2024-03-22 13:58:58.372 GMT [1540][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:58.375 GMT [1540][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/4081110, redo lsn=0/4081110
2024-03-22 13:58:58.380 GMT [4028][postmaster] LOG:  database system is shut down
2024-03-22 13:58:58.528 GMT [5912][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:58.529 GMT [5912][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:58.530 GMT [5912][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:58.550 GMT [3940][startup] LOG:  database system was shut down at 2024-03-22 13:58:58 GMT
2024-03-22 13:58:58.558 GMT [5912][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:58.621 GMT [4104][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50495
2024-03-22 13:58:58.624 GMT [4104][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:58:58.624 GMT [4104][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:58:58.736 GMT [7748][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50496
2024-03-22 13:58:58.744 GMT [7748][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-22 13:58:58.744 GMT [7748][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-22 13:58:58.768 GMT [7748][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-22 13:58:58.771 GMT [7748][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.042 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50496
2024-03-22 13:58:58.830 GMT [5912][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:58.830 GMT [5912][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:58.835 GMT [5912][postmaster] LOG:  background worker "logical replication launcher" (PID 6596) exited with exit code 1
2024-03-22 13:58:58.835 GMT [2196][checkpointer] LOG:  shutting down
2024-03-22 13:58:58.836 GMT [2196][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:58.839 GMT [2196][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/4081188, redo lsn=0/4081188
2024-03-22 13:58:58.844 GMT [5912][postmaster] LOG:  database system is shut down
2024-03-22 13:58:58.996 GMT [6100][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:58.996 GMT [6100][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:58.997 GMT [6100][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:59.023 GMT [7352][startup] LOG:  database system was shut down at 2024-03-22 13:58:58 GMT
2024-03-22 13:58:59.030 GMT [6100][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:59.087 GMT [7588][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50497
2024-03-22 13:58:59.090 GMT [7588][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:58:59.091 GMT [7588][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:58:59.153 GMT [7512][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50498
2024-03-22 13:58:59.161 GMT [7512][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-22 13:58:59.161 GMT [7512][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-22 13:58:59.174 GMT [7512][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-22 13:58:59.177 GMT [7512][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50498
2024-03-22 13:58:59.237 GMT [6100][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:59.237 GMT [6100][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:59.243 GMT [6100][postmaster] LOG:  background worker "logical replication launcher" (PID 3260) exited with exit code 1
2024-03-22 13:58:59.243 GMT [4816][checkpointer] LOG:  shutting down
2024-03-22 13:58:59.244 GMT [4816][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:59.247 GMT [4816][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/4081200, redo lsn=0/4081200
2024-03-22 13:58:59.252 GMT [6100][postmaster] LOG:  database system is shut down
2024-03-22 13:58:59.401 GMT [1844][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:59.401 GMT [1844][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:59.402 GMT [1844][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:59.422 GMT [5988][startup] LOG:  database system was shut down at 2024-03-22 13:58:59 GMT
2024-03-22 13:58:59.430 GMT [1844][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:59.492 GMT [7932][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50499
2024-03-22 13:58:59.495 GMT [7932][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:58:59.495 GMT [7932][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:58:59.559 GMT [956][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50500
2024-03-22 13:58:59.567 GMT [956][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-22 13:58:59.567 GMT [956][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-22 13:58:59.579 GMT [956][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-22 13:58:59.582 GMT [956][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.031 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50500
2024-03-22 13:58:59.644 GMT [1844][postmaster] LOG:  received fast shutdown request
2024-03-22 13:58:59.644 GMT [1844][postmaster] LOG:  aborting any active transactions
2024-03-22 13:58:59.650 GMT [1844][postmaster] LOG:  background worker "logical replication launcher" (PID 1912) exited with exit code 1
2024-03-22 13:58:59.651 GMT [6108][checkpointer] LOG:  shutting down
2024-03-22 13:58:59.651 GMT [6108][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:58:59.654 GMT [6108][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/4081278, redo lsn=0/4081278
2024-03-22 13:58:59.660 GMT [1844][postmaster] LOG:  database system is shut down
2024-03-22 13:58:59.806 GMT [2144][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:58:59.807 GMT [2144][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:58:59.808 GMT [2144][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:58:59.834 GMT [4716][startup] LOG:  database system was shut down at 2024-03-22 13:58:59 GMT
2024-03-22 13:58:59.843 GMT [2144][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:58:59.906 GMT [5640][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50501
2024-03-22 13:58:59.909 GMT [5640][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:58:59.909 GMT [5640][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:59:00.015 GMT [7328][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50502
2024-03-22 13:59:00.022 GMT [7328][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-22 13:59:00.023 GMT [7328][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-22 13:59:00.035 GMT [7328][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-22 13:59:00.037 GMT [7328][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50502
2024-03-22 13:59:00.096 GMT [2144][postmaster] LOG:  received fast shutdown request
2024-03-22 13:59:00.096 GMT [2144][postmaster] LOG:  aborting any active transactions
2024-03-22 13:59:00.101 GMT [2144][postmaster] LOG:  background worker "logical replication launcher" (PID 7940) exited with exit code 1
2024-03-22 13:59:00.102 GMT [3992][checkpointer] LOG:  shutting down
2024-03-22 13:59:00.102 GMT [3992][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:59:00.105 GMT [3992][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/40812F0, redo lsn=0/40812F0
2024-03-22 13:59:00.110 GMT [2144][postmaster] LOG:  database system is shut down
2024-03-22 13:59:00.259 GMT [6740][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:59:00.259 GMT [6740][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:59:00.261 GMT [6740][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:59:00.285 GMT [1596][startup] LOG:  database system was shut down at 2024-03-22 13:59:00 GMT
2024-03-22 13:59:00.294 GMT [6740][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:59:00.356 GMT [5924][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50503
2024-03-22 13:59:00.360 GMT [5924][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:59:00.360 GMT [5924][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:59:00.419 GMT [3936][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50504
2024-03-22 13:59:00.427 GMT [3936][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-22 13:59:00.427 GMT [3936][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-22 13:59:00.439 GMT [3936][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-22 13:59:00.441 GMT [3936][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50504
2024-03-22 13:59:00.503 GMT [6740][postmaster] LOG:  received fast shutdown request
2024-03-22 13:59:00.503 GMT [6740][postmaster] LOG:  aborting any active transactions
2024-03-22 13:59:00.507 GMT [6740][postmaster] LOG:  background worker "logical replication launcher" (PID 2972) exited with exit code 1
2024-03-22 13:59:00.507 GMT [3684][checkpointer] LOG:  shutting down
2024-03-22 13:59:00.507 GMT [3684][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:59:00.510 GMT [3684][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/4081368, redo lsn=0/4081368
2024-03-22 13:59:00.515 GMT [6740][postmaster] LOG:  database system is shut down
2024-03-22 13:59:00.665 GMT [4392][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:59:00.665 GMT [4392][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:59:00.666 GMT [4392][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:59:00.687 GMT [592][startup] LOG:  database system was shut down at 2024-03-22 13:59:00 GMT
2024-03-22 13:59:00.696 GMT [4392][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:59:00.762 GMT [6840][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50505
2024-03-22 13:59:00.765 GMT [6840][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:59:00.766 GMT [6840][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:59:00.826 GMT [1508][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50506
2024-03-22 13:59:00.834 GMT [1508][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-22 13:59:00.834 GMT [1508][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-22 13:59:00.848 GMT [1508][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-22 13:59:00.851 GMT [1508][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.033 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50506
2024-03-22 13:59:00.907 GMT [4392][postmaster] LOG:  received fast shutdown request
2024-03-22 13:59:00.907 GMT [4392][postmaster] LOG:  aborting any active transactions
2024-03-22 13:59:00.911 GMT [4392][postmaster] LOG:  background worker "logical replication launcher" (PID 3368) exited with exit code 1
2024-03-22 13:59:00.911 GMT [3588][checkpointer] LOG:  shutting down
2024-03-22 13:59:00.912 GMT [3588][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:59:00.916 GMT [3588][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/40813E0, redo lsn=0/40813E0
2024-03-22 13:59:00.922 GMT [4392][postmaster] LOG:  database system is shut down
2024-03-22 13:59:01.075 GMT [5348][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:59:01.075 GMT [5348][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:59:01.077 GMT [5348][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:59:01.100 GMT [2184][startup] LOG:  database system was shut down at 2024-03-22 13:59:00 GMT
2024-03-22 13:59:01.107 GMT [5348][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:59:01.164 GMT [3952][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50507
2024-03-22 13:59:01.167 GMT [3952][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:59:01.167 GMT [3952][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:59:01.230 GMT [6052][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50508
2024-03-22 13:59:01.238 GMT [6052][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-22 13:59:01.238 GMT [6052][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-22 13:59:01.251 GMT [6052][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-22 13:59:01.254 GMT [6052][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.030 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50508
2024-03-22 13:59:01.312 GMT [5348][postmaster] LOG:  received fast shutdown request
2024-03-22 13:59:01.313 GMT [5348][postmaster] LOG:  aborting any active transactions
2024-03-22 13:59:01.316 GMT [5348][postmaster] LOG:  background worker "logical replication launcher" (PID 4588) exited with exit code 1
2024-03-22 13:59:01.317 GMT [4336][checkpointer] LOG:  shutting down
2024-03-22 13:59:01.317 GMT [4336][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:59:01.320 GMT [4336][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/4081458, redo lsn=0/4081458
2024-03-22 13:59:01.324 GMT [5348][postmaster] LOG:  database system is shut down
2024-03-22 13:59:01.496 GMT [4820][postmaster] LOG:  starting PostgreSQL 17devel on x86_64-windows, compiled by msvc-19.29.30151, 64-bit
2024-03-22 13:59:01.496 GMT [4820][postmaster] LOG:  listening on IPv4 address "127.0.0.1", port 63919
2024-03-22 13:59:01.497 GMT [4820][postmaster] LOG:  listening on Unix socket "C:/Windows/TEMP/Gn9eQm77zV/.s.PGSQL.63919"
2024-03-22 13:59:01.527 GMT [3876][startup] LOG:  database system was shut down at 2024-03-22 13:59:01 GMT
2024-03-22 13:59:01.536 GMT [4820][postmaster] LOG:  database system is ready to accept connections
2024-03-22 13:59:01.685 GMT [7936][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50509
2024-03-22 13:59:01.689 GMT [7936][not initialized] [[unknown]][:0] WARNING:  could not read ssl_ocsp_file
2024-03-22 13:59:01.689 GMT [7936][not initialized] [[unknown]][:0] LOG:  could not accept SSL connection: A non-blocking socket operation could not be completed immediately.
	
2024-03-22 13:59:01.800 GMT [6868][not initialized] [[unknown]][:0] LOG:  connection received: host=pg-loadbalancetest port=50510
2024-03-22 13:59:01.807 GMT [6868][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-22 13:59:01.807 GMT [6868][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-22 13:59:01.818 GMT [6868][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-22 13:59:01.822 GMT [6868][client backend] [001_ssltests.pl][:0] LOG:  disconnection: session time: 0:00:00.029 user=ssltestuser database=trustdb host=pg-loadbalancetest port=50510
2024-03-22 13:59:01.880 GMT [4820][postmaster] LOG:  received fast shutdown request
2024-03-22 13:59:01.880 GMT [4820][postmaster] LOG:  aborting any active transactions
2024-03-22 13:59:01.887 GMT [4820][postmaster] LOG:  background worker "logical replication launcher" (PID 1116) exited with exit code 1
2024-03-22 13:59:01.887 GMT [8064][checkpointer] LOG:  shutting down
2024-03-22 13:59:01.887 GMT [8064][checkpointer] LOG:  checkpoint starting: shutdown immediate
2024-03-22 13:59:01.889 GMT [8064][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/40814D0, redo lsn=0/40814D0
2024-03-22 13:59:01.893 GMT [4820][postmaster] LOG:  database system is shut down
2024-03-22 13:59:02.026 GMT [6168][postmaster] FATAL:  could not load server certificate file "server-ip-cn-only+server_ca.crt": No such file or directory
2024-03-22 13:59:02.026 GMT [6168][postmaster] LOG:  database system is shut down
# No postmaster PID for node "primary"
[13:59:02.096](0.237s) Bail out!  pg_ctl restart failed
# No postmaster PID for node "primary"