On Tue, 2021-02-02 at 22:22 +0000, Jacob Champion wrote: > Given the feedback above, I'll continue to flesh out the PoC patch, > focusing on 1) storing the identity in a single place for all auth > methods and 2) exposing it consistently in the logs as part of > log_connections.
Attached is a v1 patchset. Note that I haven't compiled or tested on Windows and BSD yet, so the SSPI and BSD auth changes are eyeballed for now. The first two patches are preparatory, pulled from other threads on the mailing list: 0001 comes from my Kerberos test fix thread [1], and 0002 is extracted from Andrew Dunstan's patch [2] to store the subject DN from a client cert. 0003 has the actual implementation, which now fills in port->authn_id for all auth methods. Now that we're using log_connections instead of log_line_prefix, there's more helpful information we can put into the log when authentication succeeds. For now, I include the identity of the user, the auth method in use, and the pg_hba.conf file and line number. E.g. 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 If the overall direction seems good, then I have two questions: - Since the authenticated identity is more or less an opaque string that may come from a third party, should I be escaping it in some way before it goes into the logs? Or is it generally accepted that log files can contain arbitrary blobs in unspecified encodings? - For the SSPI auth method, I pick the format of the identity string based on the compatibility mode: "DOMAIN\user" when using compat_realm, and "user@DOMAIN" otherwise. For Windows DBAs, is this a helpful way to visualize the identity, or should I just stick to one format? > I also > plan to write a follow-up patch to add the authenticated identity to > the statistics collector, with pg_get_authenticated_identity() to > retrieve it. This part turned out to be more work than I'd thought! Now I understand why pg_stat_ssl truncates several fields to NAMEDATALEN. Has there been any prior discussion on lifting that restriction for the statistics collector as a whole, before I go down my own path? I can't imagine taking up another 64 bytes per connection for a field that won't be useful for the most common use cases -- and yet it still won't be long enough for other users... Thanks, --Jacob [1] https://www.postgresql.org/message-id/fe7a46f8d46ebb074ba1572d4b5e4af72dc95420.camel%40vmware.com [2] https://www.postgresql.org/message-id/fd96ae76-a8e3-ef8e-a642-a592f5b76771%40dunslane.net
From a56ef4e45b4ad0b4be248a6585d07bf73fe79512 Mon Sep 17 00:00:00 2001 From: Jacob Champion <pchamp...@vmware.com> Date: Wed, 3 Feb 2021 11:04:42 -0800 Subject: [PATCH v1 1/3] prep: test/kerberos: only search forward in logs See https://www.postgresql.org/message-id/fe7a46f8d46ebb074ba1572d4b5e4af72dc95420.camel%40vmware.com --- src/test/kerberos/t/001_auth.pl | 24 +++++++++++++++++++++++- 1 file changed, 23 insertions(+), 1 deletion(-) diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index 079321bbfc..c721d24dbd 100644 --- a/src/test/kerberos/t/001_auth.pl +++ b/src/test/kerberos/t/001_auth.pl @@ -182,6 +182,9 @@ $node->safe_psql('postgres', 'CREATE USER test1;'); note "running tests"; +my $current_log_name = ''; +my $current_log_position; + # Test connection success or failure, and if success, that query returns true. sub test_access { @@ -221,18 +224,37 @@ sub test_access $lfname =~ s/^stderr //; chomp $lfname; + if ($lfname ne $current_log_name) + { + $current_log_name = $lfname; + + # Search from the beginning of this new file. + $current_log_position = 0; + note "current_log_position = $current_log_position"; + } + # 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/; + + # Don't include previously matched text in the search. + $first_logfile = substr $first_logfile, $current_log_position; + if ($first_logfile =~ m/\Q$expect_log_msg\E/g) + { + $current_log_position += pos($first_logfile); + last; + } + usleep(100_000); } like($first_logfile, qr/\Q$expect_log_msg\E/, 'found expected log file content'); + + note "current_log_position = $current_log_position"; } return; -- 2.25.1
From c42ee0d1dda878993b476d98a8f2c1f0dda307cc Mon Sep 17 00:00:00 2001 From: Jacob Champion <pchamp...@vmware.com> Date: Mon, 8 Feb 2021 10:53:20 -0800 Subject: [PATCH v1 2/3] prep: add port->peer_dn Original patch by Andrew Dunstan: https://www.postgresql.org/message-id/fd96ae76-a8e3-ef8e-a642-a592f5b76771%40dunslane.net --- src/backend/libpq/be-secure-openssl.c | 53 +++++++++++++++++++++++---- src/include/libpq/libpq-be.h | 1 + 2 files changed, 47 insertions(+), 7 deletions(-) diff --git a/src/backend/libpq/be-secure-openssl.c b/src/backend/libpq/be-secure-openssl.c index 1e2ecc6e7a..83c0eb5006 100644 --- a/src/backend/libpq/be-secure-openssl.c +++ b/src/backend/libpq/be-secure-openssl.c @@ -523,22 +523,25 @@ aloop: /* Get client certificate, if available. */ port->peer = SSL_get_peer_certificate(port->ssl); - /* and extract the Common Name from it. */ + /* and extract the Common Name / Distinguished Name from it. */ port->peer_cn = NULL; + port->peer_dn = NULL; port->peer_cert_valid = false; if (port->peer != NULL) { int len; + X509_NAME *x509name = X509_get_subject_name(port->peer); + char *peer_cn; + char *peer_dn; + BIO *bio = NULL; + BUF_MEM *bio_buf = NULL; - len = X509_NAME_get_text_by_NID(X509_get_subject_name(port->peer), - NID_commonName, NULL, 0); + len = X509_NAME_get_text_by_NID(x509name, NID_commonName, NULL, 0); if (len != -1) { - char *peer_cn; - peer_cn = MemoryContextAlloc(TopMemoryContext, len + 1); - r = X509_NAME_get_text_by_NID(X509_get_subject_name(port->peer), - NID_commonName, peer_cn, len + 1); + r = X509_NAME_get_text_by_NID(x509name, NID_commonName, peer_cn, + len + 1); peer_cn[len] = '\0'; if (r != len) { @@ -562,6 +565,36 @@ aloop: port->peer_cn = peer_cn; } + + bio = BIO_new(BIO_s_mem()); + if (!bio) + { + pfree(port->peer_cn); + port->peer_cn = NULL; + return -1; + } + /* use commas instead of slashes */ + X509_NAME_print_ex(bio, x509name, 0, XN_FLAG_RFC2253); + BIO_get_mem_ptr(bio, &bio_buf); + peer_dn = MemoryContextAlloc(TopMemoryContext, bio_buf->length + 1); + memcpy(peer_dn, bio_buf->data, bio_buf->length); + peer_dn[bio_buf->length] = '\0'; + if (bio_buf->length != strlen(peer_dn)) + { + ereport(COMMERROR, + (errcode(ERRCODE_PROTOCOL_VIOLATION), + errmsg("SSL certificate's distinguished name contains embedded null"))); + BIO_free(bio); + pfree(peer_dn); + pfree(port->peer_cn); + port->peer_cn = NULL; + return -1; + } + + BIO_free(bio); + + port->peer_dn = peer_dn; + port->peer_cert_valid = true; } @@ -590,6 +623,12 @@ be_tls_close(Port *port) pfree(port->peer_cn); port->peer_cn = NULL; } + + if (port->peer_dn) + { + pfree(port->peer_dn); + port->peer_dn = NULL; + } } ssize_t diff --git a/src/include/libpq/libpq-be.h b/src/include/libpq/libpq-be.h index 66a8673d93..c0988d2404 100644 --- a/src/include/libpq/libpq-be.h +++ b/src/include/libpq/libpq-be.h @@ -190,6 +190,7 @@ typedef struct Port */ bool ssl_in_use; char *peer_cn; + char *peer_dn; bool peer_cert_valid; /* -- 2.25.1
From 5548a1e074805cedafe15098233f15e5a2913ae8 Mon Sep 17 00:00:00 2001 From: Jacob Champion <pchamp...@vmware.com> Date: Wed, 3 Feb 2021 11:42:05 -0800 Subject: [PATCH v1 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: TODO The trust auth method does not set an authenticated identity. Neither does using clientcert=verify-full (use the cert auth method instead). The Kerberos test suite has been modified to let tests match multiple log lines in order. TODOs: - Test SSPI on Windows and decide on the identity format - Test BSD auth - Escape the identity string in the logs? --- doc/src/sgml/config.sgml | 2 +- src/backend/libpq/auth.c | 118 +++++++++++++++++++++- src/backend/libpq/hba.c | 24 +++++ src/include/libpq/hba.h | 1 + src/include/libpq/libpq-be.h | 12 +++ src/test/authentication/t/001_password.pl | 60 ++++++++++- src/test/kerberos/t/001_auth.pl | 73 ++++++++----- src/test/ldap/t/001_auth.pl | 28 ++++- src/test/ssl/t/001_ssltests.pl | 55 +++++++++- src/test/ssl/t/002_scram.pl | 53 +++++++++- 10 files changed, 392 insertions(+), 34 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 5ef1c7ad3c..e59c105537 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6626,7 +6626,7 @@ 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 client authentication 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 545635f41a..c86919f136 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,49 @@ 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 exactly once, as soon as the user is + * successfully authenticated, even if they have reason to know that + * authorization will fail later. + */ +static void +set_authn_id(Port *port, const char *id) +{ + Assert(id); + + /* TODO: should the identity strings be escaped before being logged? */ + + 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. @@ -766,6 +812,9 @@ CheckPasswordAuth(Port *port, char **logdetail) pfree(shadow_pass); pfree(passwd); + if (result == STATUS_OK) + set_authn_id(port, port->user_name); + return result; } @@ -825,6 +874,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; } @@ -1208,9 +1261,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); + set_authn_id(port, gbuf.value); /* * Split the username at the realm separator @@ -1320,6 +1374,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; @@ -1562,6 +1617,27 @@ pg_SSPI_recvauth(Port *port) return status; } + /* + * We have all of the information necessary to construct the authenticated + * identity. + * + * TODO: will DBAs find the DOMAIN\user construct useful in compat_realm + * mode, or should we use user@DOMAIN for all cases? + */ + 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. @@ -1949,8 +2025,11 @@ ident_inet_done: pg_freeaddrinfo_all(local_addr.addr.ss_family, la); if (ident_return) - /* Success! Check the usermap */ + { + /* Success! Store the identity and check the usermap */ + set_authn_id(port, ident_user); return check_usermap(port->hba->usermap, port->user_name, ident_user, false); + } return STATUS_ERROR; } @@ -2006,8 +2085,12 @@ auth_peer(hbaPort *port) return STATUS_ERROR; } - /* Make a copy of static getpw*() result area. */ + /* + * Make a copy of static getpw*() result area. This is our authenticated + * identity. + */ peer_user = pstrdup(pw->pw_name); + set_authn_id(port, peer_user); ret = check_usermap(port->hba->usermap, port->user_name, peer_user, false); @@ -2268,6 +2351,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 */ @@ -2303,6 +2389,7 @@ CheckBSDAuth(Port *port, char *user) if (!retval) return STATUS_ERROR; + set_authn_id(port, user); return STATUS_OK; } #endif /* USE_BSD_AUTH */ @@ -2809,6 +2896,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); @@ -2861,6 +2951,26 @@ CheckCertAuth(Port *port) return STATUS_ERROR; } + if (port->hba->auth_method == uaCert) + { + /* + * The client's Subject DN is our authenticated identity. + */ + if (!port->peer_dn) + { + /* + * Unlikely to happen (after all, we were able to get the subject + * CN). This probably indicates problems with the TLS backend. + */ + 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 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) @@ -3023,6 +3133,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 20bf1461ce..e2c79dd769 100644 --- a/src/backend/libpq/hba.c +++ b/src/backend/libpq/hba.c @@ -3110,3 +3110,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) + { + Assert((0 <= auth_method) && (auth_method <= USER_AUTH_LAST)); + return NULL; + } + + return UserAuthName[auth_method]; +} diff --git a/src/include/libpq/hba.h b/src/include/libpq/hba.h index 8f09b5638f..7cc06808aa 100644 --- a/src/include/libpq/hba.h +++ b/src/include/libpq/hba.h @@ -130,6 +130,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 c0988d2404..c2aae8b080 100644 --- a/src/include/libpq/libpq-be.h +++ b/src/include/libpq/libpq-be.h @@ -154,6 +154,18 @@ 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 + * 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 36a616d7c7..3ac137aebd 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 => 19; } @@ -57,6 +57,7 @@ sub test_role # 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 @@ -69,27 +70,84 @@ $node->safe_psql('postgres', ); $ENV{"PGPASSWORD"} = 'pass'; +my $log = $node->rotate_logfile(); +$node->restart; + # For "trust" method, all users should be able to connect. reset_pg_hba($node, 'trust'); test_role($node, 'scram_role', 'trust', 0); test_role($node, 'md5_role', 'trust', 0); +$node->stop('fast'); +my $log_contents = slurp_file($log); + +unlike( + $log_contents, + qr/connection authenticated:/, + "trust method does not authenticate users"); + +$log = $node->rotate_logfile(); +$node->start; + # 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); +$node->stop('fast'); +$log_contents = slurp_file($log); + +like( + $log_contents, + qr/connection authenticated: identity="scram_role" method=password/, + "password method logs authenticated identity"); + +$log = $node->rotate_logfile(); +$node->start; + # 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); +$node->stop('fast'); +$log_contents = slurp_file($log); + +like( + $log_contents, + qr/connection authenticated: identity="scram_role" method=scram-sha-256/, + "scram-sha-256 method logs authenticated identity"); + +unlike( + $log_contents, + qr/connection authenticated: identity="md5_role"/, + "mismatched crypt methods do not result in authentication"); + +$log = $node->rotate_logfile(); +$node->start; + # 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); +$node->stop('fast'); +$log_contents = slurp_file($log); + +like( + $log_contents, + qr/connection authenticated: identity="md5_role" method=md5/, + "md5 method logs authenticated identity"); + +like( + $log_contents, + qr/connection authenticated: identity="scram_role" method=md5/, + "md5 method logs authenticated identity for SCRAM users too"); + +$log = $node->rotate_logfile(); +$node->start; + # Tests for channel binding without SSL. # Using the password authentication method; channel binding can't work reset_pg_hba($node, 'password'); diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index c721d24dbd..c2e6f33701 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 => 48; } else { @@ -188,7 +188,7 @@ my $current_log_position; # 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 ($res, $stdoutres, $stderrres) = $node->psql( @@ -212,8 +212,8 @@ sub test_access is($res, $expected_res, $test_name); } - # Verify specified log message is logged in the log file. - if ($expect_log_msg ne '') + # Verify specified log messages are logged in the log file. + if (@expect_log_msgs > 0) { my $current_logfiles = slurp_file($node->data_dir . '/current_logfiles'); note "current_logfiles = $current_logfiles"; @@ -233,28 +233,31 @@ sub test_access note "current_log_position = $current_log_position"; } - # 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++) + while (my $expect_log_msg = shift @expect_log_msgs) { - $first_logfile = slurp_file($node->data_dir . '/' . $lfname); - - # Don't include previously matched text in the search. - $first_logfile = substr $first_logfile, $current_log_position; - if ($first_logfile =~ m/\Q$expect_log_msg\E/g) + # 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++) { - $current_log_position += pos($first_logfile); - last; - } + $first_logfile = slurp_file($node->data_dir . '/' . $lfname); - usleep(100_000); - } + # Don't include previously matched text in the search. + $first_logfile = substr $first_logfile, $current_log_position; + if ($first_logfile =~ m/\Q$expect_log_msg\E/g) + { + $current_log_position += pos($first_logfile); + last; + } - like($first_logfile, qr/\Q$expect_log_msg\E/, - 'found expected log file content'); + usleep(100_000); + } - note "current_log_position = $current_log_position"; + like($first_logfile, qr/\Q$expect_log_msg\E/, + 'found expected log file content'); + + note "current_log_position = $current_log_position"; + } } return; @@ -288,11 +291,13 @@ $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; @@ -304,6 +309,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)" ); @@ -314,6 +320,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( @@ -323,6 +330,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)" ); @@ -359,6 +367,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( @@ -368,10 +377,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', @@ -385,10 +395,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', @@ -396,6 +407,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)" ); @@ -412,5 +424,16 @@ 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)" ); + +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 3bc7672451..94f8850ca8 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_connections = on\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"} @@ -184,9 +188,31 @@ test_access($node, 'test0', 2, 'simple bind authentication fails if user not found in LDAP'); test_access($node, 'test1', 2, 'simple bind authentication fails with wrong password'); + +$node->stop('fast'); +my $log_contents = slurp_file($log); + +unlike( + $log_contents, + qr/connection authenticated:/, + "unauthenticated DNs are not logged"); + +$log = $node->rotate_logfile(); +$node->start; + $ENV{"PGPASSWORD"} = 'secret1'; test_access($node, 'test1', 0, 'simple bind authentication succeeds'); +$node->stop('fast'); +$log_contents = slurp_file($log); + +like( + $log_contents, + qr/connection authenticated: identity="uid=test1,dc=example,dc=net" method=ldap/, + "authenticated DNs are 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 7928de4e7c..8e1108d0d8 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 => 93; + plan tests => 97; } #### Some configuration @@ -399,6 +399,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 +409,17 @@ 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); + +like( + $log_contents, + qr/connection authenticated: identity="CN=ssltestuser" method=cert/, + "authenticated DNs are logged"); + +$node->start; + # correct client cert in unencrypted DER test_connect_ok( $common_connstr, @@ -491,6 +505,9 @@ SKIP: "certificate authorization fails because of file permissions"); } +$log = $node->rotate_logfile(); +$node->restart; + # client cert belonging to another user test_connect_fails( $common_connstr, @@ -499,6 +516,17 @@ test_connect_fails( "certificate authorization fails with client cert belonging to another user" ); +$node->stop('fast'); +$log_contents = slurp_file($log); + +like( + $log_contents, + qr/connection authenticated: identity="CN=ssltestuser" method=cert/, + "cert authentication succeeds even if authorization fails"); + +$log = $node->rotate_logfile(); +$node->restart; + # revoked client cert test_connect_fails( $common_connstr, @@ -506,12 +534,25 @@ test_connect_fails( qr/SSL error/, "certificate authorization fails with revoked client cert"); +$node->stop('fast'); +$log_contents = slurp_file($log); + +unlike( + $log_contents, + qr/connection authenticated:/, + "revoked certs do not authenticate users"); + +$node->start; + # 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 +574,18 @@ test_connect_ok( "auth_option clientcert=verify-ca succeeds with mismatching username and Common Name" ); +$node->stop('fast'); +$log_contents = slurp_file($log); + +# None of the above connections to verifydb should have resulted in +# authentication. +unlike( + $log_contents, + qr/connection authenticated:/, + "trust auth method does not set authenticated identity"); + +$node->start; + # 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 410b9e910d..d222e086ec 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; @@ -48,14 +48,44 @@ $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); + +unlike( + $log_contents, + qr/connection authenticated:/, + "SCRAM does not set authenticated identity with bad password"); + +$log = $node->rotate_logfile(); +$node->start; + # 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); + +like( + $log_contents, + qr/connection authenticated: identity="ssltestuser" method=scram-sha-256/, + "Basic SCRAM sets the username as the authenticated identity"); + +$node->start; + # Test channel_binding test_connect_fails( $common_connstr, @@ -102,6 +132,25 @@ 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); + +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->start; + # clean up unlink($client_tmp_key); -- 2.25.1