From 78674be74ef2751a6e026b3615844571c4cc83b5 Mon Sep 17 00:00:00 2001 From: Commitfest Bot Date: Tue, 22 Apr 2025 09:23:24 +0000 Subject: [PATCH] [PATCH]: ./v2-fix-connect_fails-races.patch --- src/test/authentication/t/001_password.pl | 2 + src/test/authentication/t/003_peer.pl | 2 + src/test/kerberos/t/001_auth.pl | 1 + src/test/ldap/t/001_auth.pl | 2 + .../modules/oauth_validator/t/001_server.pl | 2 + src/test/perl/PostgreSQL/Test/Cluster.pm | 19 +++++- src/test/ssl/t/001_ssltests.pl | 67 ++++++++----------- 7 files changed, 53 insertions(+), 42 deletions(-) diff --git a/src/test/authentication/t/001_password.pl b/src/test/authentication/t/001_password.pl index 756b41460500..37d96d95a1ae 100644 --- a/src/test/authentication/t/001_password.pl +++ b/src/test/authentication/t/001_password.pl @@ -66,6 +66,8 @@ sub test_conn my $node = PostgreSQL::Test::Cluster->new('primary'); $node->init; $node->append_conf('postgresql.conf', "log_connections = on\n"); +# Needed to allow connect_fails to inspect postmaster log: +$node->append_conf('postgresql.conf', "log_min_messages = debug2"); $node->start; # Test behavior of log_connections GUC diff --git a/src/test/authentication/t/003_peer.pl b/src/test/authentication/t/003_peer.pl index 69ba73bd2b9a..2879800eacfd 100644 --- a/src/test/authentication/t/003_peer.pl +++ b/src/test/authentication/t/003_peer.pl @@ -72,6 +72,8 @@ sub test_role my $node = PostgreSQL::Test::Cluster->new('node'); $node->init; $node->append_conf('postgresql.conf', "log_connections = on\n"); +# Needed to allow connect_fails to inspect postmaster log: +$node->append_conf('postgresql.conf', "log_min_messages = debug2"); $node->start; # Set pg_hba.conf with the peer authentication. diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index 6748b109decf..2dc6bec9b899 100644 --- a/src/test/kerberos/t/001_auth.pl +++ b/src/test/kerberos/t/001_auth.pl @@ -66,6 +66,7 @@ listen_addresses = '$hostaddr' krb_server_keyfile = '$krb->{keytab}' log_connections = on +log_min_messages = debug2 lc_messages = 'C' }); $node->start; diff --git a/src/test/ldap/t/001_auth.pl b/src/test/ldap/t/001_auth.pl index 352b0fc1fa7b..d1315ed5351b 100644 --- a/src/test/ldap/t/001_auth.pl +++ b/src/test/ldap/t/001_auth.pl @@ -48,6 +48,8 @@ my $node = PostgreSQL::Test::Cluster->new('node'); $node->init; $node->append_conf('postgresql.conf', "log_connections = on\n"); +# Needed to allow connect_fails to inspect postmaster log: +$node->append_conf('postgresql.conf', "log_min_messages = debug2"); $node->start; $node->safe_psql('postgres', 'CREATE USER test0;'); diff --git a/src/test/modules/oauth_validator/t/001_server.pl b/src/test/modules/oauth_validator/t/001_server.pl index d88994abc243..4f035417a40d 100644 --- a/src/test/modules/oauth_validator/t/001_server.pl +++ b/src/test/modules/oauth_validator/t/001_server.pl @@ -48,6 +48,8 @@ $node->append_conf('postgresql.conf', "log_connections = on\n"); $node->append_conf('postgresql.conf', "oauth_validator_libraries = 'validator'\n"); +# Needed to allow connect_fails to inspect postmaster log: +$node->append_conf('postgresql.conf', "log_min_messages = debug2"); $node->start; $node->safe_psql('postgres', 'CREATE USER test;'); diff --git a/src/test/perl/PostgreSQL/Test/Cluster.pm b/src/test/perl/PostgreSQL/Test/Cluster.pm index 8759ed2cbba1..aa5b53167688 100644 --- a/src/test/perl/PostgreSQL/Test/Cluster.pm +++ b/src/test/perl/PostgreSQL/Test/Cluster.pm @@ -2618,13 +2618,19 @@ to fail. =item expected_stderr => B -If this regular expression is set, matches it with the output generated. +If this regular expression is set, matches it to the output generated +by B. =item log_like => [ qr/required message/ ] =item log_unlike => [ qr/prohibited message/ ] -See C. +See C. CAUTION: use of either option requires that +the server's log_min_messages be at least DEBUG2, and that no other +client backend is launched concurrently. These requirements allow +C to wait to see the postmaster-log report of backend +exit, without which there is a race condition as to whether we will +see the expected backend log output. =back @@ -2652,7 +2658,14 @@ sub connect_fails like($stderr, $params{expected_stderr}, "$test_name: matches"); } - $self->log_check($test_name, $log_location, %params); + if (defined($params{log_like}) or defined($params{log_unlike})) + { + $self->wait_for_log( + qr/DEBUG: (?:00000: )?forked new client backend, pid=(\d+) socket.*DEBUG: (?:00000: )?client backend \(PID \1\) exited with exit code \d/s, + $log_location); + + $self->log_check($test_name, $log_location, %params); + } } =pod diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl index 086abf3b8b39..8b0de2d8e7e7 100644 --- a/src/test/ssl/t/001_ssltests.pl +++ b/src/test/ssl/t/001_ssltests.pl @@ -60,6 +60,8 @@ sub switch_server_cert note "setting up data directory"; my $node = PostgreSQL::Test::Cluster->new('primary'); $node->init; +# Needed to allow connect_fails to inspect postmaster log: +$node->append_conf('postgresql.conf', "log_min_messages = debug2"); # PGHOST is enforced here to set up the node, subsequent connections # will use a dedicated connection string. @@ -807,10 +809,8 @@ sub switch_server_cert expected_stderr => qr/certificate authentication failed for user "anotheruser"/, # certificate authentication should be logged even on failure - # temporarily(?) skip this check due to timing issue - # log_like => - # [qr/connection authenticated: identity="CN=ssltestuser" method=cert/], -); + log_like => + [qr/connection authenticated: identity="CN=ssltestuser" method=cert/],); # revoked client cert $node->connect_fails( @@ -818,11 +818,10 @@ sub switch_server_cert . sslkey('client-revoked.key'), "certificate authorization fails with revoked client cert", expected_stderr => qr|SSL error: ssl[a-z0-9/]* alert certificate revoked|, - # temporarily(?) skip this check due to timing issue - # log_like => [ - # qr{Client certificate verification failed at depth 0: certificate revoked}, - # qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number 2315134995201656577, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, - # ], + log_like => [ + qr{Client certificate verification failed at depth 0: certificate revoked}, + qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number \d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, + ], # revoked certificates should not authenticate the user log_unlike => [qr/connection authenticated:/],); @@ -872,24 +871,20 @@ sub switch_server_cert $common_connstr . " " . "sslmode=require sslcert=ssl/client.crt", "intermediate client certificate is missing", expected_stderr => qr/SSL error: tlsv1 alert unknown ca/, - # temporarily(?) skip this check due to timing issue - # log_like => [ - # qr{Client certificate verification failed at depth 0: unable to get local issuer certificate}, - # qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number 2315134995201656576, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, - # ] -); + log_like => [ + qr{Client certificate verification failed at depth 0: unable to get local issuer certificate}, + qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number \d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, + ]); $node->connect_fails( "$common_connstr sslmode=require sslcert=ssl/client-long.crt " . sslkey('client-long.key'), "logged client certificate Subjects are truncated if they're too long", expected_stderr => qr/SSL error: tlsv1 alert unknown ca/, - # temporarily(?) skip this check due to timing issue - # log_like => [ - # qr{Client certificate verification failed at depth 0: unable to get local issuer certificate}, - # qr{Failed certificate data \(unverified\): subject "\.\.\./CN=ssl-123456789012345678901234567890123456789012345678901234567890", serial number 2315418733629425152, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, - # ] -); + log_like => [ + qr{Client certificate verification failed at depth 0: unable to get local issuer certificate}, + qr{Failed certificate data \(unverified\): subject "\.\.\./CN=ssl-123456789012345678901234567890123456789012345678901234567890", serial number \d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, + ]); # Use an invalid cafile here so that the next test won't be able to verify the # client CA. @@ -904,12 +899,10 @@ sub switch_server_cert "$common_connstr sslmode=require sslcert=ssl/client+client_ca.crt", "intermediate client certificate is untrusted", expected_stderr => qr/SSL error: tlsv1 alert unknown ca/, - # temporarily(?) skip this check due to timing issue - # log_like => [ - # qr{Client certificate verification failed at depth 1: unable to get local issuer certificate}, - # 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"}, - # ] -); + log_like => [ + qr{Client certificate verification failed at depth 1: unable to get local issuer certificate}, + 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"}, + ]); # test server-side CRL directory switch_server_cert( @@ -923,12 +916,10 @@ sub switch_server_cert . sslkey('client-revoked.key'), "certificate authorization fails with revoked client cert with server-side CRL directory", expected_stderr => qr|SSL error: ssl[a-z0-9/]* alert certificate revoked|, - # temporarily(?) skip this check due to timing issue - # log_like => [ - # qr{Client certificate verification failed at depth 0: certificate revoked}, - # qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number 2315134995201656577, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, - # ] -); + log_like => [ + qr{Client certificate verification failed at depth 0: certificate revoked}, + qr{Failed certificate data \(unverified\): subject "/CN=ssltestuser", serial number \d+, issuer "/CN=Test CA for PostgreSQL SSL regression test client certs"}, + ]); # revoked client cert, non-ASCII subject $node->connect_fails( @@ -936,11 +927,9 @@ sub switch_server_cert . sslkey('client-revoked-utf8.key'), "certificate authorization fails with revoked UTF-8 client cert with server-side CRL directory", expected_stderr => qr|SSL error: ssl[a-z0-9/]* alert certificate revoked|, - # temporarily(?) skip this check due to timing issue - # log_like => [ - # qr{Client certificate verification failed at depth 0: certificate revoked}, - # 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"}, - # ] -); + log_like => [ + qr{Client certificate verification failed at depth 0: certificate revoked}, + 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"}, + ]); done_testing();