diff options
| -rw-r--r-- | src/backend/tcop/backend_startup.c | 23 | ||||
| -rw-r--r-- | src/backend/utils/misc/guc_tables.c | 11 | ||||
| -rw-r--r-- | src/test/libpq_encryption/t/001_negotiate_encryption.pl | 380 |
3 files changed, 255 insertions, 159 deletions
diff --git a/src/backend/tcop/backend_startup.c b/src/backend/tcop/backend_startup.c index 0b9f899cd8b..64df3ff32a2 100644 --- a/src/backend/tcop/backend_startup.c +++ b/src/backend/tcop/backend_startup.c @@ -37,6 +37,9 @@ #include "utils/ps_status.h" #include "utils/timeout.h" +/* GUCs */ +bool Trace_connection_negotiation = false; + static void BackendInitialize(ClientSocket *client_sock, CAC_state cac); static int ProcessStartupPacket(Port *port, bool ssl_done, bool gss_done); static void SendNegotiateProtocolVersion(List *unrecognized_protocol_options); @@ -474,6 +477,16 @@ ProcessStartupPacket(Port *port, bool ssl_done, bool gss_done) SSLok = 'N'; /* No support for SSL */ #endif + if (Trace_connection_negotiation) + { + if (SSLok == 'S') + ereport(LOG, + (errmsg("SSLRequest accepted"))); + else + ereport(LOG, + (errmsg("SSLRequest rejected"))); + } + retry1: if (send(port->sock, &SSLok, 1, 0) != 1) { @@ -519,6 +532,16 @@ retry1: GSSok = 'G'; #endif + if (Trace_connection_negotiation) + { + if (GSSok == 'G') + ereport(LOG, + (errmsg("GSSENCRequest accepted"))); + else + ereport(LOG, + (errmsg("GSSENCRequest rejected"))); + } + while (send(port->sock, &GSSok, 1, 0) != 1) { if (errno == EINTR) diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index f9bb2b0f9e5..83e3a59d7e9 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -96,6 +96,7 @@ /* XXX these should appear in other modules' header files */ extern bool Log_disconnections; +extern bool Trace_connection_negotiation; extern int CommitDelay; extern int CommitSiblings; extern char *default_tablespace; @@ -1225,6 +1226,16 @@ struct config_bool ConfigureNamesBool[] = NULL, NULL, NULL }, { + {"trace_connection_negotiation", PGC_POSTMASTER, DEVELOPER_OPTIONS, + gettext_noop("Log details of pre-authentication connection handshake."), + NULL, + GUC_NOT_IN_SAMPLE + }, + &Trace_connection_negotiation, + false, + NULL, NULL, NULL + }, + { {"log_disconnections", PGC_SU_BACKEND, LOGGING_WHAT, gettext_noop("Logs end of a session, including duration."), NULL diff --git a/src/test/libpq_encryption/t/001_negotiate_encryption.pl b/src/test/libpq_encryption/t/001_negotiate_encryption.pl index ed33988aa78..f277edda825 100644 --- a/src/test/libpq_encryption/t/001_negotiate_encryption.pl +++ b/src/test/libpq_encryption/t/001_negotiate_encryption.pl @@ -18,17 +18,21 @@ # Each combination is represented by a line in a table. The line lists # the options specifying the test case, and an expected outcome. The # expected outcome includes whether the connection succeeds or fails, -# and whether it uses SSL, GSS or no encryption. +# and whether it uses SSL, GSS or no encryption. It also includes a +# condensed trace of what steps were taken during the negotiation. +# That can catch cases like useless retries, or if the encryption +# methods are attempted in wrong order, even when it doesn't affect +# the final outcome. # # TEST TABLE FORMAT # ----------------- # # Example of the test table format: # -# # USER GSSENCMODE SSLMODE OUTCOME -# testuser disable allow plain -# . . prefer ssl -# testuser require * fail +# # USER GSSENCMODE SSLMODE EVENTS -> OUTCOME +# testuser disable allow connect, authok -> plain +# . . prefer connect, sslaccept, authok -> ssl +# testuser require * connect, gssreject -> fail # # USER, GSSENCMODE and SSLMODE fields are the libpq 'user', # 'gssencmode' and 'sslmode' options used in the test. As a shorthand, @@ -37,6 +41,23 @@ # as a wildcard; it is expanded to mean all possible values of that # field. # +# The EVENTS field is a condensed trace of expected steps during the +# negotiation: +# +# connect: a TCP connection was established +# reconnect: TCP connection was disconnected, and a new one was established +# sslaccept: client requested SSL encryption and server accepted it +# sslreject: client requested SSL encryption but server rejected it +# gssaccept: client requested GSSAPI encryption and server accepted it +# gssreject: client requested GSSAPI encryption but server rejected it +# authok: client sent startup packet and authentication was performed successfully +# authfail: client sent startup packet but server rejected the authentication +# +# The event trace can be used to verify that the client negotiated the +# connection properly in more detail than just by looking at the +# outcome. For example, if the client opens spurious extra TCP +# connections, that would show up in the EVENTS. +# # The OUTCOME field indicates the expected result of the test: # # plain: an unencrypted connection was established @@ -80,7 +101,11 @@ $node->init; $node->append_conf( 'postgresql.conf', qq{ listen_addresses = '$hostaddr' + +# Capturing the EVENTS that occur during tests requires these settings log_connections = on +log_disconnections = on +trace_connection_negotiation = on lc_messages = 'C' }); my $pgdata = $node->data_dir; @@ -190,20 +215,19 @@ my $server_config = { ### Run tests with GSS and SSL disabled in the server ### my $test_table = q{ -# USER GSSENCMODE SSLMODE OUTCOME -testuser disable disable plain -. . allow plain -. . prefer plain -. . require fail -. prefer disable plain -. . allow plain -. . prefer plain -. . require fail - -# All attempts with gssencmode=require fail because no credential -# cache has been configured in the client (and the server isn't -# configured for GSS either) -. require * fail +# USER GSSENCMODE SSLMODE EVENTS -> OUTCOME +testuser disable disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslreject, authok -> plain +. . require connect, sslreject -> fail +. prefer disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslreject, authok -> plain +. . require connect, sslreject -> fail + +# All attempts with gssencmode=require fail without connecting because +# no credential cache has been configured in the client +. require * - -> fail }; note("Running tests with SSL and GSS disabled in the server"); test_matrix($node, $server_config, @@ -218,19 +242,19 @@ SKIP: skip "SSL not supported by this build" if $ssl_supported == 0; $test_table = q{ -# USER GSSENCMODE SSLMODE OUTCOME -testuser disable disable plain -. . allow plain -. . prefer ssl -. . require ssl -ssluser . disable fail -. . allow ssl -. . prefer ssl -. . require ssl -nossluser . disable plain -. . allow plain -. . prefer plain -. . require fail +# USER GSSENCMODE SSLMODE EVENTS -> OUTCOME +testuser disable disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslaccept, authok -> ssl +. . require connect, sslaccept, authok -> ssl +ssluser . disable connect, authfail -> fail +. . allow connect, authfail, reconnect, sslaccept, authok -> ssl +. . prefer connect, sslaccept, authok -> ssl +. . require connect, sslaccept, authok -> ssl +nossluser . disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslaccept, authfail, reconnect, authok -> plain +. . require connect, sslaccept, authfail -> fail }; # Enable SSL in the server @@ -256,35 +280,50 @@ SKIP: { skip "GSSAPI/Kerberos not supported by this build" if $gss_supported == 0; $test_table = q{ -# USER GSSENCMODE SSLMODE OUTCOME -testuser disable disable plain -. . allow plain -. . prefer plain -. . require fail -. require * gss -. prefer * gss - -gssuser disable disable fail -. . allow fail -. . prefer fail -. . require fail -. prefer * gss -. require * gss - -nogssuser disable disable plain -. . allow plain -. . prefer plain -. . require fail -. prefer disable plain -. . allow plain -. . prefer plain -. . require fail -. require * fail +# USER GSSENCMODE SSLMODE EVENTS -> OUTCOME +testuser disable disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslreject, authok -> plain +. . require connect, sslreject -> fail +. prefer * connect, gssaccept, authok -> gss +. require disable connect, gssaccept, authok -> gss +. . allow connect, gssaccept, authok -> gss +. . prefer connect, gssaccept, authok -> gss +. . require connect, gssaccept, authok -> gss # If both GSS and SSL is possible, GSS is chosen over SSL, even if sslmode=require + +gssuser disable disable connect, authfail -> fail + +# XXX: after the reconnection and SSL negotiation failure, libpq tries +# again to authenticate in plaintext. That's unnecessariy and doomed +# to fail. We already know the server doesn't accept that because of +# the first authentication failure. +. . allow connect, authfail, reconnect, sslreject, authfail -> fail + +. . prefer connect, sslreject, authfail -> fail +. . require connect, sslreject -> fail +. prefer * connect, gssaccept, authok -> gss +. require * connect, gssaccept, authok -> gss + +nogssuser disable disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslreject, authok -> plain +. . require connect, sslreject, -> fail +. prefer disable connect, gssaccept, authfail, reconnect, authok -> plain +. . allow connect, gssaccept, authfail, reconnect, authok -> plain +. . prefer connect, gssaccept, authfail, reconnect, sslreject, authok -> plain +. . require connect, gssaccept, authfail, reconnect, sslreject -> fail +. require disable connect, gssaccept, authfail -> fail + +# XXX: libpq retries the connection unnecessarily in this case: +. . allow connect, gssaccept, authfail, reconnect, gssaccept, authfail -> fail + +. . prefer connect, gssaccept, authfail -> fail +. . require connect, gssaccept, authfail -> fail }; # Sanity check that the connection fails when no kerberos ticket # is present in the client - connect_test($node, 'user=testuser gssencmode=require sslmode=disable', 'fail'); + connect_test($node, 'user=testuser gssencmode=require sslmode=disable', '- -> fail'); $krb->create_principal('gssuser', $gssuser_password); $krb->create_ticket('gssuser', $gssuser_password); @@ -294,19 +333,6 @@ nogssuser disable disable plain test_matrix($node, $server_config, ['testuser', 'gssuser', 'nogssuser'], \@all_sslmodes, \@all_gssencmodes, parse_table($test_table)); - - # Check that logs match the expected 'no pg_hba.conf entry' line, too, as - # that is not tested by test_matrix. - connect_test($node, 'user=nogssuser gssencmode=require sslmode=prefer', 'fail', - 'no pg_hba.conf entry for host "127.0.0.1", user "nogssuser", database "postgres", GSS encryption'); - - # With 'gssencmode=prefer', libpq will first negotiate GSSAPI - # encryption, but the connection will fail because pg_hba.conf - # forbids GSSAPI encryption for this user. It will then reconnect - # with SSL, but the server doesn't support it, so it will continue - # with no encryption. - connect_test($node, 'user=nogssuser gssencmode=prefer sslmode=prefer', 'plain', - 'no pg_hba.conf entry for host "127.0.0.1", user "nogssuser", database "postgres", GSS encryption'); } ### @@ -317,57 +343,72 @@ SKIP: skip "GSSAPI/Kerberos or SSL not supported by this build" unless ($ssl_supported && $gss_supported); $test_table = q{ -# USER GSSENCMODE SSLMODE OUTCOME -testuser disable disable plain -. . allow plain -. . prefer ssl -. . require ssl -. prefer disable gss -. . allow gss -. . prefer gss -. . require gss # If both GSS and SSL is possible, GSS is chosen over SSL, even if sslmode=require -. require disable gss -. . allow gss -. . prefer gss -. . require gss # If both GSS and SSL is possible, GSS is chosen over SSL, even if sslmode=require - -gssuser disable * fail -. prefer * gss -. require * gss - -ssluser disable disable fail -. . allow ssl -. . prefer ssl -. . require ssl -. prefer disable fail -. . allow ssl -. . prefer ssl -. . require ssl -. require disable fail -. . allow fail -. . prefer fail -. . require fail # If both GSS and SSL are required, the sslmode=require is effectively ignored and GSS is required - -nogssuser disable disable plain -. . allow plain -. . prefer ssl -. . require ssl -. prefer disable plain -. . allow plain -. . prefer ssl -. . require ssl -. require * fail - -nossluser disable disable plain -. . allow plain -. . prefer plain -. . require fail -. prefer * gss -. require * gss +# USER GSSENCMODE SSLMODE EVENTS -> OUTCOME +testuser disable disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslaccept, authok -> ssl +. . require connect, sslaccept, authok -> ssl +. prefer disable connect, gssaccept, authok -> gss +. . allow connect, gssaccept, authok -> gss +. . prefer connect, gssaccept, authok -> gss +. . require connect, gssaccept, authok -> gss # If both GSS and SSL is possible, GSS is chosen over SSL, even if sslmode=require +. require disable connect, gssaccept, authok -> gss +. . allow connect, gssaccept, authok -> gss +. . prefer connect, gssaccept, authok -> gss +. . require connect, gssaccept, authok -> gss # If both GSS and SSL is possible, GSS is chosen over SSL, even if sslmode=require + +gssuser disable disable connect, authfail -> fail +. . allow connect, authfail, reconnect, sslaccept, authfail -> fail +. . prefer connect, sslaccept, authfail, reconnect, authfail -> fail +. . require connect, sslaccept, authfail -> fail +. prefer * connect, gssaccept, authok -> gss +. require disable connect, gssaccept, authok -> gss +. . allow connect, gssaccept, authok -> gss +. . prefer connect, gssaccept, authok -> gss +. . require connect, gssaccept, authok -> gss # If both GSS and SSL is possible, GSS is chosen over SSL, even if sslmode=require + +ssluser disable disable connect, authfail -> fail +. . allow connect, authfail, reconnect, sslaccept, authok -> ssl +. . prefer connect, sslaccept, authok -> ssl +. . require connect, sslaccept, authok -> ssl +. prefer disable connect, gssaccept, authfail, reconnect, authfail -> fail +. . allow connect, gssaccept, authfail, reconnect, authfail, reconnect, sslaccept, authok -> ssl +. . prefer connect, gssaccept, authfail, reconnect, sslaccept, authok -> ssl +. . require connect, gssaccept, authfail, reconnect, sslaccept, authok -> ssl +. require disable connect, gssaccept, authfail -> fail + +# XXX: libpq retries the connection unnecessarily in this case: +. . allow connect, gssaccept, authfail, reconnect, gssaccept, authfail -> fail + +. . prefer connect, gssaccept, authfail -> fail +. . require connect, gssaccept, authfail -> fail # If both GSS and SSL are required, the sslmode=require is effectively ignored and GSS is required + +nogssuser disable disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslaccept, authok -> ssl +. . require connect, sslaccept, authok -> ssl +. prefer disable connect, gssaccept, authfail, reconnect, authok -> plain +. . allow connect, gssaccept, authfail, reconnect, authok -> plain +. . prefer connect, gssaccept, authfail, reconnect, sslaccept, authok -> ssl +. . require connect, gssaccept, authfail, reconnect, sslaccept, authok -> ssl +. require disable connect, gssaccept, authfail -> fail + +# XXX: libpq retries the connection unnecessarily in this case: +. . allow connect, gssaccept, authfail, reconnect, gssaccept, authfail -> fail + +. . prefer connect, gssaccept, authfail -> fail +. . require connect, gssaccept, authfail -> fail + +nossluser disable disable connect, authok -> plain +. . allow connect, authok -> plain +. . prefer connect, sslaccept, authfail, reconnect, authok -> plain +. . require connect, sslaccept, authfail -> fail +. prefer * connect, gssaccept, authok -> gss +. require * connect, gssaccept, authok -> gss }; # Sanity check that GSSAPI is still enabled from previous test. - connect_test($node, 'user=testuser gssencmode=prefer sslmode=prefer', 'gss'); + connect_test($node, 'user=testuser gssencmode=prefer sslmode=prefer', 'connect, gssaccept, authok -> gss'); # Enable SSL $node->adjust_conf('postgresql.conf', 'ssl', 'on'); @@ -378,22 +419,6 @@ nossluser disable disable plain test_matrix($node, $server_config, ['testuser', 'gssuser', 'ssluser', 'nogssuser', 'nossluser'], \@all_sslmodes, \@all_gssencmodes, parse_table($test_table)); - - # Test case that server supports GSSAPI, but it's not allowed for - # this user. Special cased because we check output - connect_test($node, 'user=nogssuser gssencmode=require sslmode=prefer', 'fail', - 'no pg_hba.conf entry for host "127.0.0.1", user "nogssuser", database "postgres", GSS encryption'); - - # with 'gssencmode=prefer', libpq will first negotiate GSSAPI - # encryption, but the connection will fail because pg_hba.conf - # forbids GSSAPI encryption for this user. It will then reconnect - # with SSL. - connect_test($node, 'user=nogssuser gssencmode=prefer sslmode=prefer', 'ssl', - 'no pg_hba.conf entry for host "127.0.0.1", user "nogssuser", database "postgres", GSS encryption'); - - # Setting both gssencmode=require and sslmode=require fails if - # GSSAPI is not available. - connect_test($node, 'user=nogssuser gssencmode=require sslmode=require ', 'fail'); } ### @@ -403,8 +428,8 @@ SKIP: { skip "Unix domain sockets not supported" unless ($unixdir ne ""); - connect_test($node, "user=localuser gssencmode=prefer sslmode=require host=$unixdir", 'plain'); - connect_test($node, "user=localuser gssencmode=require sslmode=prefer host=$unixdir", 'fail'); + connect_test($node, "user=localuser gssencmode=prefer sslmode=require host=$unixdir", 'connect, authok -> plain'); + connect_test($node, "user=localuser gssencmode=require sslmode=prefer host=$unixdir", '- -> fail'); } done_testing(); @@ -434,30 +459,35 @@ sub test_matrix sslmode=>$client_mode, ); my $key = "$test_user $gssencmode $client_mode"; - my $res = $expected{$key}; - if (!defined $res) { - $res = "<expected result missing>"; + my $expected_events = $expected{$key}; + if (!defined($expected_events)) { + $expected_events = "<line missing from expected output table>"; } - connect_test($pg_node, "user=$test_user gssencmode=$gssencmode sslmode=$client_mode", $res); + connect_test($pg_node, "user=$test_user gssencmode=$gssencmode sslmode=$client_mode", $expected_events); } } } } +# Try to establish a connection to the server using libpq. Verify the +# negotiation events and outcome. sub connect_test { local $Test::Builder::Level = $Test::Builder::Level + 1; - my ($node, $connstr, $expected_outcome, @expect_log_msgs) - = @_; + my ($node, $connstr, $expected_events_and_outcome) = @_; - my $test_name = " '$connstr' -> $expected_outcome"; + my $test_name = " '$connstr' -> $expected_events_and_outcome"; my $connstr_full = ""; $connstr_full .= "dbname=postgres " unless $connstr =~ m/dbname=/; $connstr_full .= "host=$host hostaddr=$hostaddr " unless $connstr =~ m/host=/; $connstr_full .= $connstr; + # Get the current size of the logfile before running the test. + # After the test, we can then check just the new lines that have + # appeared. (This is the same approach that the $node->log_contains + # function uses). my $log_location = -s $node->logfile; # XXX: Pass command with -c, because I saw intermittent test @@ -477,18 +507,18 @@ sub connect_test my $outcome = $ret == 0 ? $stdout : 'fail'; - is($outcome, $expected_outcome, $test_name) or diag("$stderr"); + # Parse the EVENTS from the log file. + my $log_contents = + PostgreSQL::Test::Utils::slurp_file($node->logfile, $log_location); + my @events = parse_log_events($log_contents); - if (@expect_log_msgs) - { - # Match every message literally. - my @regexes = map { qr/\Q$_\E/ } @expect_log_msgs; - my %params = (); - $params{log_like} = \@regexes; - $node->log_check($test_name, $log_location, %params); - } + # Check that the events and outcome match the expected events and + # outcome + my $events_and_outcome = join(', ', @events) . " -> $outcome"; + is($events_and_outcome, $expected_events_and_outcome, $test_name) or diag("$stderr"); } +# Parse a test table. See comment at top of the file for the format. sub parse_table { my ($table) = @_; @@ -509,15 +539,19 @@ sub parse_table # Ignore empty lines (includes comment-only lines) next if $line eq ''; - my @cols = split /\s+/, $line; - die "test table line \"$line\" has incorrect number of columns\n" if scalar(@cols) != 4 ; + $line =~ m/^(\S+)\s+(\S+)\s+(\S+)\s+(\S.*)\s*->\s*(\S+)\s*$/ or die "could not parse line \"$line\""; + $user = $1 unless $1 eq "."; + $gssencmode = $2 unless $2 eq "."; + $sslmode = $3 unless $3 eq "."; - $user = $cols[0] unless $cols[0] eq "."; - $gssencmode = $cols[1] unless $cols[1] eq "."; - $sslmode = $cols[2] unless $cols[2] eq "."; - my $outcome = $cols[3]; + # Normalize the whitespace in the "EVENTS -> OUTCOME" part + my @events = split /,\s*/, $4; + my $outcome = $5; + my $events_str = join(', ', @events); + $events_str =~ s/\s+$//; # trim whitespace + my $events_and_outcome = "$events_str -> $outcome"; - my %expanded = expand_expected_line($user, $gssencmode, $sslmode, $outcome); + my %expanded = expand_expected_line($user, $gssencmode, $sslmode, $events_and_outcome); %expected = (%expected, %expanded); } return %expected; @@ -546,3 +580,31 @@ sub expand_expected_line } return %result; } + +# Scrape the server log for the negotiation events that match the +# EVENTS field of the test tables. +sub parse_log_events +{ + my ($log_contents) = (@_); + + my @events = (); + + my @lines = split /\n/, $log_contents; + foreach my $line (@lines) { + push @events, "reconnect" if $line =~ /connection received/ && scalar(@events) > 0; + push @events, "connect" if $line =~ /connection received/ && scalar(@events) == 0; + push @events, "sslaccept" if $line =~ /SSLRequest accepted/; + push @events, "sslreject" if $line =~ /SSLRequest rejected/; + push @events, "gssaccept" if $line =~ /GSSENCRequest accepted/; + push @events, "gssreject" if $line =~ /GSSENCRequest rejected/; + push @events, "authfail" if $line =~ /no pg_hba.conf entry/; + push @events, "authok" if $line =~ /connection authenticated/; + } + + # No events at all is represented by "-" + if (scalar @events == 0) { + push @events, "-" + } + + return @events; +} |