BUG #17391: While using --with-ssl=openssl and PG_TEST_EXTRA='ssl' options, SSL tests fail on OpenBSD 7.0
The following bug has been logged on the website:
Bug reference: 17391
Logged by: Nazir Bilal Yavuz
Email address: byavuz81@gmail.com
PostgreSQL version: 14.1
Operating system: OpenBSD 7.0
Description:
Hi,
While installing PostgreSQL from source code, SSL tests fail on OpenBSD
7.0.
The commands I used are:
./configure \
--enable-tap-tests \
--with-ssl=openssl \
\
--with-includes=/usr/local/include --with-libs=/usr/local/lib && \
gmake -s world-bin && gmake -s check-world PG_TEST_EXTRA='ssl'
OS:
OpenBSD openbsd-host.my.domain 7.0 GENERIC#224 amd64
OpenSSL Version:
LibreSSL 3.4.1
Error message:
t/001_ssltests.pl (Wstat: 5632 Tests: 110 Failed: 22)
t/002_scram.pl (Wstat: 1792 Tests: 11 Failed: 7)
t/003_sslinfo.pl (Wstat: 7424 Tests: 1 Failed: 1)
Example Logs(001_ssltests_primary.log and regress_log_001_ssltests):
001_ssltests_primary.log:
2022-02-03 00:26:51.127 +03 [88304] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:26:51.127 +03 [88304] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:26:51.147 +03 [63726] LOG: database system was shut down at
2022-02-03 00:26:51 +03
2022-02-03 00:26:51.149 +03 [88304] LOG: database system is ready to accept
connections
2022-02-03 00:26:51.172 +03 [59203] 001_ssltests.pl LOG: statement: SHOW
ssl_library
2022-02-03 00:26:51.230 +03 [30464] 001_ssltests.pl LOG: statement: CREATE
USER ssltestuser
2022-02-03 00:26:51.278 +03 [14697] 001_ssltests.pl LOG: statement: CREATE
USER md5testuser
2022-02-03 00:26:51.302 +03 [3601] 001_ssltests.pl LOG: statement: CREATE
USER anotheruser
2022-02-03 00:26:51.327 +03 [63049] 001_ssltests.pl LOG: statement: CREATE
USER yetanotheruser
2022-02-03 00:26:51.533 +03 [3961] 001_ssltests.pl LOG: statement: CREATE
DATABASE trustdb
2022-02-03 00:26:51.533 +03 [89906] LOG: checkpoint starting: immediate
force wait flush-all
2022-02-03 00:26:51.535 +03 [89906] LOG: checkpoint complete: wrote 10
buffers (0.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=4 kB, estimate=4 kB
2022-02-03 00:26:52.959 +03 [89906] LOG: checkpoint starting: immediate
force wait
2022-02-03 00:26:52.959 +03 [89906] LOG: checkpoint complete: wrote 0
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=4 kB
2022-02-03 00:26:53.282 +03 [17946] 001_ssltests.pl LOG: statement: CREATE
DATABASE certdb
2022-02-03 00:26:53.283 +03 [89906] LOG: checkpoint starting: immediate
force wait flush-all
2022-02-03 00:26:53.284 +03 [89906] LOG: checkpoint complete: wrote 4
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=1 kB, estimate=4 kB
2022-02-03 00:26:53.586 +03 [89906] LOG: checkpoint starting: immediate
force wait
2022-02-03 00:26:53.587 +03 [89906] LOG: checkpoint complete: wrote 0
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=3 kB
2022-02-03 00:26:53.679 +03 [69142] 001_ssltests.pl LOG: statement: CREATE
DATABASE certdb_dn
2022-02-03 00:26:53.679 +03 [89906] LOG: checkpoint starting: immediate
force wait flush-all
2022-02-03 00:26:53.680 +03 [89906] LOG: checkpoint complete: wrote 4
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=1 kB, estimate=3 kB
2022-02-03 00:26:54.163 +03 [89906] LOG: checkpoint starting: immediate
force wait
2022-02-03 00:26:54.163 +03 [89906] LOG: checkpoint complete: wrote 0
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=3 kB
2022-02-03 00:26:54.597 +03 [87708] 001_ssltests.pl LOG: statement: CREATE
DATABASE certdb_dn_re
2022-02-03 00:26:54.597 +03 [89906] LOG: checkpoint starting: immediate
force wait flush-all
2022-02-03 00:26:54.598 +03 [89906] LOG: checkpoint complete: wrote 4
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=1 kB, estimate=3 kB
2022-02-03 00:26:54.730 +03 [89906] LOG: checkpoint starting: immediate
force wait
2022-02-03 00:26:54.730 +03 [89906] LOG: checkpoint complete: wrote 0
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=2 kB
2022-02-03 00:26:54.874 +03 [73405] 001_ssltests.pl LOG: statement: CREATE
DATABASE certdb_cn
2022-02-03 00:26:54.881 +03 [89906] LOG: checkpoint starting: immediate
force wait flush-all
2022-02-03 00:26:54.882 +03 [89906] LOG: checkpoint complete: wrote 4
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=2 kB, estimate=2 kB
2022-02-03 00:26:54.951 +03 [89906] LOG: checkpoint starting: immediate
force wait
2022-02-03 00:26:54.951 +03 [89906] LOG: checkpoint complete: wrote 0
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=2 kB
2022-02-03 00:26:55.254 +03 [83428] 001_ssltests.pl LOG: statement: CREATE
DATABASE verifydb
2022-02-03 00:26:55.254 +03 [89906] LOG: checkpoint starting: immediate
force wait flush-all
2022-02-03 00:26:55.257 +03 [89906] LOG: checkpoint complete: wrote 4
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=2 kB, estimate=2 kB
2022-02-03 00:26:55.362 +03 [89906] LOG: checkpoint starting: immediate
force wait
2022-02-03 00:26:55.363 +03 [89906] LOG: checkpoint complete: wrote 0
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.001 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=2 kB
2022-02-03 00:26:55.542 +03 [88304] LOG: received fast shutdown request
2022-02-03 00:26:55.542 +03 [88304] LOG: aborting any active transactions
2022-02-03 00:26:55.544 +03 [88304] LOG: background worker "logical
replication launcher" (PID 56614) exited with exit code 1
2022-02-03 00:26:55.544 +03 [89906] LOG: shutting down
2022-02-03 00:26:55.544 +03 [89906] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:26:55.548 +03 [89906] LOG: checkpoint complete: wrote 1
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.000 s,
sync=0.000 s, total=0.004 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=2 kB
2022-02-03 00:26:55.553 +03 [88304] LOG: database system is shut down
2022-02-03 00:26:55.603 +03 [80056] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:26:55.603 +03 [80056] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:26:55.620 +03 [80056] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:26:55.678 +03 [41931] LOG: database system was shut down at
2022-02-03 00:26:55 +03
2022-02-03 00:26:55.688 +03 [80056] LOG: database system is ready to accept
connections
2022-02-03 00:26:55.825 +03 [80056] LOG: received fast shutdown request
2022-02-03 00:26:55.825 +03 [80056] LOG: aborting any active transactions
2022-02-03 00:26:55.827 +03 [80056] LOG: background worker "logical
replication launcher" (PID 65521) exited with exit code 1
2022-02-03 00:26:55.827 +03 [87556] LOG: shutting down
2022-02-03 00:26:55.827 +03 [87556] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:26:55.829 +03 [87556] LOG: checkpoint complete: wrote 4
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:26:55.832 +03 [80056] LOG: database system is shut down
2022-02-03 00:26:55.902 +03 [26092] FATAL: could not load private key file
"server-password.key": bad decrypt
2022-02-03 00:26:55.902 +03 [26092] LOG: database system is shut down
2022-02-03 00:26:56.194 +03 [59483] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:26:56.194 +03 [59483] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:26:56.194 +03 [59483] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:26:56.274 +03 [91273] LOG: database system was shut down at
2022-02-03 00:26:55 +03
2022-02-03 00:26:56.279 +03 [59483] LOG: database system is ready to accept
connections
2022-02-03 00:26:56.507 +03 [59483] LOG: received fast shutdown request
2022-02-03 00:26:56.507 +03 [59483] LOG: aborting any active transactions
2022-02-03 00:26:56.509 +03 [59483] LOG: background worker "logical
replication launcher" (PID 21939) exited with exit code 1
2022-02-03 00:26:56.509 +03 [9455] LOG: shutting down
2022-02-03 00:26:56.509 +03 [9455] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:26:56.511 +03 [9455] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:26:56.515 +03 [59483] LOG: database system is shut down
2022-02-03 00:26:56.794 +03 [45020] FATAL: could not set maximum SSL
protocol version
2022-02-03 00:26:56.794 +03 [45020] LOG: database system is shut down
2022-02-03 00:26:56.990 +03 [56065] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:26:56.991 +03 [56065] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:26:56.991 +03 [56065] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:26:57.015 +03 [99076] LOG: database system was shut down at
2022-02-03 00:26:56 +03
2022-02-03 00:26:57.017 +03 [56065] LOG: database system is ready to accept
connections
2022-02-03 00:26:57.107 +03 [56065] LOG: received fast shutdown request
2022-02-03 00:26:57.107 +03 [56065] LOG: aborting any active transactions
2022-02-03 00:26:57.109 +03 [56065] LOG: background worker "logical
replication launcher" (PID 34941) exited with exit code 1
2022-02-03 00:26:57.109 +03 [33335] LOG: shutting down
2022-02-03 00:26:57.109 +03 [33335] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:26:57.110 +03 [33335] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:26:57.115 +03 [56065] LOG: database system is shut down
2022-02-03 00:26:57.161 +03 [87966] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:26:57.162 +03 [87966] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:26:57.162 +03 [87966] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:26:57.187 +03 [29490] LOG: database system was shut down at
2022-02-03 00:26:57 +03
2022-02-03 00:26:57.194 +03 [87966] LOG: database system is ready to accept
connections
2022-02-03 00:26:57.262 +03 [68121] [unknown] LOG: connection received:
host=localhost port=41336
2022-02-03 00:26:57.268 +03 [68121] [unknown] FATAL: no pg_hba.conf entry
for host "127.0.0.1", user "ssltestuser", database "trustdb", no
encryption
2022-02-03 00:26:57.268 +03 [68121] [unknown] DETAIL: Client IP address
resolved to "localhost", forward lookup not checked.
2022-02-03 00:26:57.328 +03 [84039] [unknown] LOG: connection received:
host=localhost port=12182
2022-02-03 00:26:57.361 +03 [84039] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:26:57.376 +03 [84039] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test sslrootcert=invalid
sslmode=require$$
2022-02-03 00:26:57.415 +03 [76636] [unknown] LOG: connection received:
host=localhost port=49071
2022-02-03 00:26:57.442 +03 [76636] [unknown] LOG: could not accept SSL
connection: EOF detected
2022-02-03 00:26:57.469 +03 [63906] [unknown] LOG: connection received:
host=localhost port=29901
2022-02-03 00:26:57.488 +03 [63906] [unknown] LOG: could not accept SSL
connection: EOF detected
2022-02-03 00:26:57.550 +03 [57856] [unknown] LOG: connection received:
host=localhost port=9741
2022-02-03 00:26:57.574 +03 [57856] [unknown] LOG: could not accept SSL
connection: tlsv1 alert unknown ca
2022-02-03 00:26:57.609 +03 [10201] [unknown] LOG: connection received:
host=localhost port=29429
2022-02-03 00:26:57.653 +03 [10201] [unknown] LOG: could not accept SSL
connection: tlsv1 alert unknown ca
2022-02-03 00:26:57.690 +03 [22036] [unknown] LOG: connection received:
host=localhost port=22975
2022-02-03 00:26:57.784 +03 [22036] [unknown] LOG: could not accept SSL
connection: tlsv1 alert unknown ca
2022-02-03 00:26:57.823 +03 [42487] [unknown] LOG: connection received:
host=localhost port=45404
2022-02-03 00:26:57.859 +03 [42487] [unknown] LOG: could not accept SSL
connection: tlsv1 alert unknown ca
2022-02-03 00:26:57.967 +03 [80741] [unknown] LOG: connection received:
host=localhost port=6033
2022-02-03 00:26:58.065 +03 [80741] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:26:58.078 +03 [80741] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=ssl/root+server_ca.crt sslmode=require$$
2022-02-03 00:26:58.149 +03 [89578] [unknown] LOG: connection received:
host=localhost port=48381
2022-02-03 00:26:58.262 +03 [89578] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:26:58.269 +03 [89578] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca$$
2022-02-03 00:26:58.412 +03 [55012] [unknown] LOG: connection received:
host=localhost port=28357
2022-02-03 00:26:58.566 +03 [55012] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:26:58.595 +03 [55012] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=ssl/root+server_ca.crt sslmode=verify-full$$
2022-02-03 00:26:58.831 +03 [28146] [unknown] LOG: connection received:
host=localhost port=24203
2022-02-03 00:26:59.245 +03 [28146] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:26:59.293 +03 [28146] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=ssl/both-cas-1.crt sslmode=verify-ca$$
2022-02-03 00:26:59.403 +03 [68249] [unknown] LOG: connection received:
host=localhost port=31654
2022-02-03 00:26:59.614 +03 [68249] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:26:59.616 +03 [68249] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=ssl/both-cas-2.crt sslmode=verify-ca$$
2022-02-03 00:26:59.784 +03 [48189] [unknown] LOG: connection received:
host=localhost port=29141
2022-02-03 00:27:00.017 +03 [48189] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:00.033 +03 [48189] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca sslcrl=invalid$$
2022-02-03 00:27:00.156 +03 [66329] [unknown] LOG: connection received:
host=localhost port=18238
2022-02-03 00:27:00.324 +03 [66329] [unknown] LOG: could not accept SSL
connection: tlsv1 alert unknown ca
2022-02-03 00:27:00.491 +03 [24932] [unknown] LOG: connection received:
host=localhost port=24603
2022-02-03 00:27:00.569 +03 [24932] [unknown] LOG: could not accept SSL
connection: tlsv1 alert unknown ca
2022-02-03 00:27:00.856 +03 [37114] [unknown] LOG: connection received:
host=localhost port=30183
2022-02-03 00:27:01.150 +03 [37114] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:01.183 +03 [37114] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
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$$
2022-02-03 00:27:01.246 +03 [67656] [unknown] LOG: connection received:
host=localhost port=42539
2022-02-03 00:27:01.333 +03 [67656] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:01.337 +03 [67656] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
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$$
2022-02-03 00:27:01.398 +03 [52851] [unknown] LOG: connection received:
host=localhost port=41360
2022-02-03 00:27:01.484 +03 [52851] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:01.498 +03 [52851] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=require
host=wronghost.test$$
2022-02-03 00:27:01.585 +03 [40160] [unknown] LOG: connection received:
host=localhost port=37625
2022-02-03 00:27:01.987 +03 [40160] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:02.047 +03 [40160] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-ca
host=wronghost.test$$
2022-02-03 00:27:02.189 +03 [61439] [unknown] LOG: connection received:
host=localhost port=42493
2022-02-03 00:27:02.436 +03 [87966] LOG: received fast shutdown request
2022-02-03 00:27:02.436 +03 [87966] LOG: aborting any active transactions
2022-02-03 00:27:02.441 +03 [87966] LOG: background worker "logical
replication launcher" (PID 15053) exited with exit code 1
2022-02-03 00:27:02.441 +03 [95537] LOG: shutting down
2022-02-03 00:27:02.441 +03 [95537] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:27:02.443 +03 [95537] LOG: checkpoint complete: wrote 4
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:27:02.451 +03 [87966] LOG: database system is shut down
2022-02-03 00:27:02.583 +03 [54211] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:27:02.583 +03 [54211] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:27:02.585 +03 [54211] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:27:02.632 +03 [33944] LOG: database system was shut down at
2022-02-03 00:27:02 +03
2022-02-03 00:27:02.681 +03 [54211] LOG: database system is ready to accept
connections
2022-02-03 00:27:02.854 +03 [5733] [unknown] LOG: connection received:
host=localhost port=32424
2022-02-03 00:27:02.993 +03 [5733] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:03.114 +03 [5733] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full
host=dns1.alt-name.pg-ssltest.test$$
2022-02-03 00:27:03.205 +03 [87701] [unknown] LOG: connection received:
host=localhost port=15430
2022-02-03 00:27:03.314 +03 [87701] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:03.326 +03 [87701] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full
host=dns2.alt-name.pg-ssltest.test$$
2022-02-03 00:27:03.472 +03 [99455] [unknown] LOG: connection received:
host=localhost port=13487
2022-02-03 00:27:03.668 +03 [99455] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:03.694 +03 [99455] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full
host=foo.wildcard.pg-ssltest.test$$
2022-02-03 00:27:03.958 +03 [56631] [unknown] LOG: connection received:
host=localhost port=17831
2022-02-03 00:27:04.300 +03 [35125] [unknown] LOG: connection received:
host=localhost port=48918
2022-02-03 00:27:04.949 +03 [54211] LOG: received fast shutdown request
2022-02-03 00:27:04.949 +03 [54211] LOG: aborting any active transactions
2022-02-03 00:27:04.953 +03 [54211] LOG: background worker "logical
replication launcher" (PID 38490) exited with exit code 1
2022-02-03 00:27:04.953 +03 [69508] LOG: shutting down
2022-02-03 00:27:04.953 +03 [69508] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:27:04.955 +03 [69508] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:27:04.961 +03 [54211] LOG: database system is shut down
2022-02-03 00:27:06.096 +03 [65102] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:27:06.096 +03 [65102] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:27:06.097 +03 [65102] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:27:06.123 +03 [9859] LOG: database system was shut down at
2022-02-03 00:27:04 +03
2022-02-03 00:27:06.131 +03 [65102] LOG: database system is ready to accept
connections
2022-02-03 00:27:06.410 +03 [10840] [unknown] LOG: connection received:
host=localhost port=10396
2022-02-03 00:27:07.129 +03 [10840] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:07.182 +03 [10840] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full
host=single.alt-name.pg-ssltest.test$$
2022-02-03 00:27:07.417 +03 [18339] [unknown] LOG: connection received:
host=localhost port=45593
2022-02-03 00:27:07.757 +03 [38783] [unknown] LOG: connection received:
host=localhost port=43413
2022-02-03 00:27:07.977 +03 [65102] LOG: received fast shutdown request
2022-02-03 00:27:07.977 +03 [65102] LOG: aborting any active transactions
2022-02-03 00:27:07.980 +03 [65102] LOG: background worker "logical
replication launcher" (PID 75820) exited with exit code 1
2022-02-03 00:27:07.980 +03 [39362] LOG: shutting down
2022-02-03 00:27:07.980 +03 [39362] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:27:07.981 +03 [39362] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:27:07.985 +03 [65102] LOG: database system is shut down
2022-02-03 00:27:08.117 +03 [28120] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:27:08.117 +03 [28120] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:27:08.117 +03 [28120] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:27:08.134 +03 [76752] LOG: database system was shut down at
2022-02-03 00:27:07 +03
2022-02-03 00:27:08.136 +03 [28120] LOG: database system is ready to accept
connections
2022-02-03 00:27:08.300 +03 [7921] [unknown] LOG: connection received:
host=localhost port=1235
2022-02-03 00:27:08.575 +03 [7921] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:08.860 +03 [7921] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full
host=dns1.alt-name.pg-ssltest.test$$
2022-02-03 00:27:09.027 +03 [33529] [unknown] LOG: connection received:
host=localhost port=3769
2022-02-03 00:27:09.227 +03 [33529] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:09.234 +03 [33529] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-full
host=dns2.alt-name.pg-ssltest.test$$
2022-02-03 00:27:09.315 +03 [69195] [unknown] LOG: connection received:
host=localhost port=39582
2022-02-03 00:27:09.525 +03 [28120] LOG: received fast shutdown request
2022-02-03 00:27:09.525 +03 [28120] LOG: aborting any active transactions
2022-02-03 00:27:09.528 +03 [28120] LOG: background worker "logical
replication launcher" (PID 61885) exited with exit code 1
2022-02-03 00:27:09.528 +03 [4767] LOG: shutting down
2022-02-03 00:27:09.529 +03 [4767] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:27:09.530 +03 [4767] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:27:09.535 +03 [28120] LOG: database system is shut down
2022-02-03 00:27:09.707 +03 [50785] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:27:09.707 +03 [50785] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:27:09.707 +03 [50785] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:27:09.742 +03 [24937] LOG: database system was shut down at
2022-02-03 00:27:09 +03
2022-02-03 00:27:09.754 +03 [50785] LOG: database system is ready to accept
connections
2022-02-03 00:27:09.862 +03 [70733] [unknown] LOG: connection received:
host=localhost port=31324
2022-02-03 00:27:09.971 +03 [70733] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:09.992 +03 [70733] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
sslrootcert=ssl/root+server_ca.crt hostaddr=127.0.0.1 sslmode=verify-ca
host=common-name.pg-ssltest.test$$
2022-02-03 00:27:10.151 +03 [42736] [unknown] LOG: connection received:
host=localhost port=11626
2022-02-03 00:27:10.338 +03 [50785] LOG: received fast shutdown request
2022-02-03 00:27:10.338 +03 [50785] LOG: aborting any active transactions
2022-02-03 00:27:10.340 +03 [50785] LOG: background worker "logical
replication launcher" (PID 25760) exited with exit code 1
2022-02-03 00:27:10.340 +03 [63437] LOG: shutting down
2022-02-03 00:27:10.340 +03 [63437] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:27:10.343 +03 [63437] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 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
2022-02-03 00:27:10.348 +03 [50785] LOG: database system is shut down
2022-02-03 00:27:10.444 +03 [83429] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:27:10.444 +03 [83429] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:27:10.444 +03 [83429] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:27:10.459 +03 [64141] LOG: database system was shut down at
2022-02-03 00:27:10 +03
2022-02-03 00:27:10.461 +03 [83429] LOG: database system is ready to accept
connections
2022-02-03 00:27:10.598 +03 [59512] [unknown] LOG: connection received:
host=localhost port=36151
2022-02-03 00:27:10.660 +03 [59512] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:10.870 +03 [59512] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=ssl/root+server_ca.crt sslmode=verify-ca$$
2022-02-03 00:27:10.998 +03 [44649] [unknown] LOG: connection received:
host=localhost port=3558
2022-02-03 00:27:11.336 +03 [44649] [unknown] LOG: could not accept SSL
connection: sslv3 alert certificate revoked
2022-02-03 00:27:11.430 +03 [36439] [unknown] LOG: connection received:
host=localhost port=12757
2022-02-03 00:27:11.472 +03 [36439] [unknown] LOG: could not accept SSL
connection: sslv3 alert certificate revoked
2022-02-03 00:27:11.543 +03 [27312] [unknown] LOG: connection received:
host=localhost port=22355
2022-02-03 00:27:11.838 +03 [27312] [unknown] LOG: connection authorized:
user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL
enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
2022-02-03 00:27:11.897 +03 [27312] 001_ssltests.pl LOG: statement: SELECT
* FROM pg_stat_ssl WHERE pid = pg_backend_pid()
2022-02-03 00:27:12.189 +03 [52690] [unknown] LOG: connection received:
host=localhost port=23076
2022-02-03 00:27:12.245 +03 [52690] [unknown] 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)
2022-02-03 00:27:12.256 +03 [52690] 001_ssltests.pl LOG: statement: SELECT
$$connected with user=ssltestuser dbname=trustdb sslcert=invalid
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$$
2022-02-03 00:27:12.793 +03 [36971] [unknown] LOG: connection received:
host=localhost port=2717
2022-02-03 00:27:12.851 +03 [36971] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:13.139 +03 [67032] [unknown] LOG: connection received:
host=localhost port=14305
2022-02-03 00:27:13.215 +03 [67032] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:13.390 +03 [67442] [unknown] LOG: connection received:
host=localhost port=13873
2022-02-03 00:27:13.434 +03 [67442] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:13.774 +03 [9375] [unknown] LOG: connection received:
host=localhost port=20439
2022-02-03 00:27:13.834 +03 [9375] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:14.016 +03 [49711] [unknown] LOG: connection received:
host=localhost port=19814
2022-02-03 00:27:14.052 +03 [49711] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:14.292 +03 [28112] [unknown] LOG: connection received:
host=localhost port=44709
2022-02-03 00:27:14.356 +03 [28112] [unknown] LOG: could not accept SSL
connection: EOF detected
2022-02-03 00:27:14.421 +03 [73952] [unknown] LOG: connection received:
host=localhost port=26092
2022-02-03 00:27:14.433 +03 [73952] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:14.758 +03 [48484] [unknown] LOG: connection received:
host=localhost port=19155
2022-02-03 00:27:14.773 +03 [48484] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:14.839 +03 [74476] [unknown] LOG: connection received:
host=localhost port=20094
2022-02-03 00:27:14.851 +03 [74476] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:14.995 +03 [25958] [unknown] LOG: connection received:
host=localhost port=5219
2022-02-03 00:27:15.008 +03 [25958] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:15.127 +03 [60506] [unknown] LOG: connection received:
host=localhost port=41191
2022-02-03 00:27:15.159 +03 [60506] [unknown] LOG: could not accept SSL
connection: EOF detected
2022-02-03 00:27:15.207 +03 [395] [unknown] LOG: connection received:
host=localhost port=1925
2022-02-03 00:27:15.227 +03 [395] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:15.312 +03 [7195] [unknown] LOG: connection received:
host=localhost port=4367
2022-02-03 00:27:15.332 +03 [7195] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:15.439 +03 [75715] [unknown] LOG: connection received:
host=localhost port=44836
2022-02-03 00:27:15.457 +03 [75715] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:15.586 +03 [95142] [unknown] LOG: connection received:
host=localhost port=8336
2022-02-03 00:27:15.606 +03 [95142] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:15.702 +03 [98682] [unknown] LOG: connection received:
host=localhost port=12937
2022-02-03 00:27:15.729 +03 [98682] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:15.809 +03 [83429] LOG: received fast shutdown request
2022-02-03 00:27:15.809 +03 [83429] LOG: aborting any active transactions
2022-02-03 00:27:15.812 +03 [83429] LOG: background worker "logical
replication launcher" (PID 47697) exited with exit code 1
2022-02-03 00:27:15.812 +03 [61954] LOG: shutting down
2022-02-03 00:27:15.812 +03 [61954] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:27:15.813 +03 [61954] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s,
sync=0.001 s, total=0.002 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=0 kB, estimate=0 kB
2022-02-03 00:27:15.818 +03 [83429] LOG: database system is shut down
2022-02-03 00:27:16.026 +03 [65607] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:27:16.026 +03 [65607] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:27:16.026 +03 [65607] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:27:16.130 +03 [46774] LOG: database system was shut down at
2022-02-03 00:27:15 +03
2022-02-03 00:27:16.132 +03 [65607] LOG: database system is ready to accept
connections
2022-02-03 00:27:16.166 +03 [163] [unknown] LOG: connection received:
host=localhost port=30758
2022-02-03 00:27:16.210 +03 [163] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:16.381 +03 [81662] [unknown] LOG: connection received:
host=localhost port=32497
2022-02-03 00:27:16.428 +03 [81662] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:16.576 +03 [65607] LOG: received fast shutdown request
2022-02-03 00:27:16.576 +03 [65607] LOG: aborting any active transactions
2022-02-03 00:27:16.579 +03 [65607] LOG: background worker "logical
replication launcher" (PID 96725) exited with exit code 1
2022-02-03 00:27:16.579 +03 [84662] LOG: shutting down
2022-02-03 00:27:16.579 +03 [84662] LOG: checkpoint starting: shutdown
immediate
2022-02-03 00:27:16.581 +03 [84662] LOG: checkpoint complete: wrote 3
buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 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
2022-02-03 00:27:16.585 +03 [65607] LOG: database system is shut down
2022-02-03 00:27:16.979 +03 [47738] LOG: starting PostgreSQL 15devel on
x86_64-unknown-openbsd7.0, compiled by OpenBSD clang version 11.1.0,
64-bit
2022-02-03 00:27:16.979 +03 [47738] LOG: listening on IPv4 address
"127.0.0.1", port 56010
2022-02-03 00:27:16.980 +03 [47738] LOG: listening on Unix socket
"/tmp/rkGcakKpBu/.s.PGSQL.56010"
2022-02-03 00:27:17.007 +03 [75810] LOG: database system was shut down at
2022-02-03 00:27:16 +03
2022-02-03 00:27:17.009 +03 [47738] LOG: database system is ready to accept
connections
2022-02-03 00:27:17.200 +03 [88500] [unknown] LOG: connection received:
host=localhost port=27583
2022-02-03 00:27:17.286 +03 [88500] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
2022-02-03 00:27:17.306 +03 [5933] [unknown] LOG: connection received:
host=localhost port=10939
2022-02-03 00:27:17.311 +03 [5933] [unknown] FATAL: no pg_hba.conf entry
for host "127.0.0.1", user "ssltestuser", database "certdb", no encryption
2022-02-03 00:27:17.311 +03 [5933] [unknown] DETAIL: Client IP address
resolved to "localhost", forward lookup not checked.
2022-02-03 00:27:17.631 +03 [47738] LOG: received immediate shutdown
request
2022-02-03 00:27:17.637 +03 [47738] LOG: database system is shut down
regress_log_001_ssltests:
1..110
# setting up data directory
# Checking port 56010
# Found port 56010
Name: primary
Data directory:
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
Backup directory:
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/backup
Archive directory:
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/archives
Connection string: port=56010 host=/tmp/rkGcakKpBu
Log file:
/home/postgres/postgres/src/test/ssl/tmp_check/log/001_ssltests_primary.log
# Running: initdb -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-A trust -N
The files belonging to this database system will be owned by user
"postgres".
This user must also own the server process.
The database cluster will be initialized with locales
COLLATE: en_US.UTF-8
CTYPE: en_US.UTF-8
MESSAGES: C
MONETARY: en_US.UTF-8
NUMERIC: en_US.UTF-8
TIME: en_US.UTF-8
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".
Data page checksums are disabled.
creating directory
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Europe/Istanbul
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
Sync to disk skipped.
The data directory might become corrupt if the operating system crashes.
Success. You can now start the database server using:
pg_ctl -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l logfile start
# Running:
/home/postgres/postgres/src/test/ssl/../../../src/test/regress/pg_regress
--config-auth
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
### Starting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/log/001_ssltests_primary.log
-o --cluster-name=primary start
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 88304
ok 1 - ssl_library parameter
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 80056
# testing password-protected keys
# Running: pg_ctl -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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.
ok 2 - restart fails with password-protected key file with wrong password
# No postmaster PID for node "primary"
# Running: pg_ctl -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/log/001_ssltests_primary.log
restart
pg_ctl: PID file
"/home/postgres/postgres/src/test/ssl/tmp_check/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
ok 3 - restart succeeds with password-protected key file
# Postmaster PID for node "primary" is 59483
# Running: pg_ctl -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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.
ok 4 - restart fails with incorrect SSL protocol bounds
# Running: pg_ctl -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/log/001_ssltests_primary.log
restart
pg_ctl: PID file
"/home/postgres/postgres/src/test/ssl/tmp_check/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
ok 5 - restart succeeds with correct SSL protocol bounds
# running client tests
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 87966
ok 6 - server doesn't accept non-SSL connections
ok 7 - server doesn't accept non-SSL connections: matches
ok 8 - connect without server root cert sslmode=require
ok 9 - connect without server root cert sslmode=verify-ca
ok 10 - connect without server root cert sslmode=verify-ca: matches
ok 11 - connect without server root cert sslmode=verify-full
ok 12 - connect without server root cert sslmode=verify-full: matches
ok 13 - connect with wrong server root cert sslmode=require
ok 14 - connect with wrong server root cert sslmode=require: matches
ok 15 - connect with wrong server root cert sslmode=verify-ca
ok 16 - connect with wrong server root cert sslmode=verify-ca: matches
ok 17 - connect with wrong server root cert sslmode=verify-full
ok 18 - connect with wrong server root cert sslmode=verify-full: matches
ok 19 - connect with server CA cert, without root CA
ok 20 - connect with server CA cert, without root CA: matches
ok 21 - connect with correct server CA cert file sslmode=require
ok 22 - connect with correct server CA cert file sslmode=verify-ca
ok 23 - connect with correct server CA cert file sslmode=verify-full
ok 24 - cert root file that contains two certificates, order 1
ok 25 - cert root file that contains two certificates, order 2
ok 26 - sslcrl option with invalid file name
ok 27 - CRL belonging to a different CA
ok 28 - CRL belonging to a different CA: matches
ok 29 - directory CRL belonging to a different CA
ok 30 - directory CRL belonging to a different CA: matches
ok 31 - CRL with a non-revoked cert
ok 32 - directory CRL with a non-revoked cert
ok 33 - mismatch between host name and server certificate sslmode=require
ok 34 - mismatch between host name and server certificate
sslmode=verify-ca
ok 35 - mismatch between host name and server certificate
sslmode=verify-full
ok 36 - mismatch between host name and server certificate
sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 54211
ok 37 - host name matching with X.509 Subject Alternative Names 1
ok 38 - host name matching with X.509 Subject Alternative Names 2
ok 39 - host name matching with X.509 Subject Alternative Names wildcard
ok 40 - host name not matching with X.509 Subject Alternative Names
ok 41 - host name not matching with X.509 Subject Alternative Names:
matches
ok 42 - host name not matching with X.509 Subject Alternative Names
wildcard
ok 43 - host name not matching with X.509 Subject Alternative Names
wildcard: matches
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 65102
ok 44 - host name matching with a single X.509 Subject Alternative Name
ok 45 - host name not matching with a single X.509 Subject Alternative
Name
ok 46 - host name not matching with a single X.509 Subject Alternative Name:
matches
ok 47 - host name not matching with a single X.509 Subject Alternative Name
wildcard
ok 48 - host name not matching with a single X.509 Subject Alternative Name
wildcard: matches
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 28120
ok 49 - certificate with both a CN and SANs 1
ok 50 - certificate with both a CN and SANs 2
ok 51 - certificate with both a CN and SANs ignores CN
ok 52 - certificate with both a CN and SANs ignores CN: matches
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 50785
ok 53 - server certificate without CN or SANs sslmode=verify-ca
ok 54 - server certificate without CN or SANs sslmode=verify-full
ok 55 - server certificate without CN or SANs sslmode=verify-full: matches
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 83429
ok 56 - connects without client-side CRL
ok 57 - does not connect with client-side CRL file
ok 58 - does not connect with client-side CRL file: matches
ok 59 - does not connect with client-side CRL directory
ok 60 - does not connect with client-side CRL directory: matches
# Running: psql -X -A -F , -P null=_null_ -d user=ssltestuser dbname=trustdb
sslcert=invalid hostaddr=127.0.0.1 host=common-name.pg-ssltest.test
sslrootcert=invalid -c SELECT * FROM pg_stat_ssl WHERE pid =
pg_backend_pid()
ok 61 - pg_stat_ssl view without client certificate: exit code 0
ok 62 - pg_stat_ssl view without client certificate: no stderr
ok 63 - pg_stat_ssl view without client certificate: matches
ok 64 - connection success with correct range of TLS protocol versions
ok 65 - connection failure with incorrect range of TLS protocol versions
ok 66 - connection failure with incorrect range of TLS protocol versions:
matches
ok 67 - connection failure with an incorrect SSL protocol minimum bound
ok 68 - connection failure with an incorrect SSL protocol minimum bound:
matches
ok 69 - connection failure with an incorrect SSL protocol maximum bound
ok 70 - connection failure with an incorrect SSL protocol maximum bound:
matches
# running server tests
ok 71 - certificate authorization fails without client cert
not ok 72 - certificate authorization fails without client cert: matches
# Failed test 'certificate authorization fails without client cert:
matches'
# at t/001_ssltests.pl line 402.
# 'psql: error: connection to server at "127.0.0.1", port
56010 failed: SSL error: sslv3 alert illegal parameter'
# doesn't match '(?^:connection requires a valid client certificate)'
not ok 73 - certificate authorization succeeds with correct client cert in
PEM format
# Failed test 'certificate authorization succeeds with correct client cert
in PEM format'
# at t/001_ssltests.pl line 408.
# got: '2'
# expected: '0'
not ok 74 - certificate authorization succeeds with correct client cert in
DER format
# Failed test 'certificate authorization succeeds with correct client cert
in DER format'
# at t/001_ssltests.pl line 414.
# got: '2'
# expected: '0'
not ok 75 - certificate authorization succeeds with correct client cert in
encrypted PEM format
# Failed test 'certificate authorization succeeds with correct client cert
in encrypted PEM format'
# at t/001_ssltests.pl line 420.
# got: '2'
# expected: '0'
not ok 76 - certificate authorization succeeds with correct client cert in
encrypted DER format
# Failed test 'certificate authorization succeeds with correct client cert
in encrypted DER format'
# at t/001_ssltests.pl line 426.
# got: '2'
# expected: '0'
ok 77 - certificate authorization fails with correct client cert and wrong
password in encrypted PEM format
ok 78 - certificate authorization fails with correct client cert and wrong
password in encrypted PEM format: matches
not ok 79 - certificate authorization succeeds with DN mapping
# Failed test 'certificate authorization succeeds with DN mapping'
# at t/001_ssltests.pl line 443.
# got: '2'
# expected: '0'
not ok 80 - certificate authorization succeeds with DN mapping: log
matches
# Failed test 'certificate authorization succeeds with DN mapping: log
matches'
# at t/001_ssltests.pl line 443.
# '2022-02-03 00:27:14.421 +03 [73952] [unknown] LOG:
connection received: host=localhost port=26092
# 2022-02-03 00:27:14.433 +03 [73952] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
# '
# doesn't match '(?^:connection authenticated:
identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG"
method=cert)'
not ok 81 - certificate authorization succeeds with DN regex mapping
# Failed test 'certificate authorization succeeds with DN regex mapping'
# at t/001_ssltests.pl line 453.
# got: '2'
# expected: '0'
not ok 82 - certificate authorization succeeds with CN mapping
# Failed test 'certificate authorization succeeds with CN mapping'
# at t/001_ssltests.pl line 460.
# got: '2'
# expected: '0'
not ok 83 - certificate authorization succeeds with CN mapping: log
matches
# Failed test 'certificate authorization succeeds with CN mapping: log
matches'
# at t/001_ssltests.pl line 460.
# '2022-02-03 00:27:14.839 +03 [74476] [unknown] LOG:
connection received: host=localhost port=20094
# 2022-02-03 00:27:14.851 +03 [74476] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
# '
# doesn't match '(?^:connection authenticated:
identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG"
method=cert)'
not ok 84 # TODO & SKIP Need Pty support
not ok 85 # TODO & SKIP Need Pty support
not ok 86 # TODO & SKIP Need Pty support
not ok 87 # TODO & SKIP Need Pty support
Hexadecimal number > 0xffffffff non-portable at t/001_ssltests.pl line
508.
# Running: psql -X -A -F , -P null=_null_ -d
sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=certdb
hostaddr=127.0.0.1 user=ssltestuser sslcert=ssl/client.crt
sslkey=/home/postgres/postgres/src/test/ssl/tmp_check/tmp_test_b1a4/client.key
-c SELECT * FROM pg_stat_ssl WHERE pid = pg_backend_pid()
not ok 88 - pg_stat_ssl with client certificate: exit code 0
# Failed test 'pg_stat_ssl with client certificate: exit code 0'
# at t/001_ssltests.pl line 523.
not ok 89 - pg_stat_ssl with client certificate: no stderr
# Failed test 'pg_stat_ssl with client certificate: no stderr'
# at t/001_ssltests.pl line 523.
# got: 'psql: error: connection to server at "127.0.0.1", port
56010 failed: SSL error: sslv3 alert illegal parameter
# '
# expected: ''
not ok 90 - pg_stat_ssl with client certificate: matches
# Failed test 'pg_stat_ssl with client certificate: matches'
# at t/001_ssltests.pl line 523.
# ''
# doesn't match
'(?^mx:^pid,ssl,version,cipher,bits,client_dn,client_serial,issuer_dn\r?\n
#
^\d+,t,TLSv[\d.]+,[\w-]+,\d+,/CN=ssltestuser,2315134995201656576,\/CN\=Test\
CA\ for\ PostgreSQL\ SSL\ regression\ test\ client\ certs\r?$)'
ok 91 - certificate authorization fails because of file permissions
ok 92 - certificate authorization fails because of file permissions:
matches
ok 93 - certificate authorization fails with client cert belonging to
another user
not ok 94 - certificate authorization fails with client cert belonging to
another user: matches
# Failed test 'certificate authorization fails with client cert belonging
to another user: matches'
# at t/001_ssltests.pl line 556.
# 'psql: error: connection to server at "127.0.0.1", port
56010 failed: SSL error: sslv3 alert illegal parameter'
# doesn't match '(?^:certificate authentication failed for user
"anotheruser")'
not ok 95 - certificate authorization fails with client cert belonging to
another user: log matches
# Failed test 'certificate authorization fails with client cert belonging
to another user: log matches'
# at t/001_ssltests.pl line 556.
# '2022-02-03 00:27:15.207 +03 [395] [unknown] LOG:
connection received: host=localhost port=1925
# 2022-02-03 00:27:15.227 +03 [395] [unknown] LOG: could not accept SSL
connection: sslv3 alert illegal parameter
# '
# doesn't match '(?^:connection authenticated: identity="CN=ssltestuser"
method=cert)'
ok 96 - certificate authorization fails with revoked client cert
not ok 97 - certificate authorization fails with revoked client cert:
matches
# Failed test 'certificate authorization fails with revoked client cert:
matches'
# at t/001_ssltests.pl line 565.
# 'psql: error: connection to server at "127.0.0.1", port
56010 failed: SSL error: sslv3 alert illegal parameter'
# doesn't match '(?^:SSL error: sslv3 alert certificate revoked)'
ok 98 - certificate authorization fails with revoked client cert: log does
not match
not ok 99 - auth_option clientcert=verify-full succeeds with matching
username and Common Name
# Failed test 'auth_option clientcert=verify-full succeeds with matching
username and Common Name'
# at t/001_ssltests.pl line 578.
# got: '2'
# expected: '0'
ok 100 - auth_option clientcert=verify-full succeeds with matching username
and Common Name: log does not match
ok 101 - auth_option clientcert=verify-full fails with mismatching username
and Common Name
not ok 102 - auth_option clientcert=verify-full fails with mismatching
username and Common Name: matches
# Failed test 'auth_option clientcert=verify-full fails with mismatching
username and Common Name: matches'
# at t/001_ssltests.pl line 584.
# 'psql: error: connection to server at "127.0.0.1", port
56010 failed: SSL error: sslv3 alert illegal parameter'
# doesn't match '(?^:FATAL: .* "trust" authentication failed for user
"anotheruser")'
ok 103 - auth_option clientcert=verify-full fails with mismatching username
and Common Name: log does not match
not ok 104 - auth_option clientcert=verify-ca succeeds with mismatching
username and Common Name
# Failed test 'auth_option clientcert=verify-ca succeeds with mismatching
username and Common Name'
# at t/001_ssltests.pl line 594.
# got: '2'
# expected: '0'
ok 105 - auth_option clientcert=verify-ca succeeds with mismatching username
and Common Name: log does not match
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 65607
not ok 106 - intermediate client certificate is provided by client
# Failed test 'intermediate client certificate is provided by client'
# at t/001_ssltests.pl line 605.
# got: '2'
# expected: '0'
ok 107 - intermediate client certificate is missing
not ok 108 - intermediate client certificate is missing: matches
# Failed test 'intermediate client certificate is missing: matches'
# at t/001_ssltests.pl line 608.
# 'psql: error: connection to server at "127.0.0.1", port
56010 failed: SSL error: sslv3 alert illegal parameter'
# doesn't match '(?^:SSL error: tlsv1 alert unknown ca)'
### Restarting node "primary"
# Running: pg_ctl -w -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-l
/home/postgres/postgres/src/test/ssl/tmp_check/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 47738
ok 109 - certificate authorization fails with revoked client cert with
server-side CRL directory
not ok 110 - certificate authorization fails with revoked client cert with
server-side CRL directory: matches
# Failed test 'certificate authorization fails with revoked client cert
with server-side CRL directory: matches'
# at t/001_ssltests.pl line 618.
# 'psql: error: connection to server at "127.0.0.1", port
56010 failed: SSL error: sslv3 alert illegal parameter
# connection to server at "127.0.0.1", port 56010 failed: FATAL: no
pg_hba.conf entry for host "127.0.0.1", user "ssltestuser", database
"certdb", no encryption'
# doesn't match '(?^:SSL error: sslv3 alert certificate revoked)'
### Stopping node "primary" using mode immediate
# Running: pg_ctl -D
/home/postgres/postgres/src/test/ssl/tmp_check/t_001_ssltests_primary_data/pgdata
-m immediate stop
waiting for server to shut down... done
server stopped
# No postmaster PID for node "primary"
# Looks like you failed 22 tests of 110.
Thanks,
Nazir Bilal Yavuz
Hi,
Daniel, Heikki, Michael CCing you as you seem to have worked most on those
tests and libressl fixes.
On 2022-02-02 19:19:22 +0000, PG Bug reporting form wrote:
While installing PostgreSQL from source code, SSL tests fail on OpenBSD
7.0.OpenSSL Version:
LibreSSL 3.4.1
Do we expect the SSL tests to pass when using libressl? If not, we should make
the ssl tests SKIP when using libressl...
Greetings,
Andres Freund
On Thu, Feb 3, 2022 at 10:39 AM Andres Freund <andres@anarazel.de> wrote:
Daniel, Heikki, Michael CCing you as you seem to have worked most on those
tests and libressl fixes.
I guess the previous commits mentioning libressl were just getting it
to compile on OpenBSD? Very few BF animals actually run the ssl tests
(which requires setting PG_TEST_EXTRA="ssl"). That said, people are
definitely running PostgreSQL with SSL on OpenBSD in the wild, so it's
at least partially working. I wonder if the problem is something that
needs to be configured in /etc/ssl/openssl.cnf (something like
https://obsd.solutions/en/blog/2020/06/08/libressl-error-due-to-missing-v3_ca-in-extension/
though that doesn't seem to be it).
Anyway, I can also reproduce this problem on my Vagrant image (OpenBSD
6.9 'cause I haven't got around to setting up 7). Just in case it
helps someone who (unlike me) knows enough about libressl to debug
this and knows how to drive vagrant, here's a reproducer:
git clone https://github.com/macdice/postgresql-dev-vagrant.git
cd postgresql-dev-vagarant/openbsd6
vagrant up
... wait for installation and build ...
vagrant ssh
cd postgres/src/test/ssl
gmake check
Thomas Munro <thomas.munro@gmail.com> writes:
Anyway, I can also reproduce this problem on my Vagrant image (OpenBSD
6.9 'cause I haven't got around to setting up 7).
I had an OpenBSD 6.8 image laying about, so I tried the ssl test
there, and it falls over in even more places:
Test Summary Report
-------------------
t/001_ssltests.pl (Wstat: 8448 Tests: 110 Failed: 33)
Failed tests: 14, 16, 18-20, 28, 30-32, 58, 60, 72-76
79-83, 88-90, 94-95, 97, 99, 102, 104, 106
108, 110
Non-zero exit status: 33
t/002_scram.pl (Wstat: 1792 Tests: 11 Failed: 7)
Failed tests: 1, 4-5, 7, 9-11
Non-zero exit status: 7
t/003_sslinfo.pl (Wstat: 7424 Tests: 1 Failed: 1)
Failed test: 1
Non-zero exit status: 29
Parse errors: Bad plan. You planned 13 tests but ran 1.
A lot of the errors look like they didn't yet have support for
TLS 1.2; this is typical:
# Failed test 'pg_stat_ssl with client certificate: no stderr'
# at t/001_ssltests.pl line 523.
# got: 'psql: error: connection to server at "127.0.0.1", port 57105 failed: SSL error: tlsv1 alert protocol version
# This may indicate that the server does not support any SSL protocol version between TLSv1.2 and TLSv1.2.
The postmaster log entries corresponding to this look like
2022-02-02 20:13:49.420 EST [16352] [unknown] LOG: connection received: host=localhost port=39596
2022-02-02 20:13:49.429 EST [16352] [unknown] LOG: could not accept SSL connection: sslv3 alert illegal parameter
I don't see anything in /etc/ssl/openssl.cnf that looks related
to TLS protocol restrictions.
Perhaps 6.8 is too old to be of interest anymore, but that's
what I've got handy.
BTW, I also reproduced something that seems odd from the OP's
postmaster logs: there are what seem a quite excessive number
of checkpoints happening during these tests. That happens
on my Linux box too, so it's not an OpenBSD issue. It looks
like there are two per CREATE DATABASE --- I could understand
one maybe, but why two?
regards, tom lane
Hi,
On 2022-02-02 20:31:52 -0500, Tom Lane wrote:
BTW, I also reproduced something that seems odd from the OP's
postmaster logs: there are what seem a quite excessive number
of checkpoints happening during these tests. That happens
on my Linux box too, so it's not an OpenBSD issue. It looks
like there are two per CREATE DATABASE --- I could understand
one maybe, but why two?
I think that's unfortunately normal. There's two RequestCheckpoint()s in
createdb(). We should optimize that someday...
Greetings,
Andres Freund
Andres Freund <andres@anarazel.de> writes:
On 2022-02-02 20:31:52 -0500, Tom Lane wrote:
BTW, I also reproduced something that seems odd from the OP's
postmaster logs: there are what seem a quite excessive number
of checkpoints happening during these tests. That happens
on my Linux box too, so it's not an OpenBSD issue. It looks
like there are two per CREATE DATABASE --- I could understand
one maybe, but why two?
I think that's unfortunately normal. There's two RequestCheckpoint()s in
createdb(). We should optimize that someday...
Hmm. I wonder how much that slows down a check-world run.
I suppose the second checkpoint should be pretty speedy
for lack of anything to do, but still ...
regards, tom lane
Hi,
On 2022-02-02 21:44:41 -0500, Tom Lane wrote:
Andres Freund <andres@anarazel.de> writes:
On 2022-02-02 20:31:52 -0500, Tom Lane wrote:
BTW, I also reproduced something that seems odd from the OP's
postmaster logs: there are what seem a quite excessive number
of checkpoints happening during these tests. That happens
on my Linux box too, so it's not an OpenBSD issue. It looks
like there are two per CREATE DATABASE --- I could understand
one maybe, but why two?I think that's unfortunately normal. There's two RequestCheckpoint()s in
createdb(). We should optimize that someday...Hmm. I wonder how much that slows down a check-world run.
I suppose the second checkpoint should be pretty speedy
for lack of anything to do, but still ...
There is a patch making CREATE DATABASE fully WAL logged [1]https://commitfest.postgresql.org/36/3192/.
cfbot timings aren't super reliable, but it provides perhaps a bit of
information.
It does seem to make individual create databases a bit faster. Comparing runs
with another patch and looking at windows (since that's the slowest and
doesn't run regression tests concurrently), we can see:
https://cirrus-ci.com/github/postgresql-cfbot/postgresql/commitfest/36/3314
https://cirrus-ci.com/github/postgresql-cfbot/postgresql/commitfest/36/3192
CF 3314:
[01:28:31.630] Checking plpgsql
[01:28:31.764] ============== creating database "pl_regression" ==============
[01:28:32.631] CREATE DATABASE
[01:28:36.515] Checking plperl
[01:28:36.751] ============== creating database "pl_regression" ==============
[01:28:37.560] CREATE DATABASE
[01:28:40.990] Checking plpythonu
[01:28:41.233] ============== creating database "pl_regression" ==============
[01:28:42.057] CREATE DATABASE
CF 3192:
[07:03:54.861] Checking plpgsql
[07:03:54.986] ============== creating database "pl_regression" ==============
[07:03:55.254] CREATE DATABASE
[07:03:58.950] Checking plperl
[07:03:59.234] ============== creating database "pl_regression" ==============
[07:03:59.484] CREATE DATABASE
[07:04:02.724] Checking plpythonu
[07:04:02.960] ============== creating database "pl_regression" ==============
[07:04:03.202] CREATE DATABASE
Which does seem to suggest createdb being noticably faster.
This is also visible in aggregate across several tests, e.g. "test_modules"
averaging ~45s for 36/3314, but ~30s for 36/3192.
For the longer running tap tests it doesn't seem to make much of a difference,
which make some sense.
Greetings,
Andres Freund
I wrote:
I had an OpenBSD 6.8 image laying about, so I tried the ssl test
there, and it falls over in even more places:
...
A lot of the errors look like they didn't yet have support for
TLS 1.2; this is typical:
On further investigation, that's nonsense, because the postmaster logs
show that most if not all of the connections that are succeeding are
TLSv1.3, eg
2022-02-02 21:31:07.492 EST [96067] [unknown] LOG: 00000: connection authorized: user=ssltestuser database=trustdb application_name=001_ssltests.pl SSL enabled (protocol=TLSv1.3, cipher=AEAD-AES256-GCM-SHA384, bits=256)
However, PG believes that the library only supports up to 1.2,
because TLS1_3_VERSION isn't defined. I found this in
/usr/include/openssl/tls1.h:
#if defined(LIBRESSL_HAS_TLS1_3) || defined(LIBRESSL_INTERNAL)
#define TLS1_3_VERSION 0x0304
#endif
LIBRESSL_HAS_TLS1_3 is not defined anywhere; in
/usr/include/openssl/opensslfeatures.h I find
/*
* Feature flags for LibreSSL... so you can actually tell when things
* are enabled, rather than not being able to tell when things are
* enabled (or possibly not yet not implemented, or removed!).
*/
/* #define LIBRESSL_HAS_TLS1_3 */
which is about the best example I've seen lately of crappy code
falsifying the adjacent comment.
I added
#define LIBRESSL_HAS_TLS1_3 1
to pg_config.h to see what would happen. It seems that about
the same number of tests fall over, but now the errors are
(mostly) not about TLS version. Some look like they might
just be mismatched expectations of exactly what error will
be issued:
# Failed test 'connect with wrong server root cert sslmode=require: matches'
# at t/001_ssltests.pl line 170.
# 'psql: error: connection to server at "127.0.0.1", port 62542 failed: SSL error: tlsv1 alert unknown ca'
# doesn't match '(?^:SSL error: certificate verify failed)'
I get the impression though that there's still some mismatch
about how to establish which CAs are trusted, and there are
still a few "tlsv1 alert protocol version" errors with no
obvious reason.
I thought for awhile that the library might be forcing a minimum
TLS version of 1.3 (despite the headers not even claiming to
support it at all), because that would fit right in with OpenBSD's
securer-than-thou ethos. I still suspect that something like that
might be going on, but I don't have hard evidence.
regards, tom lane
On 3 Feb 2022, at 06:41, Tom Lane <tgl@sss.pgh.pa.us> wrote:
However, PG believes that the library only supports up to 1.2,
because TLS1_3_VERSION isn't defined. I found this in
/usr/include/openssl/tls1.h:#if defined(LIBRESSL_HAS_TLS1_3) || defined(LIBRESSL_INTERNAL)
#define TLS1_3_VERSION 0x0304
#endifLIBRESSL_HAS_TLS1_3 is not defined anywhere; in
/usr/include/openssl/opensslfeatures.h I find/*
* Feature flags for LibreSSL... so you can actually tell when things
* are enabled, rather than not being able to tell when things are
* enabled (or possibly not yet not implemented, or removed!).
*/
/* #define LIBRESSL_HAS_TLS1_3 */which is about the best example I've seen lately of crappy code
falsifying the adjacent comment.
AFAICT from reading their (not too extensive) docs is that they consider 1.3
supporting starting with 3.4 which supports the OpenSSL 1.1.1 API. Recent
reports [0]https://github.com/libressl-portable/portable/issues/228 on their -portable Github repo are saying it still doesn't work. I
haven't dug too far in to this yet, but will have a look.
Adding host=localhost to the connection string in the tests make all the tests
but two pass for me:
t/001_ssltests.pl .. 93/110
# Failed test 'certificate authorization fails with revoked client cert: matches'
# at t/001_ssltests.pl line 565.
# 'psql: error: connection to server at "127.0.0.1", port 50547 failed: server closed the connection unexpectedly
# This probably means the server terminated abnormally
# before or while processing the request.
# SSL SYSCALL error: Broken pipe'
# doesn't match '(?^:SSL error: sslv3 alert certificate revoked)'
# Failed test 'certificate authorization fails with revoked client cert with server-side CRL directory: matches'
# at t/001_ssltests.pl line 618.
# 'psql: error: connection to server at "127.0.0.1", port 50547 failed: server closed the connection unexpectedly
# This probably means the server terminated abnormally
# before or while processing the request.
# SSL SYSCALL error: Broken pipe
# connection to server at "127.0.0.1", port 50547 failed: FATAL: no pg_hba.conf entry for host "127.0.0.1", user "ssltestuser", database "certdb", no encryption'
# doesn't match '(?^:SSL error: sslv3 alert certificate revoked)'
# Looks like you failed 2 tests of 110.
t/001_ssltests.pl .. Dubious, test returned 2 (wstat 512, 0x200)
Failed 2/110 subtests
t/002_scram.pl ..... ok
t/003_sslinfo.pl ... ok
The remaining tests are both CRL tests, but I haven't had time yet to dig into
why those are failing (the logs weren't terribly helpful on a quick glance).
--
Daniel Gustafsson https://vmware.com/
[0]: https://github.com/libressl-portable/portable/issues/228
Pouring over SSL test logs I was again red-herringed by the warning we get for
using hex() on a large input value, before I remembered that it's benign and
emerged from the rabbithole:
Hexadecimal number > 0xffffffff non-portable at t/001_ssltests.pl line 508.
We could suppress it by turning off warnings for that line, since we know it
will work due to the 64-bit int test a few lines before:
@@ -505,6 +505,7 @@ if ($? == 0)
{
$serialno =~ s/^serial=//;
$serialno =~ s/\s+//g;
+ local $SIG{'__WARN__'} = sub { };
$serialno = hex($serialno);
}
else
Turning of warnings might be a bridge too far for some though? Thoughts?
--
Daniel Gustafsson https://vmware.com/
Hi,
On February 3, 2022 7:48:40 AM PST, Daniel Gustafsson <daniel@yesql.se> wrote:
Pouring over SSL test logs I was again red-herringed by the warning we get for
using hex() on a large input value, before I remembered that it's benign and
emerged from the rabbithole:Hexadecimal number > 0xffffffff non-portable at t/001_ssltests.pl line 508.
We could suppress it by turning off warnings for that line, since we know it
will work due to the 64-bit int test a few lines before:@@ -505,6 +505,7 @@ if ($? == 0) { $serialno =~ s/^serial=//; $serialno =~ s/\s+//g; + local $SIG{'__WARN__'} = sub { }; $serialno = hex($serialno); } elseTurning of warnings might be a bridge too far for some though? Thoughts?
Can't we just chop serialno into two 32bit numbers and call hex separately? Seems about as hard as adding a comment explaining what the warn bit is about...
Andres
--
Sent from my Android device with K-9 Mail. Please excuse my brevity.
On 3 Feb 2022, at 16:55, Andres Freund <andres@anarazel.de> wrote:
Can't we just chop serialno into two 32bit numbers and call hex separately?
Seems about as hard as adding a comment explaining what the warn bit is
about...
That doesn't not make sense.. I'll look at that instead. Thanks.
--
Daniel Gustafsson https://vmware.com/
Daniel Gustafsson <daniel@yesql.se> writes:
Adding host=localhost to the connection string in the tests make all the tests
but two pass for me:
FWIW, I see no change from that on 6.8.
regards, tom lane
On 3 Feb 2022, at 17:47, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Daniel Gustafsson <daniel@yesql.se> writes:
Adding host=localhost to the connection string in the tests make all the tests
but two pass for me:FWIW, I see no change from that on 6.8.
Interesting. I realize that I forgot to mention that this was on a fresh
install of 7 with LibreSSL 3.4.2.
--
Daniel Gustafsson https://vmware.com/
On 3 Feb 2022, at 15:25, Daniel Gustafsson <daniel@yesql.se> wrote:
The remaining tests are both CRL tests, but I haven't had time yet to dig into
why those are failing (the logs weren't terribly helpful on a quick glance).
Looking at these remaining failures today left me a bit confused. It seems to
be some form of timing or synchronization issue as delaying shutdown with a
sleep(1) in the be_tls_open_server errorpath makes the tests pass. With the
attached diff I get all tests passing on OpenBSD 7. Following the bouncing
ball into differences between OpenSSL and LibreSSL in the revocation and
shutdown paths didn't lead to anything.
Does anyone have any ideas what this could be?
Thomas: Does the attached reproduce these results for you?
--
Daniel Gustafsson https://vmware.com/
Attachments:
kludge.diffapplication/octet-stream; name=kludge.diff; x-unix-mode=0644Download+11-9
Hi,
On 2022-02-04 15:12:47 +0100, Daniel Gustafsson wrote:
Looking at these remaining failures today left me a bit confused. It seems to
be some form of timing or synchronization issue as delaying shutdown with a
sleep(1) in the be_tls_open_server errorpath makes the tests pass. With the
attached diff I get all tests passing on OpenBSD 7. Following the bouncing
ball into differences between OpenSSL and LibreSSL in the revocation and
shutdown paths didn't lead to anything.
Have you checked whether openssl on openbsd doesn't have this problem? It
could be an OS issue, rather than libressl.
Does anyone have any ideas what this could be?
I wonder if reverting 6051857fc and ed52c3707 makes a difference (like done in
the stable branches, due to windows issues)?
Greetings,
Andres Freund
Andres Freund <andres@anarazel.de> writes:
I wonder if reverting 6051857fc and ed52c3707 makes a difference (like done in
the stable branches, due to windows issues)?
Sure hope not, because that code's inside #ifdef WIN32.
regards, tom lane
On Sat, Feb 5, 2022 at 3:12 AM Daniel Gustafsson <daniel@yesql.se> wrote:
Thomas: Does the attached reproduce these results for you?
-bash-5.1$ uname -a
OpenBSD openbsd6.localdomain 6.9 GENERIC.MP#473 amd64
-bash-5.1$ openssl version
LibreSSL 3.3.2
-bash-5.1$ git rev-parse HEAD
b31e3f561365136b48d63e8561f32b697df16d1d
-bash-5.1$ curl -s
/messages/by-id/attachment/130677/kludge.diff |
patch -s -p1
-bash-5.1$ ./rebuild.sh
-bash-5.1$ gmake -s -C src/test/ssl check
t/001_ssltests.pl .. ok
t/002_scram.pl ..... ok
t/003_sslinfo.pl ... ok
All tests successful.
Files=3, Tests=134, 26 wallclock secs ( 0.18 usr 0.05 sys + 4.46
cusr 7.16 csys = 11.85 CPU)
Result: PASS
If I comment out your sleep(1), I get:
-bash-5.1$ gmake -s -C src/test/ssl check
t/001_ssltests.pl .. 80/110
# Failed test 'certificate authorization fails with revoked client
cert: matches'
# at t/001_ssltests.pl line 565.
# 'psql: error: connection to server at "127.0.0.1",
port 61927 failed: server closed the connection unexpectedly
# This probably means the server terminated abnormally
# before or while processing the request.
# SSL SYSCALL error: Broken pipe'
# doesn't match '(?^:SSL error: sslv3 alert certificate revoked)'
t/001_ssltests.pl .. 107/110
# Failed test 'certificate authorization fails with revoked client
cert with server-side CRL directory: matches'
# at t/001_ssltests.pl line 618.
# 'psql: error: connection to server at "127.0.0.1",
port 61927 failed: server closed the connection unexpectedly
# This probably means the server terminated abnormally
# before or while processing the request.
# SSL SYSCALL error: Broken pipe
# connection to server at "127.0.0.1", port 61927 failed: FATAL: no
pg_hba.conf entry for host "127.0.0.1", user "ssltestuser", database
"certdb", no encryption'
# doesn't match '(?^:SSL error: sslv3 alert certificate revoked)'
# Looks like you failed 2 tests of 110.
t/001_ssltests.pl .. Dubious, test returned 2 (wstat 512, 0x200)
Failed 2/110 subtests
t/002_scram.pl ..... ok
t/003_sslinfo.pl ... ok
Test Summary Report
-------------------
t/001_ssltests.pl (Wstat: 512 Tests: 110 Failed: 2)
Failed tests: 97, 110
Non-zero exit status: 2
Files=3, Tests=134, 26 wallclock secs ( 0.07 usr 0.03 sys + 4.81
cusr 6.55 csys = 11.46 CPU)
Result: FAIL
gmake: *** [Makefile:32: check] Error 1
Hi,
On 2022-02-04 08:05:28 -0800, Andres Freund wrote:
Have you checked whether openssl on openbsd doesn't have this problem? It
could be an OS issue, rather than libressl.
FWIW, the ssl tests do pass with openssl, on openbsd 7.0, without any
patches. So it is a libressl related issue (although it can obviously be on
"our" side rather than "their" side).
Greetings,
Andres Freund
On Sat, Feb 5, 2022 at 3:12 AM Daniel Gustafsson <daniel@yesql.se> wrote:
Looking at these remaining failures today left me a bit confused. It seems to
be some form of timing or synchronization issue as delaying shutdown with a
sleep(1) in the be_tls_open_server errorpath makes the tests pass. With the
attached diff I get all tests passing on OpenBSD 7. Following the bouncing
ball into differences between OpenSSL and LibreSSL in the revocation and
shutdown paths didn't lead to anything.Does anyone have any ideas what this could be?
usleep(1) is also enough, but usleep(0) isn't. I wonder if something
could be disabling SO_LINGER on the socket, or somehow activating
similar data-dropping behaviour so the final ereport doesn't get
transferred.