Thanks for the comments Bharath. On Sat, Oct 31, 2020 at 10:18 AM Bharath Rupireddy <bharath.rupireddyforpostg...@gmail.com> wrote: > > I took a look at v3 patch. Here are some comments. > > 1. Why are the input strings(not the newly added GSS log message > string) to test_access() function are in some places double-quoted and > in some places single quoted? > > 'succeeds with mapping with default gssencmode and host hba', > 'connection authorized: user=test1 database=postgres > application_name=001_auth.pl GSS \(authenticated=yes, encrypted=yes, > principal=test1\@EXAMPLE.COM\)' > ); > "succeeds with GSS-encrypted access required with host hba", > 'connection authorized: user=test1 database=postgres > application_name=001_auth.pl GSS \(authenticated=yes, encrypted=yes, > principal=test1\@EXAMPLE.COM\)' > ); > > And also for > > test_access( > $node, > 'test1', <<< single quotes > > test_access( > $node, > "test1", <<< double quotes > > Looks like we use double quoted strings in perl if we have any > variables inside the string to be replaced by the interpreter or else > single quoted strings are fine[1]. If this is true, can we make it > uniform across this file at least?
I have made this uniform across this file. > > 2. Instead of using hardcoded values for application_name and > principal, can we use variables? For application_name we can directly > use a single variable and use it. I think principal name is a formed > value, can we use that formed variable? > > application_name=001_auth.pl GSS \(authenticated=yes, encrypted=yes, > principal=test1\@EXAMPLE.COM\)' > Used variables for this. > 3. Why are we using escape character before ( and @, IIUC, to not let > interpreter replace it with any value. If this is correct, it doesn't > make sense here as we are using single quoted strings. The perl > interpreter replaces the variables only when strings are used in > double quotes[1]. > > + 'connection authorized: user=test1 database=postgres > application_name=001_auth.pl GSS \(authenticated=yes, encrypted=yes, > principal=test1\@EXAMPLE.COM\)' > +); > > I ran the keroberos tests on my dev machine. make check of 001_auth.pl > is passing. > I have changed this within double quotes now as it includes passing of the variable also. Removed the escape sequence which is not required. The v4 patch attached has the fixes for this. Regards, Vignesh EnterpriseDB: http://www.enterprisedb.com
From aafd8eb3844169c46ede5af7a4e2baa0767712b9 Mon Sep 17 00:00:00 2001 From: Vignesh C <vignes...@gmail.com> Date: Fri, 30 Oct 2020 17:58:45 +0530 Subject: [PATCH v4] Improving the connection authorization message for GSS authenticated/encrypted connections. Added log message to include GSS authentication, encryption & principal information. This message will help the user to know if GSS authentication or encryption was used and which GSS principal was used. --- src/backend/utils/init/postinit.c | 80 +++++++++----------------- src/test/kerberos/t/001_auth.pl | 118 +++++++++++++++++++++++++++----------- 2 files changed, 112 insertions(+), 86 deletions(-) diff --git a/src/backend/utils/init/postinit.c b/src/backend/utils/init/postinit.c index d4ab4c7..34d3045 100644 --- a/src/backend/utils/init/postinit.c +++ b/src/backend/utils/init/postinit.c @@ -246,62 +246,38 @@ PerformAuthentication(Port *port) if (Log_connections) { + StringInfoData logmsg; + initStringInfo(&logmsg); if (am_walsender) - { + appendStringInfo(&logmsg, "replication "); + + 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("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 + 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("replication connection authorized: user=%s application_name=%s", - port->user_name, - port->application_name) - : errmsg("replication connection authorized: user=%s", - port->user_name))); - } - else - { -#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 +#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, - (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))); - } + + ereport(LOG, errmsg("%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 b3aeea9..ec0f669 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 => 32; } 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,34 @@ 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 $expect_log_msg = chomp($expect_log_msg); + 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 = 10 * 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/$expect_log_msg /; + usleep(100_000); + } + + like($first_logfile, qr/$expect_log_msg/, + 'found expected log file content'); + } + return; } @@ -223,11 +258,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 +273,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 +324,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 +350,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 +381,5 @@ 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', + ''); -- 1.8.3.1