From 3f6e87a744be339748fc707cd071896e81e0323c Mon Sep 17 00:00:00 2001 From: Jacob Champion Date: Fri, 22 Jan 2021 14:03:14 -0800 Subject: [PATCH] WIP: log authenticated identity from multiple auth backends This is stored into port->authn_id according to the auth method: ldap: the final bind DN gss: the user principal cert: the client's Subject DN scram-sha-256: the Postgres username It can be logged with the %Z specifier in log_line_prefix. --- src/backend/libpq/auth.c | 21 ++++++++++- src/backend/libpq/be-secure-openssl.c | 22 +++++++++++ src/backend/utils/error/elog.c | 18 +++++++++ src/include/libpq/libpq-be.h | 12 ++++++ src/test/kerberos/t/001_auth.pl | 15 +++++++- src/test/ldap/t/001_auth.pl | 22 ++++++++++- src/test/ssl/t/001_ssltests.pl | 43 ++++++++++++++++++++- src/test/ssl/t/002_scram.pl | 54 ++++++++++++++++++++++++++- 8 files changed, 200 insertions(+), 7 deletions(-) diff --git a/src/backend/libpq/auth.c b/src/backend/libpq/auth.c index 545635f41a..2bff140d3c 100644 --- a/src/backend/libpq/auth.c +++ b/src/backend/libpq/auth.c @@ -1021,6 +1021,10 @@ CheckSCRAMAuth(Port *port, char *shadow_pass, char **logdetail) return STATUS_ERROR; } + /* TODO: move this up the stack so that it's shared by other password + * authentication methods, once tests are written. */ + port->authn_id = port->user_name; + return STATUS_OK; } @@ -1208,9 +1212,10 @@ pg_GSS_checkauth(Port *port) /* * Copy the original name of the authenticated principal into our backend - * memory for display later. + * memory for display later. This is also our authenticated identity. */ - port->gss->princ = MemoryContextStrdup(TopMemoryContext, gbuf.value); + port->authn_id = port->gss->princ = MemoryContextStrdup(TopMemoryContext, gbuf.value); + /* * Split the username at the realm separator @@ -2809,6 +2814,9 @@ CheckLDAPAuth(Port *port) return STATUS_ERROR; } + /* Save the original bind DN as the authenticated identity. */ + port->authn_id = MemoryContextStrdup(TopMemoryContext, fulluser); + ldap_unbind(ldap); pfree(passwd); pfree(fulluser); @@ -2861,6 +2869,15 @@ CheckCertAuth(Port *port) return STATUS_ERROR; } + if (port->hba->auth_method == uaCert) + { + /* + * The client's Subject DN is our authenticated identity. Unfortunately + * there is no canonical string representation; do the best we can. + */ + port->authn_id = be_tls_get_peer_full_subject_name(port); + } + /* Just pass the certificate cn to the usermap check */ status_check_usermap = check_usermap(port->hba->usermap, port->user_name, port->peer_cn, false); if (status_check_usermap != STATUS_OK) diff --git a/src/backend/libpq/be-secure-openssl.c b/src/backend/libpq/be-secure-openssl.c index 1e2ecc6e7a..1c7f74dc22 100644 --- a/src/backend/libpq/be-secure-openssl.c +++ b/src/backend/libpq/be-secure-openssl.c @@ -562,12 +562,34 @@ aloop: port->peer_cn = peer_cn; } + port->peer_cert_valid = true; } return 0; } +const char * +be_tls_get_peer_full_subject_name(Port *port) +{ + if (!port->peer) + return NULL; + + /* + * TODO: decide on the format for the name, and perform sanity checks to + * prohibit nasty edge cases (e.g. embedded NULLs) if the format doesn't + * perform escaping itself. + * + * See also + * https://www.postgresql.org/message-id/daf119af-60a3-54d9-978e-8c97a602ca28%40dunslane.net + * + * TODO: allocate this string in an explicit context + * TODO: reconcile this with be_tls_get_peer_subject_name, which silently + * truncates if your buffer isn't big enough + */ + return X509_NAME_oneline(X509_get_subject_name(port->peer), NULL, 0); +} + void be_tls_close(Port *port) { diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index 80c2672461..f74f7571ac 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -2717,6 +2717,24 @@ log_line_prefix(StringInfo buf, ErrorData *edata) else appendStringInfoString(buf, unpack_sql_state(edata->sqlerrcode)); break; + case 'Z': + if (MyProcPort) + { + const char *authn_id = MyProcPort->authn_id; + + /* TODO: should we consider the empty ID as unknown too? */ + if (authn_id == NULL) + authn_id = _("[unknown]"); + if (padding != 0) + appendStringInfo(buf, "%*s", padding, authn_id); + else + appendStringInfoString(buf, authn_id); + + } + else if (padding != 0) + appendStringInfoSpaces(buf, + padding > 0 ? padding : -padding); + break; default: /* format error - ignore it */ break; diff --git a/src/include/libpq/libpq-be.h b/src/include/libpq/libpq-be.h index 66a8673d93..69ea0d5dfb 100644 --- a/src/include/libpq/libpq-be.h +++ b/src/include/libpq/libpq-be.h @@ -154,6 +154,17 @@ typedef struct Port */ HbaLine *hba; + /* + * Authenticated identity. The meaning of this identifier is dependent on + * hba->auth_method; it's the identity (if any) that the user presented + * during the authentication cycle, before they were assigned a role. (It's + * the "left side" of a pg_ident usermap.) + * + * 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. * @@ -270,6 +281,7 @@ extern bool be_tls_get_compression(Port *port); extern const char *be_tls_get_version(Port *port); extern const char *be_tls_get_cipher(Port *port); extern void be_tls_get_peer_subject_name(Port *port, char *ptr, size_t len); +extern const char *be_tls_get_peer_full_subject_name(Port *port); extern void be_tls_get_peer_issuer_name(Port *port, char *ptr, size_t len); extern void be_tls_get_peer_serial(Port *port, char *ptr, size_t len); diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index 079321bbfc..8685d19487 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 => 43; } else { @@ -170,6 +170,7 @@ $node->append_conf( 'postgresql.conf', qq{ listen_addresses = '$hostaddr' krb_server_keyfile = '$keytab' +log_line_prefix = '%m [%p] %q%a (%u:%Z) ' logging_collector = on log_connections = on # these ensure stability of test results: @@ -268,10 +269,18 @@ $node->restart; test_access($node, 'test1', 'SELECT true', 2, '', 'fails without ticket', ''); +test_access($node, 'test1', 'SELECT true', 2, '', + 'does not log unauthenticated principal', + "(test1:[unknown]) FATAL: GSSAPI authentication failed"); + 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, '', + 'logs authenticated principal even without authorized mapping', + "(test1:test1\@$realm) LOG: no match in usermap"); + $node->append_conf('pg_ident.conf', qq{mymap /^(.*)\@$realm\$ \\1}); $node->restart; @@ -304,6 +313,10 @@ 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', 0, 'gssencmode=require', + 'logs authenticated principal for authorized connection', + "(test1:test1\@$realm) LOG: connection authorized:"); + # Test that we can transport a reasonable amount of data. test_query( $node, diff --git a/src/test/ldap/t/001_auth.pl b/src/test/ldap/t/001_auth.pl index 3bc7672451..34a1e9a10d 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 => 24; } else { @@ -152,6 +152,7 @@ note "setting up PostgreSQL instance"; my $node = get_new_node('node'); $node->init; +$node->append_conf('postgresql.conf', "log_line_prefix = '%m [%p] %q%a (%u:%Z) '\n"); $node->start; $node->safe_psql('postgres', 'CREATE USER test0;'); @@ -173,6 +174,9 @@ sub test_access note "simple bind"; +# save log location for later tests +my $log = $node->rotate_logfile(); + unlink($node->data_dir . '/pg_hba.conf'); $node->append_conf('pg_hba.conf', qq{local all all ldap ldapserver=$ldap_server ldapport=$ldap_port ldapprefix="uid=" ldapsuffix=",dc=example,dc=net"} @@ -187,6 +191,22 @@ test_access($node, 'test1', 2, $ENV{"PGPASSWORD"} = 'secret1'; test_access($node, 'test1', 0, 'simple bind authentication succeeds'); +# make sure LDAP DNs are logged correctly +$node->stop('fast'); +my $log_contents = slurp_file($log); + +like( + $log_contents, + qr/\(test1:uid=test1,dc=example,dc=net\).*SELECT 1/, + "authenticated DNs are logged"); + +unlike( + $log_contents, + qr/\(test.:uid=test.,dc=example,dc=net\).*FATAL:.*LDAP authentication failed/, + "unauthenticated DNs are not logged"); + +$node->start; + note "search+bind"; unlink($node->data_dir . '/pg_hba.conf'); diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl index fd2727b568..58f371a306 100644 --- a/src/test/ssl/t/001_ssltests.pl +++ b/src/test/ssl/t/001_ssltests.pl @@ -13,7 +13,7 @@ use SSLServer; if ($ENV{with_openssl} eq 'yes') { - plan tests => 93; + plan tests => 96; } else { @@ -74,6 +74,10 @@ $node->start; my $result = $node->safe_psql('postgres', "SHOW ssl_library"); is($result, 'OpenSSL', 'ssl_library parameter'); +$node->append_conf( + 'postgresql.conf', + "log_line_prefix = '%m [%p] %q%a (%u:%Z) '\n"); + configure_test_server_for_ssl($node, $SERVERHOSTADDR, $SERVERHOSTCIDR, 'trust'); @@ -399,6 +403,9 @@ test_connect_fails( qr/connection requires a valid client certificate/, "certificate authorization fails without client cert"); +my $log = $node->rotate_logfile(); +$node->restart; + # correct client cert in unencrypted PEM test_connect_ok( $common_connstr, @@ -406,6 +413,16 @@ test_connect_ok( "certificate authorization succeeds with correct client cert in PEM format" ); +# make sure certificate DNs are logged correctly +$node->stop('fast'); +my $log_contents = slurp_file($log); +$node->start; + +like( + $log_contents, + qr/\(ssltestuser:\/CN=ssltestuser\).*SELECT \$\$connected/, + "authenticated DNs are logged"); + # correct client cert in unencrypted DER test_connect_ok( $common_connstr, @@ -499,6 +516,9 @@ test_connect_fails( "certificate authorization fails with client cert belonging to another user" ); +$log = $node->rotate_logfile(); +$node->restart; + # revoked client cert test_connect_fails( $common_connstr, @@ -506,12 +526,24 @@ test_connect_fails( qr/SSL error/, "certificate authorization fails with revoked client cert"); +$node->stop('fast'); +$log_contents = slurp_file($log); +$node->start; + +like( + $log_contents, + qr/\(\[unknown\]:\[unknown\]\).*could not accept SSL connection: certificate verify failed/, + "unauthenticated DNs are not logged"); + # Check that connecting with auth-option verify-full in pg_hba: # works, iff username matches Common Name # fails, iff username doesn't match Common Name. $common_connstr = "sslrootcert=ssl/root+server_ca.crt sslmode=require dbname=verifydb hostaddr=$SERVERHOSTADDR"; +$log = $node->rotate_logfile(); +$node->restart; + test_connect_ok( $common_connstr, "user=ssltestuser sslcert=ssl/client.crt sslkey=ssl/client_tmp.key", @@ -533,6 +565,15 @@ test_connect_ok( "auth_option clientcert=verify-ca succeeds with mismatching username and Common Name" ); +$node->stop('fast'); +$log_contents = slurp_file($log); +$node->start; + +unlike( + $log_contents, + qr/\(.*:\/CN=ssltestuser\)/, + "trust auth method does not set authenticated identity"); + # 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 a088f71a1a..d8dd670c7a 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 ? 15 : 16; # Allocation of base connection string shared among multiple tests. my $common_connstr; @@ -38,6 +38,10 @@ note "setting up data directory"; my $node = get_new_node('primary'); $node->init; +$node->append_conf( + 'postgresql.conf', + "log_line_prefix = '%m [%p] %q%a (%u:%Z) '\n"); + # PGHOST is enforced here to set up the node, subsequent connections # will use a dedicated connection string. $ENV{PGHOST} = $node->host; @@ -48,14 +52,42 @@ $node->start; configure_test_server_for_ssl($node, $SERVERHOSTADDR, $SERVERHOSTCIDR, "scram-sha-256", "pass", "scram-sha-256"); switch_server_cert($node, 'server-cn-only'); -$ENV{PGPASSWORD} = "pass"; $common_connstr = "dbname=trustdb sslmode=require sslcert=invalid sslrootcert=invalid hostaddr=$SERVERHOSTADDR"; +my $log = $node->rotate_logfile(); +$node->restart; + +# Bad password +$ENV{PGPASSWORD} = "badpass"; +test_connect_fails($common_connstr, "user=ssltestuser", + qr/password authentication failed/, + "Basic SCRAM authentication with bad password"); + +$node->stop('fast'); +my $log_contents = slurp_file($log); +$log = $node->rotate_logfile(); +$node->start; + +unlike( + $log_contents, + qr/\(ssltestuser:ssltestuser\)/, + "SCRAM does not set authenticated identity with bad password"); + # Default settings +$ENV{PGPASSWORD} = "pass"; test_connect_ok($common_connstr, "user=ssltestuser", "Basic SCRAM authentication with SSL"); +$node->stop('fast'); +$log_contents = slurp_file($log); +$node->start; + +like( + $log_contents, + qr/\(ssltestuser:ssltestuser\)/, + "Basic SCRAM sets the username as the authenticated identity"); + # Test channel_binding test_connect_fails( $common_connstr, @@ -102,6 +134,24 @@ test_connect_fails( qr/channel binding required, but server authenticated client without channel binding/, "Cert authentication and channel_binding=require"); +$log = $node->rotate_logfile(); +$node->restart; + +# Certificate verification at the connection level should still work fine. +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"); + +$node->stop('fast'); +$log_contents = slurp_file($log); +$node->start; + +like( + $log_contents, + qr/\(ssltestuser:ssltestuser\)/, + "SCRAM with clientcert=verify-full sets the username as the authenticated identity"); + # clean up unlink($client_tmp_key); -- 2.25.1