Greetings, * vignesh C (vignes...@gmail.com) wrote: > Thanks for testing this, I had missed testing this. The expression > matching was not correct. Attached v6 patch which includes the fix for > this.
This generally looks pretty good to me. I did reword the commit message a bit, run pgindent, and added the appropriate log message for the last test (was there a reason you didn't include that..?). In general, this looks pretty good to commit to me. I'll look at it again over the weekend or early next week and unless there's objections, I'll push it. Thanks, Stephen
From f78100d1c7401d4d47e6ee58f1baaac5b21b1216 Mon Sep 17 00:00:00 2001 From: Stephen Frost <sfr...@snowman.net> Date: Fri, 27 Nov 2020 16:52:44 -0500 Subject: [PATCH] Add GSS information to connection authorized log message GSS information (if used) such as if the connection was authorized using GSS or if it was encrypted using GSS, and perhaps most importantly, what the GSS principal used for the authentication was, is extremely useful but wasn't being included in the connection authorized log message. Therefore, add to the connection authorized log message that information, in a similar manner to how we log SSL information when SSL is used for a connection. Author: Vignesh C Reviewed-by: Bharath Rupireddy Discussion: https://www.postgresql.org/message-id/CALDaNm2N1385_Ltoo%3DS7VGT-ESu_bRQa-sC1wg6ikrM2L2Z49w%40mail.gmail.com --- src/backend/utils/init/postinit.c | 82 ++++++++------------- src/test/kerberos/t/001_auth.pl | 118 +++++++++++++++++++++--------- 2 files changed, 114 insertions(+), 86 deletions(-) diff --git a/src/backend/utils/init/postinit.c b/src/backend/utils/init/postinit.c index f2dd8e4914..82d451569d 100644 --- a/src/backend/utils/init/postinit.c +++ b/src/backend/utils/init/postinit.c @@ -245,62 +245,40 @@ PerformAuthentication(Port *port) if (Log_connections) { + StringInfoData logmsg; + + initStringInfo(&logmsg); if (am_walsender) - { -#ifdef USE_SSL - if (port->ssl_in_use) - ereport(LOG, - (port->application_name != NULL - ? errmsg("replication connection authorized: user=%s application_name=%s SSL enabled (protocol=%s, cipher=%s, bits=%d, compression=%s)", - port->user_name, - port->application_name, - be_tls_get_version(port), - be_tls_get_cipher(port), - be_tls_get_cipher_bits(port), - be_tls_get_compression(port) ? _("on") : _("off")) - : errmsg("replication connection authorized: user=%s SSL enabled (protocol=%s, cipher=%s, bits=%d, compression=%s)", - port->user_name, - be_tls_get_version(port), - be_tls_get_cipher(port), - be_tls_get_cipher_bits(port), - be_tls_get_compression(port) ? _("on") : _("off")))); - else -#endif - ereport(LOG, - (port->application_name != NULL - ? errmsg("replication connection authorized: user=%s application_name=%s", - port->user_name, - port->application_name) - : errmsg("replication connection authorized: user=%s", - port->user_name))); - } + appendStringInfo(&logmsg, _("replication connection authorized: user=%s"), + port->user_name); else - { + appendStringInfo(&logmsg, _("connection authorized: user=%s"), + port->user_name); + if (!am_walsender) + appendStringInfo(&logmsg, _(" database=%s"), port->database_name); + + if (port->application_name != NULL) + appendStringInfo(&logmsg, _(" application_name=%s"), + port->application_name); + #ifdef USE_SSL - if (port->ssl_in_use) - ereport(LOG, - (port->application_name != NULL - ? errmsg("connection authorized: user=%s database=%s application_name=%s SSL enabled (protocol=%s, cipher=%s, bits=%d, compression=%s)", - port->user_name, port->database_name, port->application_name, - be_tls_get_version(port), - be_tls_get_cipher(port), - be_tls_get_cipher_bits(port), - be_tls_get_compression(port) ? _("on") : _("off")) - : errmsg("connection authorized: user=%s database=%s SSL enabled (protocol=%s, cipher=%s, bits=%d, compression=%s)", - port->user_name, port->database_name, - be_tls_get_version(port), - be_tls_get_cipher(port), - be_tls_get_cipher_bits(port), - be_tls_get_compression(port) ? _("on") : _("off")))); - else + if (port->ssl_in_use) + appendStringInfo(&logmsg, _(" SSL enabled (protocol=%s, cipher=%s, bits=%d, compression=%s)"), + be_tls_get_version(port), + be_tls_get_cipher(port), + be_tls_get_cipher_bits(port), + be_tls_get_compression(port) ? _("on") : _("off")); #endif - ereport(LOG, - (port->application_name != NULL - ? errmsg("connection authorized: user=%s database=%s application_name=%s", - port->user_name, port->database_name, port->application_name) - : errmsg("connection authorized: user=%s database=%s", - port->user_name, port->database_name))); - } +#ifdef ENABLE_GSS + if (be_gssapi_get_princ(port)) + appendStringInfo(&logmsg, _(" GSS (authenticated=%s, encrypted=%s, principal=%s)"), + be_gssapi_get_auth(port) ? _("yes") : _("no"), + be_gssapi_get_enc(port) ? _("yes") : _("no"), + be_gssapi_get_princ(port)); +#endif + + ereport(LOG, errmsg_internal("%s", logmsg.data)); + pfree(logmsg.data); } set_ps_display("startup"); diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index b3aeea9574..e58e69b497 100644 --- a/src/test/kerberos/t/001_auth.pl +++ b/src/test/kerberos/t/001_auth.pl @@ -16,10 +16,11 @@ use warnings; use TestLib; use PostgresNode; use Test::More; +use Time::HiRes qw(usleep); if ($ENV{with_gssapi} eq 'yes') { - plan tests => 18; + plan tests => 34; } else { @@ -74,6 +75,10 @@ my $kdc_datadir = "${TestLib::tmp_check}/krb5kdc"; my $kdc_pidfile = "${TestLib::tmp_check}/krb5kdc.pid"; my $keytab = "${TestLib::tmp_check}/krb5.keytab"; +my $dbname = 'postgres'; +my $username = 'test1'; +my $application = '001_auth.pl'; + note "setting up Kerberos"; my ($stdout, $krb5_version); @@ -160,6 +165,8 @@ my $node = get_new_node('node'); $node->init; $node->append_conf('postgresql.conf', "listen_addresses = '$hostaddr'"); $node->append_conf('postgresql.conf', "krb_server_keyfile = '$keytab'"); +$node->append_conf('postgresql.conf', "logging_collector = on"); +$node->append_conf('postgresql.conf', "log_connections = on"); $node->start; $node->safe_psql('postgres', 'CREATE USER test1;'); @@ -169,7 +176,7 @@ 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) = @_; + 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( @@ -192,6 +199,33 @@ sub test_access { is($res, $expected_res, $test_name); } + + # Verify specified log message is logged in the log file. + if ($expect_log_msg ne '') + { + my $current_logfiles = slurp_file($node->data_dir . '/current_logfiles'); + note "current_logfiles = $current_logfiles"; + like($current_logfiles, qr|^stderr log/postgresql-.*log$|, + 'current_logfiles is sane'); + + my $lfname = $current_logfiles; + $lfname =~ s/^stderr //; + chomp $lfname; + + # might need to retry if logging collector process is slow... + my $max_attempts = 180 * 10; + my $first_logfile; + for (my $attempts = 0; $attempts < $max_attempts; $attempts++) + { + $first_logfile = slurp_file($node->data_dir . '/' . $lfname); + last if $first_logfile =~ m/\Q$expect_log_msg\E/; + usleep(100_000); + } + + like($first_logfile, qr/\Q$expect_log_msg\E/, + 'found expected log file content'); + } + return; } @@ -223,11 +257,11 @@ $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', ''); $node->append_conf('pg_ident.conf', qq{mymap /^(.*)\@$realm\$ \\1}); $node->restart; @@ -238,42 +272,49 @@ test_access( 'SELECT gss_authenticated AND encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, '', - 'succeeds with mapping with default gssencmode and host hba'); + 'succeeds with mapping with default gssencmode and host hba', + "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" +); + test_access( $node, - "test1", + 'test1', 'SELECT gss_authenticated AND encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, - "gssencmode=prefer", - "succeeds with GSS-encrypted access preferred with host hba"); + 'gssencmode=prefer', + 'succeeds with GSS-encrypted access preferred with host hba', + "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" +); test_access( $node, - "test1", + 'test1', 'SELECT gss_authenticated AND encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, - "gssencmode=require", - "succeeds with GSS-encrypted access required with host hba"); + 'gssencmode=require', + 'succeeds with GSS-encrypted access required with host hba', + "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" +); # Test that we can transport a reasonable amount of data. test_query( $node, - "test1", + 'test1', 'SELECT * FROM generate_series(1, 100000);', qr/^1\n.*\n1024\n.*\n9999\n.*\n100000$/s, - "gssencmode=require", - "receiving 100K lines works"); + 'gssencmode=require', + 'receiving 100K lines works'); test_query( $node, - "test1", + 'test1', "CREATE TABLE mytab (f1 int primary key);\n" . "COPY mytab FROM STDIN;\n" . join("\n", (1 .. 100000)) . "\n\\.\n" . "SELECT COUNT(*) FROM mytab;", qr/^100000$/s, - "gssencmode=require", - "sending 100K lines works"); + 'gssencmode=require', + 'sending 100K lines works'); unlink($node->data_dir . '/pg_hba.conf'); $node->append_conf('pg_hba.conf', @@ -282,20 +323,24 @@ $node->restart; test_access( $node, - "test1", + 'test1', 'SELECT gss_authenticated AND encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, - "gssencmode=prefer", - "succeeds with GSS-encrypted access preferred and hostgssenc hba"); + 'gssencmode=prefer', + 'succeeds with GSS-encrypted access preferred and hostgssenc hba', + "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" +); test_access( $node, - "test1", + 'test1', 'SELECT gss_authenticated AND encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, - "gssencmode=require", - "succeeds with GSS-encrypted access required and hostgssenc hba"); -test_access($node, "test1", 'SELECT true', 2, "gssencmode=disable", - "fails with GSS encryption disabled and hostgssenc hba"); + 'gssencmode=require', + 'succeeds with GSS-encrypted access required and hostgssenc hba', + "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', ''); unlink($node->data_dir . '/pg_hba.conf'); $node->append_conf('pg_hba.conf', @@ -304,21 +349,24 @@ $node->restart; test_access( $node, - "test1", + 'test1', 'SELECT gss_authenticated and not encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, - "gssencmode=prefer", - "succeeds with GSS-encrypted access preferred and hostnogssenc hba, but no encryption" + 'gssencmode=prefer', + 'succeeds with GSS-encrypted access preferred and hostnogssenc hba, but no encryption', + "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"); +test_access($node, 'test1', 'SELECT true', 2, 'gssencmode=require', + 'fails with GSS-encrypted access required and hostnogssenc hba', ''); test_access( $node, - "test1", + 'test1', 'SELECT gss_authenticated and not encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, - "gssencmode=disable", - "succeeds with GSS encryption disabled and hostnogssenc hba"); + 'gssencmode=disable', + 'succeeds with GSS encryption disabled and hostnogssenc hba', + "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=no, principal=test1\@$realm)" +); truncate($node->data_dir . '/pg_ident.conf', 0); unlink($node->data_dir . '/pg_hba.conf'); @@ -332,4 +380,6 @@ test_access( 'SELECT gss_authenticated AND encrypted from pg_stat_gssapi where pid = pg_backend_pid();', 0, '', - 'succeeds with include_realm=0 and defaults'); + 'succeeds with include_realm=0 and defaults', + "connection authorized: user=$username database=$dbname application_name=$application GSS (authenticated=yes, encrypted=yes, principal=test1\@$realm)" +); -- 2.25.1
signature.asc
Description: PGP signature