Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commite0f373e

Browse files
committed
Re-enable SSL connect_fails tests, and fix related race conditions.
Cluster.pm's connect_fails routine has long had the ability tosniff the postmaster log file for expected messages after aconnection failure. However, that's always had a race condition:on some platforms it's possible for psql to exit and the testscript to slurp up the postmaster log before the backend processhas been able to write out its final log messages. Back incommit55828a6 we disabled a bunch of tests after discoveringthat, and the aim of this patch is to re-enable them.(The sibling function connect_ok doesn't seem to have a similarproblem, mainly because the messages we look for come out duringthe authentication handshake, so that if psql reports successfulconnection they should certainly have been emitted already.)The solution used here is borrowed from 002_connection_limits.pl'sconnect_fails_wait routine: set the server's log_min_messages settingto DEBUG2 so that the postmaster will log child-process exit, and thenwait till we see that log entry before checking for the messages weare actually interested in.If a TAP test uses connect_fails' log_like or log_unlike options, andforgets to set log_min_messages, those connect_fails calls will nowhang until timeout. Fixing up the existing callers shows that we hadseveral other TAP tests that were in theory vulnerable to the sameproblem. It's unclear whether the lack of failures is just luck, orlack of buildfarm coverage, or perhaps there is some obscure timingeffect that only manifests in SSL connections. In any case, thischange should in principle make those other call sites more robust.I'm not inclined to back-patch though, unless sometime we observean actual failure in one of them.Reported-by: Andrew Dunstan <andrew@dunslane.net>Author: Tom Lane <tgl@sss.pgh.pa.us>Discussion:https://postgr.es/m/984fca80-85a8-4c6f-a5cc-bb860950b435@dunslane.net
1 parentda83b1e commite0f373e

File tree

7 files changed

+53
-42
lines changed

7 files changed

+53
-42
lines changed

‎src/test/authentication/t/001_password.pl

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,8 @@ sub test_conn
6666
my$node = PostgreSQL::Test::Cluster->new('primary');
6767
$node->init;
6868
$node->append_conf('postgresql.conf',"log_connections = on\n");
69+
# Needed to allow connect_fails to inspect postmaster log:
70+
$node->append_conf('postgresql.conf',"log_min_messages = debug2");
6971
$node->start;
7072

7173
# Test behavior of log_connections GUC

‎src/test/authentication/t/003_peer.pl

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -72,6 +72,8 @@ sub test_role
7272
my$node = PostgreSQL::Test::Cluster->new('node');
7373
$node->init;
7474
$node->append_conf('postgresql.conf',"log_connections = on\n");
75+
# Needed to allow connect_fails to inspect postmaster log:
76+
$node->append_conf('postgresql.conf',"log_min_messages = debug2");
7577
$node->start;
7678

7779
# Set pg_hba.conf with the peer authentication.

‎src/test/kerberos/t/001_auth.pl

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,7 @@
6666
listen_addresses = '$hostaddr'
6767
krb_server_keyfile = '$krb->{keytab}'
6868
log_connections = on
69+
log_min_messages = debug2
6970
lc_messages = 'C'
7071
});
7172
$node->start;

‎src/test/ldap/t/001_auth.pl

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,8 @@
4848
my$node = PostgreSQL::Test::Cluster->new('node');
4949
$node->init;
5050
$node->append_conf('postgresql.conf',"log_connections = on\n");
51+
# Needed to allow connect_fails to inspect postmaster log:
52+
$node->append_conf('postgresql.conf',"log_min_messages = debug2");
5153
$node->start;
5254

5355
$node->safe_psql('postgres','CREATE USER test0;');

‎src/test/modules/oauth_validator/t/001_server.pl

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,8 @@
4848
$node->append_conf('postgresql.conf',"log_connections = on\n");
4949
$node->append_conf('postgresql.conf',
5050
"oauth_validator_libraries = 'validator'\n");
51+
# Needed to allow connect_fails to inspect postmaster log:
52+
$node->append_conf('postgresql.conf',"log_min_messages = debug2");
5153
$node->start;
5254

5355
$node->safe_psql('postgres','CREATE USER test;');

‎src/test/perl/PostgreSQL/Test/Cluster.pm

