On Thu, 2021-04-01 at 10:21 +0900, Michael Paquier wrote: > This stuff can take advantage of 0d1a3343, and I > think that we should make the kerberos, ldap, authentication and SSL > test suites just use connect_ok() and connect_fails() from > PostgresNode.pm. They just need to be extended a bit with a new > argument for the log pattern check.
v16, attached, migrates all tests in those suites to connect_ok/fails (in the first two patches), and also adds the log pattern matching (in the final feature patch). A since-v15 diff is attached, but it should be viewed with suspicion since I've rebased on top of the new SSL tests at the same time. --Jacob
diff --git a/src/test/authentication/t/001_password.pl b/src/test/authentication/t/001_password.pl index f75d555ae5..f2cd7377d1 100644 --- a/src/test/authentication/t/001_password.pl +++ b/src/test/authentication/t/001_password.pl @@ -17,7 +17,7 @@ if (!$use_unix_sockets) } else { - plan tests => 22; + plan tests => 23; } @@ -35,47 +35,28 @@ sub reset_pg_hba return; } -# Test access for a single role, useful to wrap all tests into one. +# Test access for a single role, useful to wrap all tests into one. Extra +# named parameters are passed to connect_ok/fails as-is. sub test_role { - my $node = shift; - my $role = shift; - my $method = shift; - my $expected_res = shift; - my $expected_log_msg = shift; - my $status_string = 'failed'; - + my ($node, $role, $method, $expected_res, %params) = @_; + my $status_string = 'failed'; $status_string = 'success' if ($expected_res eq 0); local $Test::Builder::Level = $Test::Builder::Level + 1; - my $res = - $node->psql('postgres', undef, extra_params => [ '-U', $role, '-w' ]); - my $testname = - "authentication $status_string for method $method, role $role"; - is($res, $expected_res, $testname); + my $connstr = "user=$role"; + my $testname = "authentication $status_string for method $method, role $role"; - # Check if any log generated by authentication matches or not. - if ($expected_log_msg ne '') + if ($expected_res eq 0) { - my $log_contents = slurp_file($node->logfile); - if ($res == 0) - { - like($log_contents, $expected_log_msg, - "$testname: logs matching"); - } - else - { - unlike($log_contents, $expected_log_msg, - "$testname: logs not matching"); - } - - # Clean up any existing contents in the node's log file so as - # future tests don't step on each other's generated contents. - truncate $node->logfile, 0; + $node->connect_ok($connstr, $testname, %params, extra_params => [ '-w' ]); + } + else + { + # Currently, we don't check the error message, just the code. + $node->connect_fails($connstr, undef, $testname, %params, extra_params => [ '-w' ]); } - - return; } # Initialize primary node @@ -94,47 +75,41 @@ $node->safe_psql('postgres', ); $ENV{"PGPASSWORD"} = 'pass'; -# For "trust" method, all users should be able to connect. +# For "trust" method, all users should be able to connect. These users are not +# considered to be authenticated. reset_pg_hba($node, 'trust'); -test_role($node, 'scram_role', 'trust', 0); -test_role($node, 'md5_role', 'trust', 0); - -# Particular case here, the logs should have generated nothing related -# to authenticated users. -my $log_contents = slurp_file($node->logfile); -unlike( - $log_contents, - qr/connection authenticated:/, - "trust method does not authenticate users"); -truncate $node->logfile, 0; +test_role($node, 'scram_role', 'trust', 0, + log_unlike => [ qr/connection authenticated:/ ]); +test_role($node, 'md5_role', 'trust', 0, + log_unlike => [ qr/connection authenticated:/ ]); # For plain "password" method, all users should also be able to connect. reset_pg_hba($node, 'password'); test_role($node, 'scram_role', 'password', 0, - qr/connection authenticated: identity="scram_role" method=password/); + log_like => [ qr/connection authenticated: identity="scram_role" method=password/ ]); test_role($node, 'md5_role', 'password', 0, - qr/connection authenticated: identity="md5_role" method=password/); + log_like => [ qr/connection authenticated: identity="md5_role" method=password/ ]); # For "scram-sha-256" method, user "scram_role" should be able to connect. reset_pg_hba($node, 'scram-sha-256'); test_role($node, 'scram_role', 'scram-sha-256', 0, - qr/connection authenticated: identity="scram_role" method=scram-sha-256/); + log_like => [ qr/connection authenticated: identity="scram_role" method=scram-sha-256/ ]); test_role($node, 'md5_role', 'scram-sha-256', 2, - qr/connection authenticated: identity="md5_role"/); + log_unlike => [ qr/connection authenticated:/ ]); # Test that bad passwords are rejected. $ENV{"PGPASSWORD"} = 'badpass'; test_role($node, 'scram_role', 'scram-sha-256', 2, - qr/connection authenticated:/); + log_unlike => [ qr/connection authenticated:/ ]); $ENV{"PGPASSWORD"} = 'pass'; # For "md5" method, all users should be able to connect (SCRAM # authentication will be performed for the user with a SCRAM secret.) reset_pg_hba($node, 'md5'); test_role($node, 'scram_role', 'md5', 0, - qr/connection authenticated: identity="scram_role" method=md5/); + log_like => [ qr/connection authenticated: identity="scram_role" method=md5/ ]); test_role($node, 'md5_role', 'md5', 0, - qr/connection authenticated: identity="md5_role" method=md5/); + log_like => [ qr/connection authenticated: identity="md5_role" method=md5/ ]); # Tests for channel binding without SSL. # Using the password authentication method; channel binding can't work diff --git a/src/test/authentication/t/002_saslprep.pl b/src/test/authentication/t/002_saslprep.pl index 0aaab090ec..33e305e16c 100644 --- a/src/test/authentication/t/002_saslprep.pl +++ b/src/test/authentication/t/002_saslprep.pl @@ -41,12 +41,19 @@ sub test_login $status_string = 'success' if ($expected_res eq 0); + my $connstr = "user=$role"; + my $testname = "authentication $status_string for role $role with password $password"; + $ENV{"PGPASSWORD"} = $password; - my $res = $node->psql('postgres', undef, extra_params => [ '-U', $role ]); - is($res, $expected_res, - "authentication $status_string for role $role with password $password" - ); - return; + if ($expected_res eq 0) + { + $node->connect_ok($connstr, $testname); + } + else + { + # Currently, we don't check the error message, just the code. + $node->connect_fails($connstr, undef, $testname); + } } # Initialize primary node. Force UTF-8 encoding, so that we can use non-ASCII diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index d970cf3186..5ca2eb0694 100644 --- a/src/test/kerberos/t/001_auth.pl +++ b/src/test/kerberos/t/001_auth.pl @@ -20,7 +20,7 @@ use Time::HiRes qw(usleep); if ($ENV{with_gssapi} eq 'yes') { - plan tests => 38; + plan tests => 46; } else { @@ -186,40 +186,35 @@ sub test_access @expect_log_msgs) = @_; # need to connect over TCP/IP for Kerberos - my ($res, $stdoutres, $stderrres) = $node->psql( - 'postgres', - "$query", - extra_params => [ - '-XAtd', - $node->connstr('postgres') - . " host=$host hostaddr=$hostaddr $gssencmode", - '-U', - $role - ]); - - # If we get a query result back, it should be true. - if ($res == $expected_res and $res eq 0) + my $connstr = $node->connstr('postgres') . + " user=$role host=$host hostaddr=$hostaddr $gssencmode"; + + my %params = ( + query => $query, + extra_params => [ '-XAt' ], + ); + + if (@expect_log_msgs) { - is($stdoutres, "t", $test_name); + # Match every message literally. + my @regexes = map { qr/\Q$_\E/ } @expect_log_msgs; + + $params{log_like} = \@regexes; + } + + if ($expected_res eq 0) + { + my $stdoutres; + $params{stdout} = \$stdoutres; + + $node->connect_ok($connstr, $test_name, %params); + + is($stdoutres, "t", "$test_name: query result is true"); } else { - is($res, $expected_res, $test_name); + $node->connect_fails($connstr, undef, $test_name, %params); } - - # Verify specified log messages are logged in the log file. - while (my $expect_log_msg = shift @expect_log_msgs) - { - my $first_logfile = slurp_file($node->logfile); - - like($first_logfile, qr/\Q$expect_log_msg\E/, - 'found expected log file content'); - } - - # Clean up any existing contents in the node's log file so as - # future tests don't step on each other's generated contents. - truncate $node->logfile, 0; - return; } # As above, but test for an arbitrary query result. @@ -228,18 +223,18 @@ sub test_query my ($node, $role, $query, $expected, $gssencmode, $test_name) = @_; # need to connect over TCP/IP for Kerberos - my ($res, $stdoutres, $stderrres) = $node->psql( - 'postgres', - "$query", - extra_params => [ - '-XAtd', - $node->connstr('postgres') - . " host=$host hostaddr=$hostaddr $gssencmode", - '-U', - $role - ]); + my $connstr = $node->connstr('postgres') . + " user=$role host=$host hostaddr=$hostaddr $gssencmode"; + + my ($stdoutres, $stderrres); + + $node->connect_ok($connstr, $test_name, + query => $query, + extra_params => [ '-XAt' ], + stdout => \$stdoutres, + stderr => \$stderrres, + ); - is($res, 0, $test_name); like($stdoutres, $expected, $test_name); is($stderrres, "", $test_name); return; @@ -346,7 +341,7 @@ test_access( "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" ); test_access($node, 'test1', 'SELECT true', 2, 'gssencmode=disable', - 'fails with GSS encryption disabled and hostgssenc hba', ''); + 'fails with GSS encryption disabled and hostgssenc hba'); unlink($node->data_dir . '/pg_hba.conf'); $node->append_conf('pg_hba.conf', diff --git a/src/test/ldap/t/001_auth.pl b/src/test/ldap/t/001_auth.pl index e98c8fe965..bf3cf4a658 100644 --- a/src/test/ldap/t/001_auth.pl +++ b/src/test/ldap/t/001_auth.pl @@ -163,33 +163,20 @@ note "running tests"; sub test_access { - my ($node, $role, $expected_res, $test_name, $expected_log_msg) = @_; + my ($node, $role, $expected_res, $test_name, %params) = @_; + my $connstr = "user=$role"; - my $res = - $node->psql('postgres', undef, - extra_params => [ '-U', $role, '-c', 'SELECT 1' ]); - is($res, $expected_res, $test_name); + local $Test::Builder::Level = $Test::Builder::Level + 1; - # Check if any log generated by authentication matches or not. - if ($expected_log_msg ne '') + if ($expected_res eq 0) { - my $log_contents = slurp_file($node->logfile); - if ($res == 0) - { - like($log_contents, $expected_log_msg, - "$test_name: logs matching"); - } - else - { - unlike($log_contents, $expected_log_msg, - "$test_name: logs not matching"); - } - - # Clean up any existing contents in the node's log file so as - # future tests don't step on each other's generated contents. - truncate $node->logfile, 0; + $node->connect_ok($connstr, $test_name, %params); + } + else + { + # Currently, we don't check the error message, just the code. + $node->connect_fails($connstr, undef, $test_name, %params); } - return; } note "simple bind"; @@ -201,18 +188,16 @@ $node->append_conf('pg_hba.conf', $node->restart; $ENV{"PGPASSWORD"} = 'wrong'; -test_access( - $node, 'test0', 2, +test_access($node, 'test0', 2, 'simple bind authentication fails if user not found in LDAP', - qr/connection authenticated:/); -test_access( - $node, 'test1', 2, + log_unlike => [ qr/connection authenticated:/ ]); +test_access($node, 'test1', 2, 'simple bind authentication fails with wrong password', - qr/connection authenticated:/); + log_unlike => [ qr/connection authenticated:/ ]); $ENV{"PGPASSWORD"} = 'secret1'; test_access($node, 'test1', 0, 'simple bind authentication succeeds', - qr/connection authenticated: identity="uid=test1,dc=example,dc=net" method=ldap/ + log_like => [ qr/connection authenticated: identity="uid=test1,dc=example,dc=net" method=ldap/ ], ); note "search+bind"; diff --git a/src/test/perl/PostgresNode.pm b/src/test/perl/PostgresNode.pm index d6e10544bb..2afe225267 100644 --- a/src/test/perl/PostgresNode.pm +++ b/src/test/perl/PostgresNode.pm @@ -1860,47 +1860,157 @@ sub interactive_psql =pod -=item $node->connect_ok($connstr, $test_name) +=item $node->connect_ok($connstr, $test_name [, %params ]) Attempt a connection with a custom connection string. This is expected to succeed. +=over + +=item query => 'SELECT some_query;' + +By default, a query based on the connection string is performed after the +connection succeeds, to identify it in the server logs. If B<query> is set, it +will be used instead. This can be used with the B<stdout> parameter (see +C<psql()>) to capture a query result. + +=item log_like => [ qr/required message/ ] + +If given, it must be an array reference containing a list of regular expressions +to match against the server log, using C<Test::More::like()>. + +=item log_unlike => [ qr/prohibited message/ ] + +If given, it must be an array reference containing a list of regular expressions +that must NOT match against the server log. They will be passed to +C<Test::More::unlike()>. + +=back + +Any additional named parameters are passed to C<psql()> as-is. + =cut sub connect_ok { local $Test::Builder::Level = $Test::Builder::Level + 1; - my ($self, $connstr, $test_name) = @_; + my ($self, $connstr, $test_name, %params) = @_; + + my $query = "SELECT \$\$connected with $connstr\$\$"; + if (exists $params{query}) + { + $query = delete $params{query}; + } + + my (@log_like, @log_unlike); + if (exists $params{log_like}) + { + @log_like = @{ delete $params{log_like} }; + } + if (exists $params{log_unlike}) + { + @log_unlike = @{ delete $params{log_unlike} }; + } + + if (@log_like or @log_unlike) + { + # Don't let previous log entries match for this connection. + truncate $self->logfile, 0; + } + my ($ret, $stdout, $stderr) = $self->psql( 'postgres', - "SELECT \$\$connected with $connstr\$\$", + $query, + %params, connstr => "$connstr", on_error_stop => 0); - ok($ret == 0, $test_name); + is($ret, 0, $test_name); + + if (@log_like or @log_unlike) + { + my $log_contents = TestLib::slurp_file($self->logfile); + + while (my $regex = shift @log_like) + { + like($log_contents, $regex, "$test_name: log matches"); + } + while (my $regex = shift @log_unlike) + { + unlike($log_contents, $regex, "$test_name: log does not match"); + } + } } =pod -=item $node->connect_fails($connstr, $expected_stderr, $test_name) +=item $node->connect_fails($connstr, $expected_stderr, $test_name [, %params ]) Attempt a connection with a custom connection string. This is expected to fail with a message that matches the regular expression $expected_stderr. +=over + +=item log_like => [ qr/required message/ ] + +=item log_unlike => [ qr/prohibited message/ ] + +See C<connect_ok()>, above. + +=back + +Any additional named parameters are passed to C<psql()>. + =cut sub connect_fails { local $Test::Builder::Level = $Test::Builder::Level + 1; - my ($self, $connstr, $expected_stderr, $test_name) = @_; + my ($self, $connstr, $expected_stderr, $test_name, %params) = @_; + + my (@log_like, @log_unlike); + if (exists $params{log_like}) + { + @log_like = @{ delete $params{log_like} }; + } + if (exists $params{log_unlike}) + { + @log_unlike = @{ delete $params{log_unlike} }; + } + + if (@log_like or @log_unlike) + { + # Don't let previous log entries match for this connection. + truncate $self->logfile, 0; + } + my ($ret, $stdout, $stderr) = $self->psql( 'postgres', "SELECT \$\$connected with $connstr\$\$", + %params, connstr => "$connstr"); - ok($ret != 0, $test_name); - like($stderr, $expected_stderr, "$test_name: matches"); + isnt($ret, 0, $test_name); + + if (defined $expected_stderr) + { + like($stderr, $expected_stderr, "$test_name: stderr matches"); + } + + if (@log_like or @log_unlike) + { + my $log_contents = TestLib::slurp_file($self->logfile); + + while (my $regex = shift @log_like) + { + like($log_contents, $regex, "$test_name: log matches"); + } + while (my $regex = shift @log_unlike) + { + unlike($log_contents, $regex, "$test_name: log does not match"); + } + } } =pod diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl index e20aff6b55..943703fc44 100644 --- a/src/test/ssl/t/001_ssltests.pl +++ b/src/test/ssl/t/001_ssltests.pl @@ -17,33 +17,7 @@ if ($ENV{with_ssl} ne 'openssl') } else { - plan tests => 108; -} - -# Check for matching patterns in the logs of a node. This should -# be used after a connection attempt. $res indicates if the pattern -# should match or not. -sub check_auth_logs -{ - my $node = shift; - my $expected_log_msg = shift; - my $test_name = shift; - my $res = shift; - - my $log_contents = slurp_file($node->logfile); - - if ($res == 0) - { - like($log_contents, $expected_log_msg, $test_name); - } - else - { - unlike($log_contents, $expected_log_msg, $test_name); - } - - # Clean up any existing contents in the node's log file so as - # future tests don't step on each other's generated contents. - truncate $node->logfile, 0; + plan tests => 110; } #### Some configuration @@ -444,13 +418,8 @@ my $dn_connstr = "$common_connstr dbname=certdb_dn"; $node->connect_ok( "$dn_connstr user=ssltestuser sslcert=ssl/client-dn.crt sslkey=ssl/client-dn_tmp.key", - "certificate authorization succeeds with DN mapping"); - -check_auth_logs( - $node, - qr/connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert/, - "certificate authorization with DN mapping logged", - 0); + "certificate authorization succeeds with DN mapping", + log_like => [ qr/connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert/ ]); # same thing but with a regex $dn_connstr = "$common_connstr dbname=certdb_dn_re"; @@ -464,13 +433,9 @@ $dn_connstr = "$common_connstr dbname=certdb_cn"; $node->connect_ok( "$dn_connstr user=ssltestuser sslcert=ssl/client-dn.crt sslkey=ssl/client-dn_tmp.key", - "certificate authorization succeeds with CN mapping"); - -check_auth_logs( - $node, - qr/connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert/, - "certificate authorization with CN mapping logged with DN info", - 0); + "certificate authorization succeeds with CN mapping", + # the full DN should still be used as the authenticated identity + log_like => [ qr/connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert/ ]); @@ -531,24 +496,19 @@ SKIP: $node->connect_fails( "$common_connstr user=anotheruser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", qr/certificate authentication failed for user "anotheruser"/, - "certificate authorization fails with client cert belonging to another user" + "certificate authorization fails with client cert belonging to another user", + # certificate authentication should be logged even on failure + log_like => [ qr/connection authenticated: identity="CN=ssltestuser" method=cert/ ], ); - -check_auth_logs( - $node, - qr/connection authenticated: identity="CN=ssltestuser" method=cert/, - "certificate authorization logged even on failure", 0); # revoked client cert $node->connect_fails( "$common_connstr user=ssltestuser sslcert=ssl/client-revoked.crt sslkey=ssl/client-revoked_tmp.key", qr/SSL error/, - "certificate authorization fails with revoked client cert"); - -check_auth_logs( - $node, - qr/connection authenticated:/, - "certificate authentication with revoked client cert not logged", 1); + "certificate authorization fails with revoked client cert", + # revoked certificates should not authenticate the user + log_unlike => [ qr/connection authenticated:/ ], +); # Check that connecting with auth-option verify-full in pg_hba: # works, iff username matches Common Name @@ -558,31 +518,28 @@ $common_connstr = $node->connect_ok( "$common_connstr user=ssltestuser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", - "auth_option clientcert=verify-full succeeds with matching username and Common Name" + "auth_option clientcert=verify-full succeeds with matching username and Common Name", + # verify-full does not provide authentication + log_unlike => [ qr/connection authenticated:/ ], ); $node->connect_fails( "$common_connstr user=anotheruser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", qr/FATAL/, - "auth_option clientcert=verify-full fails with mismatching username and Common Name" + "auth_option clientcert=verify-full fails with mismatching username and Common Name", + # verify-full does not provide authentication + log_unlike => [ qr/connection authenticated:/ ], ); # Check that connecting with auth-optionverify-ca in pg_hba : # works, when username doesn't match Common Name -# Clean up once the logs to have a clean check state. -truncate $node->logfile, 0; $node->connect_ok( "$common_connstr user=yetanotheruser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", - "auth_option clientcert=verify-ca succeeds with mismatching username and Common Name" + "auth_option clientcert=verify-ca succeeds with mismatching username and Common Name", + # verify-full does not provide authentication + log_unlike => [ qr/connection authenticated:/ ], ); -# None of the above connections to verifydb should have resulted in -# authentication. -check_auth_logs( - $node, - qr/connection authenticated:/, - "trust auth method does not set authenticated identity", 1); - # intermediate client_ca.crt is provided by client, and isn't in server's ssl_ca_file switch_server_cert($node, 'server-cn-only', 'root_ca'); $common_connstr = diff --git a/src/test/ssl/t/002_scram.pl b/src/test/ssl/t/002_scram.pl index 9f1b080d45..d98f6319fa 100644 --- a/src/test/ssl/t/002_scram.pl +++ b/src/test/ssl/t/002_scram.pl @@ -97,20 +97,10 @@ $node->connect_fails( "Cert authentication and channel_binding=require"); # Certificate verification at the connection level should still work fine. -# Truncate once the logs, to ensure that we check what is generated for this -# specific connection. -truncate $node->logfile, 0; -test_connect_ok( - "sslcert=ssl/client.crt sslkey=$client_tmp_key sslrootcert=invalid hostaddr=$SERVERHOSTADDR", - "dbname=verifydb user=ssltestuser channel_binding=require", - "SCRAM with clientcert=verify-full and channel_binding=require"); - -my $log_contents = slurp_file($node->logfile); -like( - $log_contents, - qr/connection authenticated: identity="ssltestuser" method=scram-sha-256/, - "SCRAM with clientcert=verify-full sets the username as the authenticated identity" -); +$node->connect_ok( + "sslcert=ssl/client.crt sslkey=$client_tmp_key sslrootcert=invalid hostaddr=$SERVERHOSTADDR dbname=verifydb user=ssltestuser channel_binding=require", + "SCRAM with clientcert=verify-full and channel_binding=require", + log_like => [ qr/connection authenticated: identity="ssltestuser" method=scram-sha-256/ ]); # clean up unlink($client_tmp_key);
From f2fbbe4b034b9f0d20fe14356052197b1a067763 Mon Sep 17 00:00:00 2001 From: Jacob Champion <pchamp...@vmware.com> Date: Thu, 1 Apr 2021 09:41:38 -0700 Subject: [PATCH v16 1/3] test: continue migration to $node->connect_ok/fails ...with the authentication and ldap suites. - connect_ok() and connect_fails() now take optional named parameters to pass to the psql() call, so that the authentication suite can disable password prompts. - They also use is() and isnt() rather than ok(), to make failure modes slightly less opaque. - ldap's test_access() gets a Test::Builder::Level addition, to make it easier to debug the location of failures. --- src/test/authentication/t/001_password.pl | 16 +++++++++++---- src/test/authentication/t/002_saslprep.pl | 17 +++++++++++----- src/test/ldap/t/001_auth.pl | 19 ++++++++++++------ src/test/perl/PostgresNode.pm | 24 ++++++++++++++--------- 4 files changed, 52 insertions(+), 24 deletions(-) diff --git a/src/test/authentication/t/001_password.pl b/src/test/authentication/t/001_password.pl index 36a616d7c7..92d9b25332 100644 --- a/src/test/authentication/t/001_password.pl +++ b/src/test/authentication/t/001_password.pl @@ -48,10 +48,18 @@ sub test_role local $Test::Builder::Level = $Test::Builder::Level + 1; - my $res = $node->psql('postgres', undef, extra_params => [ '-U', $role, '-w' ]); - is($res, $expected_res, - "authentication $status_string for method $method, role $role"); - return; + my $connstr = "user=$role"; + my $testname = "authentication $status_string for method $method, role $role"; + + if ($expected_res eq 0) + { + $node->connect_ok($connstr, $testname, extra_params => [ '-w' ]); + } + else + { + # Currently, we don't check the error message, just the code. + $node->connect_fails($connstr, undef, $testname, extra_params => [ '-w' ]); + } } # Initialize primary node diff --git a/src/test/authentication/t/002_saslprep.pl b/src/test/authentication/t/002_saslprep.pl index 0aaab090ec..33e305e16c 100644 --- a/src/test/authentication/t/002_saslprep.pl +++ b/src/test/authentication/t/002_saslprep.pl @@ -41,12 +41,19 @@ sub test_login $status_string = 'success' if ($expected_res eq 0); + my $connstr = "user=$role"; + my $testname = "authentication $status_string for role $role with password $password"; + $ENV{"PGPASSWORD"} = $password; - my $res = $node->psql('postgres', undef, extra_params => [ '-U', $role ]); - is($res, $expected_res, - "authentication $status_string for role $role with password $password" - ); - return; + if ($expected_res eq 0) + { + $node->connect_ok($connstr, $testname); + } + else + { + # Currently, we don't check the error message, just the code. + $node->connect_fails($connstr, undef, $testname); + } } # Initialize primary node. Force UTF-8 encoding, so that we can use non-ASCII diff --git a/src/test/ldap/t/001_auth.pl b/src/test/ldap/t/001_auth.pl index 3bc7672451..b20e487db8 100644 --- a/src/test/ldap/t/001_auth.pl +++ b/src/test/ldap/t/001_auth.pl @@ -163,12 +163,19 @@ note "running tests"; sub test_access { my ($node, $role, $expected_res, $test_name) = @_; - - my $res = - $node->psql('postgres', undef, - extra_params => [ '-U', $role, '-c', 'SELECT 1' ]); - is($res, $expected_res, $test_name); - return; + my $connstr = "user=$role"; + + local $Test::Builder::Level = $Test::Builder::Level + 1; + + if ($expected_res eq 0) + { + $node->connect_ok($connstr, $test_name); + } + else + { + # Currently, we don't check the error message, just the code. + $node->connect_fails($connstr, undef, $test_name); + } } note "simple bind"; diff --git a/src/test/perl/PostgresNode.pm b/src/test/perl/PostgresNode.pm index d6e10544bb..137736cce6 100644 --- a/src/test/perl/PostgresNode.pm +++ b/src/test/perl/PostgresNode.pm @@ -1860,47 +1860,53 @@ sub interactive_psql =pod -=item $node->connect_ok($connstr, $test_name) +=item $node->connect_ok($connstr, $test_name [, %params ]) Attempt a connection with a custom connection string. This is expected -to succeed. +to succeed. Any additional named parameters are passed to psql(). =cut sub connect_ok { local $Test::Builder::Level = $Test::Builder::Level + 1; - my ($self, $connstr, $test_name) = @_; + my ($self, $connstr, $test_name, %params) = @_; my ($ret, $stdout, $stderr) = $self->psql( 'postgres', "SELECT \$\$connected with $connstr\$\$", + %params, connstr => "$connstr", on_error_stop => 0); - ok($ret == 0, $test_name); + is($ret, 0, $test_name); } =pod -=item $node->connect_fails($connstr, $expected_stderr, $test_name) +=item $node->connect_fails($connstr, $expected_stderr, $test_name [, %params ]) Attempt a connection with a custom connection string. This is expected to fail with a message that matches the regular expression -$expected_stderr. +$expected_stderr. Any additional named parameters are passed to psql(). =cut sub connect_fails { local $Test::Builder::Level = $Test::Builder::Level + 1; - my ($self, $connstr, $expected_stderr, $test_name) = @_; + my ($self, $connstr, $expected_stderr, $test_name, %params) = @_; my ($ret, $stdout, $stderr) = $self->psql( 'postgres', "SELECT \$\$connected with $connstr\$\$", + %params, connstr => "$connstr"); - ok($ret != 0, $test_name); - like($stderr, $expected_stderr, "$test_name: matches"); + isnt($ret, 0, $test_name); + + if (defined $expected_stderr) + { + like($stderr, $expected_stderr, "$test_name: matches"); + } } =pod -- 2.25.1
From 1fd091cb6968783128b1e6cec8da9fa3eb751f73 Mon Sep 17 00:00:00 2001 From: Jacob Champion <pchamp...@vmware.com> Date: Thu, 1 Apr 2021 11:45:53 -0700 Subject: [PATCH v16 2/3] test/kerberos: migrate to $node->connect_ok() connect_ok() has been enhanced to take an optional query to override the default. --- src/test/kerberos/t/001_auth.pl | 57 +++++++++++++++++---------------- src/test/perl/PostgresNode.pm | 24 ++++++++++++-- 2 files changed, 51 insertions(+), 30 deletions(-) diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index 38e9ef7b1f..401f52f70a 100644 --- a/src/test/kerberos/t/001_auth.pl +++ b/src/test/kerberos/t/001_auth.pl @@ -20,7 +20,7 @@ use Time::HiRes qw(usleep); if ($ENV{with_gssapi} eq 'yes') { - plan tests => 26; + plan tests => 34; } else { @@ -185,25 +185,26 @@ sub test_access my ($node, $role, $query, $expected_res, $gssencmode, $test_name, $expect_log_msg) = @_; # need to connect over TCP/IP for Kerberos - my ($res, $stdoutres, $stderrres) = $node->psql( - 'postgres', - "$query", - extra_params => [ - '-XAtd', - $node->connstr('postgres') - . " host=$host hostaddr=$hostaddr $gssencmode", - '-U', - $role - ]); - - # If we get a query result back, it should be true. - if ($res == $expected_res and $res eq 0) + my $connstr = $node->connstr('postgres') . + " user=$role host=$host hostaddr=$hostaddr $gssencmode"; + + my %params = ( + query => $query, + extra_params => [ '-XAt' ], + ); + + if ($expected_res eq 0) { - is($stdoutres, "t", $test_name); + my $stdoutres; + $params{stdout} = \$stdoutres; + + $node->connect_ok($connstr, $test_name, %params); + + is($stdoutres, "t", "$test_name: query result is true"); } else { - is($res, $expected_res, $test_name); + $node->connect_fails($connstr, undef, $test_name, %params); } # Verify specified log message is logged in the log file. @@ -227,18 +228,18 @@ sub test_query my ($node, $role, $query, $expected, $gssencmode, $test_name) = @_; # need to connect over TCP/IP for Kerberos - my ($res, $stdoutres, $stderrres) = $node->psql( - 'postgres', - "$query", - extra_params => [ - '-XAtd', - $node->connstr('postgres') - . " host=$host hostaddr=$hostaddr $gssencmode", - '-U', - $role - ]); - - is($res, 0, $test_name); + my $connstr = $node->connstr('postgres') . + " user=$role host=$host hostaddr=$hostaddr $gssencmode"; + + my ($stdoutres, $stderrres); + + $node->connect_ok($connstr, $test_name, + query => $query, + extra_params => [ '-XAt' ], + stdout => \$stdoutres, + stderr => \$stderrres, + ); + like($stdoutres, $expected, $test_name); is($stderrres, "", $test_name); return; diff --git a/src/test/perl/PostgresNode.pm b/src/test/perl/PostgresNode.pm index 137736cce6..eea8c0bef5 100644 --- a/src/test/perl/PostgresNode.pm +++ b/src/test/perl/PostgresNode.pm @@ -1863,7 +1863,20 @@ sub interactive_psql =item $node->connect_ok($connstr, $test_name [, %params ]) Attempt a connection with a custom connection string. This is expected -to succeed. Any additional named parameters are passed to psql(). +to succeed. + +=over + +=item query => 'SELECT some_query;' + +By default, a query based on the connection string is performed after the +connection succeeds, to identify it in the server logs. If B<query> is set, it +will be used instead. This can be used with the B<stdout> parameter (see +C<psql()>) to capture a query result. + +=back + +Any additional named parameters are passed to C<psql()> as-is. =cut @@ -1871,9 +1884,16 @@ sub connect_ok { local $Test::Builder::Level = $Test::Builder::Level + 1; my ($self, $connstr, $test_name, %params) = @_; + + my $query = "SELECT \$\$connected with $connstr\$\$"; + if (exists $params{query}) + { + $query = delete $params{query}; + } + my ($ret, $stdout, $stderr) = $self->psql( 'postgres', - "SELECT \$\$connected with $connstr\$\$", + $query, %params, connstr => "$connstr", on_error_stop => 0); -- 2.25.1
From 7727491c1fbf893da3bf6faab0aa377fe6f2e096 Mon Sep 17 00:00:00 2001 From: Jacob Champion <pchamp...@vmware.com> Date: Thu, 1 Apr 2021 16:01:27 -0700 Subject: [PATCH v16 3/3] Log authenticated identity from all auth backends The "authenticated identity" is the string used by an auth method to identify a particular user. In many common cases this is the same as the Postgres username, but for some third-party auth methods, the identifier in use may be shortened or otherwise translated (e.g. through pg_ident mappings) before the server stores it. To help DBAs see who has actually interacted with the system, store the original identity when authentication succeeds, and expose it via the log_connections setting. The log entries look something like this example (where a local user named "pchampion" is connecting to the database as the "admin" user): LOG: connection received: host=[local] LOG: connection authenticated: identity="pchampion" method=peer (/data/pg_hba.conf:88) LOG: connection authorized: user=admin database=postgres application_name=psql port->authn_id is set according to the auth method: bsd: the Postgres username (which is the local username) cert: the client's Subject DN gss: the user principal ident: the remote username ldap: the final bind DN pam: the Postgres username (which is the PAM username) password (and all pw-challenge methods): the Postgres username peer: the peer's pw_name radius: the Postgres username (which is the RADIUS username) sspi: either the down-level (SAM-compatible) logon name, if compat_realm=1, or the User Principal Name if compat_realm=0 The trust auth method does not set an authenticated identity. Neither does using clientcert=verify-full (use the cert auth method instead). PostgresNode::connect_ok/fails() have been modified to let tests check the logfiles for required or prohibited patterns, using the respective log_like and log_unlike parameters. --- doc/src/sgml/config.sgml | 3 +- src/backend/libpq/auth.c | 136 ++++++++++++++++++++-- src/backend/libpq/hba.c | 24 ++++ src/include/libpq/hba.h | 1 + src/include/libpq/libpq-be.h | 13 +++ src/test/authentication/t/001_password.pl | 49 +++++--- src/test/kerberos/t/001_auth.pl | 67 +++++++---- src/test/ldap/t/001_auth.pl | 20 ++-- src/test/perl/PostgresNode.pm | 88 +++++++++++++- src/test/ssl/t/001_ssltests.pl | 30 +++-- src/test/ssl/t/002_scram.pl | 8 +- 11 files changed, 375 insertions(+), 64 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index d1e2e8c4c3..38344ced5b 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6694,7 +6694,8 @@ local0.* /var/log/postgresql <listitem> <para> Causes each attempted connection to the server to be logged, - as well as successful completion of client authentication. + as well as successful completion of both client authentication (if + necessary) and authorization. Only superusers can change this parameter at session start, and it cannot be changed at all within a session. The default is <literal>off</literal>. diff --git a/src/backend/libpq/auth.c b/src/backend/libpq/auth.c index 9dc28e19aa..dee056b0d6 100644 --- a/src/backend/libpq/auth.c +++ b/src/backend/libpq/auth.c @@ -34,8 +34,10 @@ #include "libpq/scram.h" #include "miscadmin.h" #include "port/pg_bswap.h" +#include "postmaster/postmaster.h" #include "replication/walsender.h" #include "storage/ipc.h" +#include "utils/guc.h" #include "utils/memutils.h" #include "utils/timestamp.h" @@ -47,6 +49,7 @@ static void sendAuthRequest(Port *port, AuthRequest areq, const char *extradata, int extralen); static void auth_failed(Port *port, int status, char *logdetail); static char *recv_password_packet(Port *port); +static void set_authn_id(Port *port, const char *id); /*---------------------------------------------------------------- @@ -337,6 +340,51 @@ auth_failed(Port *port, int status, char *logdetail) } +/* + * Sets the authenticated identity for the current user. The provided string + * will be copied into the TopMemoryContext. The ID will be logged if + * log_connections is enabled. + * + * Auth methods should call this routine exactly once, as soon as the user is + * successfully authenticated, even if they have reasons to know that + * authorization will fail later. + * + * The provided string will be copied into TopMemoryContext, to match the + * lifetime of the Port, so it is safe to pass a string that is managed by an + * external library. + */ +static void +set_authn_id(Port *port, const char *id) +{ + Assert(id); + + if (port->authn_id) + { + /* + * An existing authn_id should never be overwritten; that means two + * authentication providers are fighting (or one is fighting itself). + * Don't leak any authn details to the client, but don't let the + * connection continue, either. + */ + ereport(FATAL, + (errmsg("connection was re-authenticated"), + errdetail_log("previous ID: \"%s\"; new ID: \"%s\"", + port->authn_id, id))); + } + + port->authn_id = MemoryContextStrdup(TopMemoryContext, id); + + if (Log_connections) + { + ereport(LOG, + errmsg("connection authenticated: identity=\"%s\" method=%s " + "(%s:%d)", + port->authn_id, hba_authname(port), HbaFileName, + port->hba->linenumber)); + } +} + + /* * Client authentication starts here. If there is an error, this * function does not return and the backend process is terminated. @@ -757,6 +805,9 @@ CheckPasswordAuth(Port *port, char **logdetail) pfree(shadow_pass); pfree(passwd); + if (result == STATUS_OK) + set_authn_id(port, port->user_name); + return result; } @@ -816,6 +867,10 @@ CheckPWChallengeAuth(Port *port, char **logdetail) Assert(auth_result != STATUS_OK); return STATUS_ERROR; } + + if (auth_result == STATUS_OK) + set_authn_id(port, port->user_name); + return auth_result; } @@ -1174,8 +1229,13 @@ pg_GSS_checkauth(Port *port) /* * Copy the original name of the authenticated principal into our backend * memory for display later. + * + * This is also our authenticated identity. Set it now, rather than + * waiting for the usermap check below, because authentication has already + * succeeded and we want the log file to reflect that. */ port->gss->princ = MemoryContextStrdup(TopMemoryContext, gbuf.value); + set_authn_id(port, gbuf.value); /* * Split the username at the realm separator @@ -1285,6 +1345,7 @@ pg_SSPI_recvauth(Port *port) DWORD domainnamesize = sizeof(domainname); SID_NAME_USE accountnameuse; HMODULE secur32; + char *authn_id; QUERY_SECURITY_CONTEXT_TOKEN_FN _QuerySecurityContextToken; @@ -1514,6 +1575,26 @@ pg_SSPI_recvauth(Port *port) return status; } + /* + * We have all of the information necessary to construct the authenticated + * identity. Set it now, rather than waiting for check_usermap below, + * because authentication has already succeeded and we want the log file + * to reflect that. + */ + if (port->hba->compat_realm) + { + /* SAM-compatible format. */ + authn_id = psprintf("%s\\%s", domainname, accountname); + } + else + { + /* Kerberos principal format. */ + authn_id = psprintf("%s@%s", accountname, domainname); + } + + set_authn_id(port, authn_id); + pfree(authn_id); + /* * Compare realm/domain if requested. In SSPI, always compare case * insensitive. @@ -1901,8 +1982,15 @@ ident_inet_done: pg_freeaddrinfo_all(local_addr.addr.ss_family, la); if (ident_return) - /* Success! Check the usermap */ + { + /* + * Success! Store the identity, then check the usermap. Note that + * setting the authenticated identity is done before checking the + * usermap, because at this point authentication has succeeded. + */ + set_authn_id(port, ident_user); return check_usermap(port->hba->usermap, port->user_name, ident_user, false); + } return STATUS_ERROR; } @@ -1926,7 +2014,6 @@ auth_peer(hbaPort *port) gid_t gid; #ifndef WIN32 struct passwd *pw; - char *peer_user; int ret; #endif @@ -1958,12 +2045,14 @@ auth_peer(hbaPort *port) return STATUS_ERROR; } - /* Make a copy of static getpw*() result area. */ - peer_user = pstrdup(pw->pw_name); - - ret = check_usermap(port->hba->usermap, port->user_name, peer_user, false); + /* + * Make a copy of static getpw*() result area; this is our authenticated + * identity. Set it before calling check_usermap, because authentication + * has already succeeded and we want the log file to reflect that. + */ + set_authn_id(port, pw->pw_name); - pfree(peer_user); + ret = check_usermap(port->hba->usermap, port->user_name, port->authn_id, false); return ret; #else @@ -2220,6 +2309,9 @@ CheckPAMAuth(Port *port, const char *user, const char *password) pam_passwd = NULL; /* Unset pam_passwd */ + if (retval == PAM_SUCCESS) + set_authn_id(port, user); + return (retval == PAM_SUCCESS ? STATUS_OK : STATUS_ERROR); } #endif /* USE_PAM */ @@ -2255,6 +2347,7 @@ CheckBSDAuth(Port *port, char *user) if (!retval) return STATUS_ERROR; + set_authn_id(port, user); return STATUS_OK; } #endif /* USE_BSD_AUTH */ @@ -2761,6 +2854,9 @@ CheckLDAPAuth(Port *port) return STATUS_ERROR; } + /* Save the original bind DN as the authenticated identity. */ + set_authn_id(port, fulluser); + ldap_unbind(ldap); pfree(passwd); pfree(fulluser); @@ -2824,6 +2920,30 @@ CheckCertAuth(Port *port) return STATUS_ERROR; } + if (port->hba->auth_method == uaCert) + { + /* + * For cert auth, the client's Subject DN is always our authenticated + * identity, even if we're only using its CN for authorization. Set + * it now, rather than waiting for check_usermap() below, because + * authentication has already succeeded and we want the log file to + * reflect that. + */ + if (!port->peer_dn) + { + /* + * This should not happen as both peer_dn and peer_cn should be + * set in this context. + */ + ereport(LOG, + (errmsg("certificate authentication failed for user \"%s\": unable to retrieve subject DN", + port->user_name))); + return STATUS_ERROR; + } + + set_authn_id(port, port->peer_dn); + } + /* Just pass the certificate cn/dn to the usermap check */ status_check_usermap = check_usermap(port->hba->usermap, port->user_name, peer_username, false); if (status_check_usermap != STATUS_OK) @@ -2995,6 +3115,8 @@ CheckRADIUSAuth(Port *port) */ if (ret == STATUS_OK) { + set_authn_id(port, port->user_name); + pfree(passwd); return STATUS_OK; } diff --git a/src/backend/libpq/hba.c b/src/backend/libpq/hba.c index feb711a6ef..b720b03e9a 100644 --- a/src/backend/libpq/hba.c +++ b/src/backend/libpq/hba.c @@ -3141,3 +3141,27 @@ hba_getauthmethod(hbaPort *port) { check_hba(port); } + + +/* + * Return the name of the auth method in use ("gss", "md5", "trust", etc.). + * + * The return value is statically allocated (see the UserAuthName array) and + * should not be freed. + */ +const char * +hba_authname(hbaPort *port) +{ + UserAuth auth_method; + + Assert(port->hba); + auth_method = port->hba->auth_method; + + if (auth_method < 0 || USER_AUTH_LAST < auth_method) + { + /* Should never happen. */ + elog(FATAL, "port has out-of-bounds UserAuth: %d", auth_method); + } + + return UserAuthName[auth_method]; +} diff --git a/src/include/libpq/hba.h b/src/include/libpq/hba.h index 1ec8603da7..63f2962139 100644 --- a/src/include/libpq/hba.h +++ b/src/include/libpq/hba.h @@ -137,6 +137,7 @@ typedef struct Port hbaPort; extern bool load_hba(void); extern bool load_ident(void); +extern const char *hba_authname(hbaPort *port); extern void hba_getauthmethod(hbaPort *port); extern int check_usermap(const char *usermap_name, const char *pg_role, const char *auth_user, diff --git a/src/include/libpq/libpq-be.h b/src/include/libpq/libpq-be.h index 713c34fedd..02015efe13 100644 --- a/src/include/libpq/libpq-be.h +++ b/src/include/libpq/libpq-be.h @@ -159,6 +159,19 @@ typedef struct Port */ HbaLine *hba; + /* + * Authenticated identity. The meaning of this identifier is dependent on + * hba->auth_method; it is the identity (if any) that the user presented + * during the authentication cycle, before they were assigned a database + * role. (It is effectively the "SYSTEM-USERNAME" of a pg_ident usermap + * -- though the exact string in use may be different, depending on pg_hba + * options.) + * + * authn_id is NULL if the user has not actually been authenticated, for + * example if the "trust" auth method is in use. + */ + const char *authn_id; + /* * TCP keepalive and user timeout settings. * diff --git a/src/test/authentication/t/001_password.pl b/src/test/authentication/t/001_password.pl index 92d9b25332..f2cd7377d1 100644 --- a/src/test/authentication/t/001_password.pl +++ b/src/test/authentication/t/001_password.pl @@ -17,7 +17,7 @@ if (!$use_unix_sockets) } else { - plan tests => 13; + plan tests => 23; } @@ -35,15 +35,12 @@ sub reset_pg_hba return; } -# Test access for a single role, useful to wrap all tests into one. +# Test access for a single role, useful to wrap all tests into one. Extra +# named parameters are passed to connect_ok/fails as-is. sub test_role { - my $node = shift; - my $role = shift; - my $method = shift; - my $expected_res = shift; + my ($node, $role, $method, $expected_res, %params) = @_; my $status_string = 'failed'; - $status_string = 'success' if ($expected_res eq 0); local $Test::Builder::Level = $Test::Builder::Level + 1; @@ -53,18 +50,19 @@ sub test_role if ($expected_res eq 0) { - $node->connect_ok($connstr, $testname, extra_params => [ '-w' ]); + $node->connect_ok($connstr, $testname, %params, extra_params => [ '-w' ]); } else { # Currently, we don't check the error message, just the code. - $node->connect_fails($connstr, undef, $testname, extra_params => [ '-w' ]); + $node->connect_fails($connstr, undef, $testname, %params, extra_params => [ '-w' ]); } } # Initialize primary node my $node = get_new_node('primary'); $node->init; +$node->append_conf('postgresql.conf', "log_connections = on\n"); $node->start; # Create 3 roles with different password methods for each one. The same @@ -77,26 +75,41 @@ $node->safe_psql('postgres', ); $ENV{"PGPASSWORD"} = 'pass'; -# For "trust" method, all users should be able to connect. +# For "trust" method, all users should be able to connect. These users are not +# considered to be authenticated. reset_pg_hba($node, 'trust'); -test_role($node, 'scram_role', 'trust', 0); -test_role($node, 'md5_role', 'trust', 0); +test_role($node, 'scram_role', 'trust', 0, + log_unlike => [ qr/connection authenticated:/ ]); +test_role($node, 'md5_role', 'trust', 0, + log_unlike => [ qr/connection authenticated:/ ]); # For plain "password" method, all users should also be able to connect. reset_pg_hba($node, 'password'); -test_role($node, 'scram_role', 'password', 0); -test_role($node, 'md5_role', 'password', 0); +test_role($node, 'scram_role', 'password', 0, + log_like => [ qr/connection authenticated: identity="scram_role" method=password/ ]); +test_role($node, 'md5_role', 'password', 0, + log_like => [ qr/connection authenticated: identity="md5_role" method=password/ ]); # For "scram-sha-256" method, user "scram_role" should be able to connect. reset_pg_hba($node, 'scram-sha-256'); -test_role($node, 'scram_role', 'scram-sha-256', 0); -test_role($node, 'md5_role', 'scram-sha-256', 2); +test_role($node, 'scram_role', 'scram-sha-256', 0, + log_like => [ qr/connection authenticated: identity="scram_role" method=scram-sha-256/ ]); +test_role($node, 'md5_role', 'scram-sha-256', 2, + log_unlike => [ qr/connection authenticated:/ ]); + +# Test that bad passwords are rejected. +$ENV{"PGPASSWORD"} = 'badpass'; +test_role($node, 'scram_role', 'scram-sha-256', 2, + log_unlike => [ qr/connection authenticated:/ ]); +$ENV{"PGPASSWORD"} = 'pass'; # For "md5" method, all users should be able to connect (SCRAM # authentication will be performed for the user with a SCRAM secret.) reset_pg_hba($node, 'md5'); -test_role($node, 'scram_role', 'md5', 0); -test_role($node, 'md5_role', 'md5', 0); +test_role($node, 'scram_role', 'md5', 0, + log_like => [ qr/connection authenticated: identity="scram_role" method=md5/ ]); +test_role($node, 'md5_role', 'md5', 0, + log_like => [ qr/connection authenticated: identity="md5_role" method=md5/ ]); # Tests for channel binding without SSL. # Using the password authentication method; channel binding can't work diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index 401f52f70a..5ca2eb0694 100644 --- a/src/test/kerberos/t/001_auth.pl +++ b/src/test/kerberos/t/001_auth.pl @@ -20,7 +20,7 @@ use Time::HiRes qw(usleep); if ($ENV{with_gssapi} eq 'yes') { - plan tests => 34; + plan tests => 46; } else { @@ -182,7 +182,8 @@ note "running tests"; # Test connection success or failure, and if success, that query returns true. sub test_access { - my ($node, $role, $query, $expected_res, $gssencmode, $test_name, $expect_log_msg) = @_; + my ($node, $role, $query, $expected_res, $gssencmode, $test_name, + @expect_log_msgs) = @_; # need to connect over TCP/IP for Kerberos my $connstr = $node->connstr('postgres') . @@ -193,6 +194,14 @@ sub test_access extra_params => [ '-XAt' ], ); + if (@expect_log_msgs) + { + # Match every message literally. + my @regexes = map { qr/\Q$_\E/ } @expect_log_msgs; + + $params{log_like} = \@regexes; + } + if ($expected_res eq 0) { my $stdoutres; @@ -206,20 +215,6 @@ sub test_access { $node->connect_fails($connstr, undef, $test_name, %params); } - - # Verify specified log message is logged in the log file. - if ($expect_log_msg ne '') - { - my $first_logfile = slurp_file($node->logfile); - - like($first_logfile, qr/\Q$expect_log_msg\E/, - 'found expected log file content'); - } - - # Clean up any existing contents in the node's log file so as - # future tests don't step on each other's generated contents. - truncate $node->logfile, 0; - return; } # As above, but test for an arbitrary query result. @@ -250,11 +245,19 @@ $node->append_conf('pg_hba.conf', qq{host all all $hostaddr/32 gss map=mymap}); $node->restart; -test_access($node, 'test1', 'SELECT true', 2, '', 'fails without ticket', ''); +test_access($node, 'test1', 'SELECT true', 2, '', 'fails without ticket'); run_log [ $kinit, 'test1' ], \$test1_password or BAIL_OUT($?); -test_access($node, 'test1', 'SELECT true', 2, '', 'fails without mapping', ''); +test_access( + $node, + 'test1', + 'SELECT true', + 2, + '', + 'fails without mapping', + "connection authenticated: identity=\"test1\@$realm\" method=gss", + "no match in usermap \"mymap\" for user \"test1\""); $node->append_conf('pg_ident.conf', qq{mymap /^(.*)\@$realm\$ \\1}); $node->restart; @@ -266,6 +269,7 @@ test_access( 0, '', 'succeeds with mapping with default gssencmode and host hba', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" ); @@ -276,6 +280,7 @@ test_access( 0, 'gssencmode=prefer', 'succeeds with GSS-encrypted access preferred with host hba', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" ); test_access( @@ -285,6 +290,7 @@ test_access( 0, 'gssencmode=require', 'succeeds with GSS-encrypted access required with host hba', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" ); @@ -321,6 +327,7 @@ test_access( 0, 'gssencmode=prefer', 'succeeds with GSS-encrypted access preferred and hostgssenc hba', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" ); test_access( @@ -330,10 +337,11 @@ test_access( 0, 'gssencmode=require', 'succeeds with GSS-encrypted access required and hostgssenc hba', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" ); test_access($node, 'test1', 'SELECT true', 2, 'gssencmode=disable', - 'fails with GSS encryption disabled and hostgssenc hba', ''); + 'fails with GSS encryption disabled and hostgssenc hba'); unlink($node->data_dir . '/pg_hba.conf'); $node->append_conf('pg_hba.conf', @@ -347,10 +355,11 @@ test_access( 0, 'gssencmode=prefer', 'succeeds with GSS-encrypted access preferred and hostnogssenc hba, but no encryption', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=no, principal=test1\@$realm)" ); test_access($node, 'test1', 'SELECT true', 2, 'gssencmode=require', - 'fails with GSS-encrypted access required and hostnogssenc hba', ''); + 'fails with GSS-encrypted access required and hostnogssenc hba'); test_access( $node, 'test1', @@ -358,6 +367,7 @@ test_access( 0, 'gssencmode=disable', 'succeeds with GSS encryption disabled and hostnogssenc hba', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=no, principal=test1\@$realm)" ); @@ -374,5 +384,22 @@ test_access( 0, '', 'succeeds with include_realm=0 and defaults', + "connection authenticated: identity=\"test1\@$realm\" method=gss", "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" ); + +# Reset pg_hba.conf, and cause a usermap failure with an authentication +# that has passed. +unlink($node->data_dir . '/pg_hba.conf'); +$node->append_conf('pg_hba.conf', + qq{host all all $hostaddr/32 gss include_realm=0 krb_realm=EXAMPLE.ORG}); +$node->restart; + +test_access( + $node, + 'test1', + 'SELECT true', + 2, + '', + 'fails with wrong krb_realm, but still authenticates', + "connection authenticated: identity=\"test1\@$realm\" method=gss"); diff --git a/src/test/ldap/t/001_auth.pl b/src/test/ldap/t/001_auth.pl index b20e487db8..bf3cf4a658 100644 --- a/src/test/ldap/t/001_auth.pl +++ b/src/test/ldap/t/001_auth.pl @@ -6,7 +6,7 @@ use Test::More; if ($ENV{with_ldap} eq 'yes') { - plan tests => 22; + plan tests => 25; } else { @@ -152,6 +152,7 @@ note "setting up PostgreSQL instance"; my $node = get_new_node('node'); $node->init; +$node->append_conf('postgresql.conf', "log_connections = on\n"); $node->start; $node->safe_psql('postgres', 'CREATE USER test0;'); @@ -162,19 +163,19 @@ note "running tests"; sub test_access { - my ($node, $role, $expected_res, $test_name) = @_; + my ($node, $role, $expected_res, $test_name, %params) = @_; my $connstr = "user=$role"; local $Test::Builder::Level = $Test::Builder::Level + 1; if ($expected_res eq 0) { - $node->connect_ok($connstr, $test_name); + $node->connect_ok($connstr, $test_name, %params); } else { # Currently, we don't check the error message, just the code. - $node->connect_fails($connstr, undef, $test_name); + $node->connect_fails($connstr, undef, $test_name, %params); } } @@ -188,11 +189,16 @@ $node->restart; $ENV{"PGPASSWORD"} = 'wrong'; test_access($node, 'test0', 2, - 'simple bind authentication fails if user not found in LDAP'); + 'simple bind authentication fails if user not found in LDAP', + log_unlike => [ qr/connection authenticated:/ ]); test_access($node, 'test1', 2, - 'simple bind authentication fails with wrong password'); + 'simple bind authentication fails with wrong password', + log_unlike => [ qr/connection authenticated:/ ]); + $ENV{"PGPASSWORD"} = 'secret1'; -test_access($node, 'test1', 0, 'simple bind authentication succeeds'); +test_access($node, 'test1', 0, 'simple bind authentication succeeds', + log_like => [ qr/connection authenticated: identity="uid=test1,dc=example,dc=net" method=ldap/ ], +); note "search+bind"; diff --git a/src/test/perl/PostgresNode.pm b/src/test/perl/PostgresNode.pm index eea8c0bef5..2afe225267 100644 --- a/src/test/perl/PostgresNode.pm +++ b/src/test/perl/PostgresNode.pm @@ -1874,6 +1874,17 @@ connection succeeds, to identify it in the server logs. If B<query> is set, it will be used instead. This can be used with the B<stdout> parameter (see C<psql()>) to capture a query result. +=item log_like => [ qr/required message/ ] + +If given, it must be an array reference containing a list of regular expressions +to match against the server log, using C<Test::More::like()>. + +=item log_unlike => [ qr/prohibited message/ ] + +If given, it must be an array reference containing a list of regular expressions +that must NOT match against the server log. They will be passed to +C<Test::More::unlike()>. + =back Any additional named parameters are passed to C<psql()> as-is. @@ -1891,6 +1902,22 @@ sub connect_ok $query = delete $params{query}; } + my (@log_like, @log_unlike); + if (exists $params{log_like}) + { + @log_like = @{ delete $params{log_like} }; + } + if (exists $params{log_unlike}) + { + @log_unlike = @{ delete $params{log_unlike} }; + } + + if (@log_like or @log_unlike) + { + # Don't let previous log entries match for this connection. + truncate $self->logfile, 0; + } + my ($ret, $stdout, $stderr) = $self->psql( 'postgres', $query, @@ -1899,6 +1926,20 @@ sub connect_ok on_error_stop => 0); is($ret, 0, $test_name); + + if (@log_like or @log_unlike) + { + my $log_contents = TestLib::slurp_file($self->logfile); + + while (my $regex = shift @log_like) + { + like($log_contents, $regex, "$test_name: log matches"); + } + while (my $regex = shift @log_unlike) + { + unlike($log_contents, $regex, "$test_name: log does not match"); + } + } } =pod @@ -1907,7 +1948,19 @@ sub connect_ok Attempt a connection with a custom connection string. This is expected to fail with a message that matches the regular expression -$expected_stderr. Any additional named parameters are passed to psql(). +$expected_stderr. + +=over + +=item log_like => [ qr/required message/ ] + +=item log_unlike => [ qr/prohibited message/ ] + +See C<connect_ok()>, above. + +=back + +Any additional named parameters are passed to C<psql()>. =cut @@ -1915,6 +1968,23 @@ sub connect_fails { local $Test::Builder::Level = $Test::Builder::Level + 1; my ($self, $connstr, $expected_stderr, $test_name, %params) = @_; + + my (@log_like, @log_unlike); + if (exists $params{log_like}) + { + @log_like = @{ delete $params{log_like} }; + } + if (exists $params{log_unlike}) + { + @log_unlike = @{ delete $params{log_unlike} }; + } + + if (@log_like or @log_unlike) + { + # Don't let previous log entries match for this connection. + truncate $self->logfile, 0; + } + my ($ret, $stdout, $stderr) = $self->psql( 'postgres', "SELECT \$\$connected with $connstr\$\$", @@ -1925,7 +1995,21 @@ sub connect_fails if (defined $expected_stderr) { - like($stderr, $expected_stderr, "$test_name: matches"); + like($stderr, $expected_stderr, "$test_name: stderr matches"); + } + + if (@log_like or @log_unlike) + { + my $log_contents = TestLib::slurp_file($self->logfile); + + while (my $regex = shift @log_like) + { + like($log_contents, $regex, "$test_name: log matches"); + } + while (my $regex = shift @log_unlike) + { + unlike($log_contents, $regex, "$test_name: log does not match"); + } } } diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl index b1a63f279c..943703fc44 100644 --- a/src/test/ssl/t/001_ssltests.pl +++ b/src/test/ssl/t/001_ssltests.pl @@ -17,7 +17,7 @@ if ($ENV{with_ssl} ne 'openssl') } else { - plan tests => 103; + plan tests => 110; } #### Some configuration @@ -418,7 +418,8 @@ my $dn_connstr = "$common_connstr dbname=certdb_dn"; $node->connect_ok( "$dn_connstr user=ssltestuser sslcert=ssl/client-dn.crt sslkey=ssl/client-dn_tmp.key", - "certificate authorization succeeds with DN mapping"); + "certificate authorization succeeds with DN mapping", + log_like => [ qr/connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert/ ]); # same thing but with a regex $dn_connstr = "$common_connstr dbname=certdb_dn_re"; @@ -432,7 +433,9 @@ $dn_connstr = "$common_connstr dbname=certdb_cn"; $node->connect_ok( "$dn_connstr user=ssltestuser sslcert=ssl/client-dn.crt sslkey=ssl/client-dn_tmp.key", - "certificate authorization succeeds with CN mapping"); + "certificate authorization succeeds with CN mapping", + # the full DN should still be used as the authenticated identity + log_like => [ qr/connection authenticated: identity="CN=ssltestuser-dn,OU=Testing,OU=Engineering,O=PGDG" method=cert/ ]); @@ -493,14 +496,19 @@ SKIP: $node->connect_fails( "$common_connstr user=anotheruser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", qr/certificate authentication failed for user "anotheruser"/, - "certificate authorization fails with client cert belonging to another user" + "certificate authorization fails with client cert belonging to another user", + # certificate authentication should be logged even on failure + log_like => [ qr/connection authenticated: identity="CN=ssltestuser" method=cert/ ], ); # revoked client cert $node->connect_fails( "$common_connstr user=ssltestuser sslcert=ssl/client-revoked.crt sslkey=ssl/client-revoked_tmp.key", qr/SSL error/, - "certificate authorization fails with revoked client cert"); + "certificate authorization fails with revoked client cert", + # revoked certificates should not authenticate the user + log_unlike => [ qr/connection authenticated:/ ], +); # Check that connecting with auth-option verify-full in pg_hba: # works, iff username matches Common Name @@ -510,20 +518,26 @@ $common_connstr = $node->connect_ok( "$common_connstr user=ssltestuser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", - "auth_option clientcert=verify-full succeeds with matching username and Common Name" + "auth_option clientcert=verify-full succeeds with matching username and Common Name", + # verify-full does not provide authentication + log_unlike => [ qr/connection authenticated:/ ], ); $node->connect_fails( "$common_connstr user=anotheruser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", qr/FATAL/, - "auth_option clientcert=verify-full fails with mismatching username and Common Name" + "auth_option clientcert=verify-full fails with mismatching username and Common Name", + # verify-full does not provide authentication + log_unlike => [ qr/connection authenticated:/ ], ); # Check that connecting with auth-optionverify-ca in pg_hba : # works, when username doesn't match Common Name $node->connect_ok( "$common_connstr user=yetanotheruser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", - "auth_option clientcert=verify-ca succeeds with mismatching username and Common Name" + "auth_option clientcert=verify-ca succeeds with mismatching username and Common Name", + # verify-full does not provide authentication + log_unlike => [ qr/connection authenticated:/ ], ); # intermediate client_ca.crt is provided by client, and isn't in server's ssl_ca_file diff --git a/src/test/ssl/t/002_scram.pl b/src/test/ssl/t/002_scram.pl index e31650b931..d98f6319fa 100644 --- a/src/test/ssl/t/002_scram.pl +++ b/src/test/ssl/t/002_scram.pl @@ -27,7 +27,7 @@ my $SERVERHOSTCIDR = '127.0.0.1/32'; my $supports_tls_server_end_point = check_pg_config("#define HAVE_X509_GET_SIGNATURE_NID 1"); -my $number_of_tests = $supports_tls_server_end_point ? 9 : 10; +my $number_of_tests = $supports_tls_server_end_point ? 11 : 12; # Allocation of base connection string shared among multiple tests. my $common_connstr; @@ -96,6 +96,12 @@ $node->connect_fails( qr/channel binding required, but server authenticated client without channel binding/, "Cert authentication and channel_binding=require"); +# Certificate verification at the connection level should still work fine. +$node->connect_ok( + "sslcert=ssl/client.crt sslkey=$client_tmp_key sslrootcert=invalid hostaddr=$SERVERHOSTADDR dbname=verifydb user=ssltestuser channel_binding=require", + "SCRAM with clientcert=verify-full and channel_binding=require", + log_like => [ qr/connection authenticated: identity="ssltestuser" method=scram-sha-256/ ]); + # clean up unlink($client_tmp_key); -- 2.25.1