Lines changed: 16 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2618,13 +2618,19 @@ to fail.
26182618
26192619
=itemexpected_stderr =>B<value>
26202620
2621-
If this regular expression is set, matches it with the output generated.
2621+
If this regular expression is set, matches it to the output generated
2622+
byB<psql>.
26222623
26232624
=itemlog_like => [ qr/required message/ ]
26242625
26252626
=itemlog_unlike => [ qr/prohibited message/ ]
26262627
2627-
SeeC<log_check(...)>.
2628+
SeeC<log_check(...)>. CAUTION: use of either option requires that
2629+
the server's log_min_messages be at least DEBUG2, and that no other
2630+
client backend is launched concurrently. These requirements allow
2631+
C<connect_fails> to wait to see the postmaster-log report of backend
2632+
exit, without which there is a race condition as to whether we will
2633+
see the expected backend log output.
26282634
26292635
=back
26302636
@@ -2652,7 +2658,14 @@ sub connect_fails
26522658
like($stderr,$params{expected_stderr},"$test_name: matches");
26532659
}
26542660

2655-
$self->log_check($test_name,$log_location,%params);
2661+
if (defined($params{log_like})ordefined($params{log_unlike}))
2662+
{
2663+
$self->wait_for_log(
2664+
qr/DEBUG: (?:00000: )?forked new client backend, pid=(\d+) socket.*DEBUG: (?:00000: )?client backend\(PID\1\) exited with exit code\d/s,
2665+
$log_location);
2666+
2667+
$self->log_check($test_name,$log_location,%params);
2668+
}
26562669
}
26572670

26582671
=pod

‎src/test/ssl/t/001_ssltests.pl

Lines changed: 28 additions & 39 deletions
Original file line numberDiff line numberDiff line change
@@ -60,6 +60,8 @@ sub switch_server_cert
6060
note"setting up data directory";
6161
my$node = PostgreSQL::Test::Cluster->new('primary');
6262
$node->init;
63+
# Needed to allow connect_fails to inspect postmaster log:
64+
$node->append_conf('postgresql.conf',"log_min_messages = debug2");
6365

6466
# PGHOST is enforced here to set up the node, subsequent connections
6567
# will use a dedicated connection string.
@@ -807,22 +809,19 @@ sub switch_server_cert
807809
expected_stderr=>
808810
qr/certificate authentication failed for user "anotheruser"/,
809811
# certificate authentication should be logged even on failure
810-
# temporarily(?) skip this check due to timing issue
811-
#log_like =>
812-
# [qr/connection authenticated: identity="CN=ssltestuser" method=cert/],
813-
);
812+
log_like=>
813+
[qr/connection authenticated: identity="CN=ssltestuser" method=cert/],);
814814

815815
# revoked client cert
816816
$node->connect_fails(
817817
"$common_connstr user=ssltestuser sslcert=ssl/client-revoked.crt"
818818
. sslkey('client-revoked.key'),
819819
"certificate authorization fails with revoked client cert",
820820
expected_stderr=>qr|SSL error: ssl[a-z0-9/]* alert certificate revoked|,
821-
# temporarily(?) skip this check due to timing issue
822-
#log_like => [
823-
#qr{Client certificate verification failed at depth 0: certificate revoked},
824-
#qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number 2315134995201656577, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
825-
#],
821+
log_like=> [
822+
qr{Client certificate verification failed at depth 0: certificate revoked},
823+
qr{Failed certificate data\(unverified\): subject "/CN=ssltestuser", serial number\d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
824+
],
826825
# revoked certificates should not authenticate the user
827826
log_unlike=> [qr/connection authenticated:/],);
828827

@@ -872,24 +871,20 @@ sub switch_server_cert
872871
$common_connstr ."" ."sslmode=require sslcert=ssl/client.crt",
873872
"intermediate client certificate is missing",
874873
expected_stderr=>qr/SSL error: tlsv1 alert unknown ca/,
875-
# temporarily(?) skip this check due to timing issue
876-
#log_like => [
877-
#qr{Client certificate verification failed at depth 0: unable to get local issuer certificate},
878-
#qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number 2315134995201656576, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
879-
#]
880-
);
874+
log_like=> [
875+
qr{Client certificate verification failed at depth 0: unable to get local issuer certificate},
876+
qr{Failed certificate data\(unverified\): subject "/CN=ssltestuser", serial number\d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
877+
]);
881878

882879
$node->connect_fails(
883880
"$common_connstr sslmode=require sslcert=ssl/client-long.crt"
884881
. sslkey('client-long.key'),
885882
"logged client certificate Subjects are truncated if they're too long",
886883
expected_stderr=>qr/SSL error: tlsv1 alert unknown ca/,
887-
# temporarily(?) skip this check due to timing issue
888-
#log_like => [
889-
#qr{Client certificate verification failed at depth 0: unable to get local issuer certificate},
890-
#qr{Failed certificate data \(unverified\): subject "\.\.\./CN=ssl-123456789012345678901234567890123456789012345678901234567890", serial number 2315418733629425152, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
891-
#]
892-
);
884+
log_like=> [
885+
qr{Client certificate verification failed at depth 0: unable to get local issuer certificate},
886+
qr{Failed certificate data\(unverified\): subject "\.\.\./CN=ssl-123456789012345678901234567890123456789012345678901234567890", serial number\d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
887+
]);
893888

894889
# Use an invalid cafile here so that the next test won't be able to verify the
895890
# client CA.
@@ -904,12 +899,10 @@ sub switch_server_cert
904899
"$common_connstr sslmode=require sslcert=ssl/client+client_ca.crt",
905900
"intermediate client certificate is untrusted",
906901
expected_stderr=>qr/SSL error: tlsv1 alert unknown ca/,
907-
# temporarily(?) skip this check due to timing issue
908-
#log_like => [
909-
#qr{Client certificate verification failed at depth 1: unable to get local issuer certificate},
910-
#qr{Failed certificate data \(unverified\): subject "/CN=Test CA for PostgreSQL SSL regression test client certs", serial number 2315134995201656577, issuer "/CN=Test root CA for PostgreSQL SSL regression test suite"},
911-
#]
912-
);
902+
log_like=> [
903+
qr{Client certificate verification failed at depth 1: unable to get local issuer certificate},
904+
qr{Failed certificate data\(unverified\): subject "/CN=Test CA for PostgreSQL SSL regression test client certs", serial number\d+, issuer "/CN=Test root CA for PostgreSQL SSL regression test suite"},
905+
]);
913906

914907
# test server-side CRL directory
915908
switch_server_cert(
@@ -923,24 +916,20 @@ sub switch_server_cert
923916
. sslkey('client-revoked.key'),
924917
"certificate authorization fails with revoked client cert with server-side CRL directory",
925918
expected_stderr=>qr|SSL error: ssl[a-z0-9/]* alert certificate revoked|,
926-
# temporarily(?) skip this check due to timing issue
927-
#log_like => [
928-
#qr{Client certificate verification failed at depth 0: certificate revoked},
929-
#qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number 2315134995201656577, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
930-
#]
931-
);
919+
log_like=> [
920+
qr{Client certificate verification failed at depth 0: certificate revoked},
921+
qr{Failed certificate data\(unverified\): subject "/CN=ssltestuser", serial number\d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
922+
]);
932923

933924
# revoked client cert, non-ASCII subject
934925
$node->connect_fails(
935926
"$common_connstr user=ssltestuser sslcert=ssl/client-revoked-utf8.crt"
936927
. sslkey('client-revoked-utf8.key'),
937928
"certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory",
938929
expected_stderr=>qr|SSL error: ssl[a-z0-9/]* alert certificate revoked|,
939-
# temporarily(?) skip this check due to timing issue
940-
#log_like => [
941-
#qr{Client certificate verification failed at depth 0: certificate revoked},
942-
#qr{Failed certificate data \(unverified\): subject "/CN=\\xce\\x9f\\xce\\xb4\\xcf\\x85\\xcf\\x83\\xcf\\x83\\xce\\xad\\xce\\xb1\\xcf\\x82", serial number 2315420958437414144, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
943-
#]
944-
);
930+
log_like=> [
931+
qr{Client certificate verification failed at depth 0: certificate revoked},
932+
qr{Failed certificate data\(unverified\): subject "/CN=\\xce\\x9f\\xce\\xb4\\xcf\\x85\\xcf\\x83\\xcf\\x83\\xce\\xad\\xce\\xb1\\xcf\\x82", serial number\d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"},
933+
]);
945934

946935
done_testing();

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp