Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lRVVF-0007OT-1i for pgsql-hackers@arkaria.postgresql.org; Wed, 31 Mar 2021 07:43:03 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1lRVVD-0005i0-JH for pgsql-hackers@arkaria.postgresql.org; Wed, 31 Mar 2021 07:42:59 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lRVVB-0005ht-Rh for pgsql-hackers@lists.postgresql.org; Wed, 31 Mar 2021 07:42:59 +0000 Received: from [66.111.4.27] (helo=out3-smtp.messagingengine.com) by makus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lRVV7-0004XQ-UT for pgsql-hackers@postgresql.org; Wed, 31 Mar 2021 07:42:56 +0000 Received: from compute1.internal (compute1.nyi.internal [10.202.2.41]) by mailout.nyi.internal (Postfix) with ESMTP id A7CC15C0183; Wed, 31 Mar 2021 03:42:42 -0400 (EDT) Received: from mailfrontend1 ([10.202.2.162]) by compute1.internal (MEProxy); Wed, 31 Mar 2021 03:42:42 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=paquier.xyz; h= date:from:to:cc:subject:message-id:references:mime-version :content-type:in-reply-to; s=fm1; bh=6v86SDIRweDLZ1ndjf2BQ7fKpQ9 djXKe4520opqLdOY=; b=x3XgY+2G9HeUbEinfmo2uryylTPM25zrsWKiNBoVK71 tPKPHJ6Y6/C7U+kj425tQaY+Ehf871Kx2aDazBiHm4UNPk8hxW2oqf1+1Ns0nsfA fUsHJDbOIPSxVXPJlK381CwRQELcdzpxuJJ4QPL5DPdkdJxxXEk2XfCWcpuOqdVj q/H9Cx3KouUH0k0GUJaWdvDe1VF+ACCDs7OBXyFeGIARD78Bno4McsaDljH5wUiB JTwOm3s4L2zyL6r9CVBSVovWg1sgEDpauAppfxITS0uWrWlt6/r4DWYRVUZ2agJg 6KafbfVoItb1rP4CsaBEO2NMczPknoQpBJ2oDcqivuQ== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d= messagingengine.com; h=cc:content-type:date:from:in-reply-to :message-id:mime-version:references:subject:to:x-me-proxy :x-me-proxy:x-me-sender:x-me-sender:x-sasl-enc; s=fm2; bh=6v86SD IRweDLZ1ndjf2BQ7fKpQ9djXKe4520opqLdOY=; b=f6CfL2dtT7Hx80NjmppeNB XXyOCuO4gr/IprxgnjzEVOFVivzWj3RT5xdtOHzt4UITU7Kp9GalRrtxOF7J9wsl yZPIWgkpR1eolxCIlN7h2oaC6tNwYAYC97qvsLf/zgAxqH9XvBWw1sIxXFCufrJz 4VaactIQl/zgOxcow90FTmtdSDpE9Gp52X3N6aB8jLof+AvcSPSJ2zLyMm5iuxSn vzxgZxxtZ/etdNvftLRTwK9JZr4EMqJPg69VZ0w7lo3qrEDAlokj6HS4Rol/oar+ X4kih8lPgwQ0d9KW2OE5gWtDjIhz9mbup8Ja69qo7GV0NBQRbcc/VRrzxqGAt4ig == X-ME-Sender: X-ME-Proxy-Cause: gggruggvucftvghtrhhoucdtuddrgeduledrudeiuddguddvudcutefuodetggdotefrod ftvfcurfhrohhfihhlvgemucfhrghsthforghilhdpqfgfvfdpuffrtefokffrpgfnqfgh necuuegrihhlohhuthemuceftddtnecusecvtfgvtghiphhivghnthhsucdlqddutddtmd enfghrlhcuvffnffculdejtddmnecujfgurhepfffhvffukfhfgggtuggjsehgtderredt tddvnecuhfhrohhmpefoihgthhgrvghlucfrrghquhhivghruceomhhitghhrggvlhesph grqhhuihgvrhdrgiihiieqnecuggftrfgrthhtvghrnhepvdegudeuhfdtueeltedtveej heehieevueeigeelteegleejleeiueeiheegvefhnecukfhppeduuddurddutddvrdduke dtrddukeehnecuvehluhhsthgvrhfuihiivgeptdenucfrrghrrghmpehmrghilhhfrhho mhepmhhitghhrggvlhesphgrqhhuihgvrhdrgiihii X-ME-Proxy: Received: from paquier.xyz (ee0822lan1.rev.em-net.ne.jp [111.102.180.185]) by mail.messagingengine.com (Postfix) with ESMTPA id 7C50C24005C; Wed, 31 Mar 2021 03:42:37 -0400 (EDT) Date: Wed, 31 Mar 2021 16:42:32 +0900 From: Michael Paquier To: Jacob Champion Cc: "magnus@hagander.net" , "stark@mit.edu" , "pgsql-hackers@postgresql.org" , "sfrost@snowman.net" , "tgl@sss.pgh.pa.us" Subject: Re: Proposal: Save user's original authenticated identity for logging Message-ID: References: <4c90814d2f0018ba835c3d8e2eb67b99e6a45578.camel@vmware.com> <9f222bb07e711f6f1ffcfcb4fe162d9e84054a1f.camel@vmware.com> <4a87886f034c713c056c43850f55e6e0ba50d8b5.camel@vmware.com> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha512; protocol="application/pgp-signature"; boundary="b8Sq8VBMU+z1HUC/" Content-Disposition: inline In-Reply-To: X-Host-Lookup-Failed: Reverse DNS lookup failed for 66.111.4.27 (deferred) List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --b8Sq8VBMU+z1HUC/ Content-Type: multipart/mixed; boundary="UeHKblSzlqVy4lQf" Content-Disposition: inline --UeHKblSzlqVy4lQf Content-Type: text/plain; charset=us-ascii Content-Disposition: inline On Tue, Mar 30, 2021 at 11:15:48PM +0000, Jacob Champion wrote: > Rather than putting Postgres log data into the Perl logs, I rotate the > logs exactly once at the beginning -- so that there's an > old 001_ssltests_primary.log, and a new 001_ssltests_primary_1.log -- > and then every time we truncate the logfile, I shuffle the bits from > the new logfile into the old one. So no one has to learn to find the > log entries in a new place, we don't get an explosion of rotated logs, > we don't lose the log data, we don't match incorrect portions of the > logs, and we only pay the restart price once. This is wrapped into a > small Perl module, LogCollector. Hmm. I have dug today into that and I am really not convinced that this is necessary, as a connection attempt combined with the output sent to stderr gives you the stability needed. If we were to have anything like that, perhaps a sub-class of PostgresNode would be adapted instead, with an internal log integration. After thinking about it, the new wording in config.sgml looks fine as-is. Anyway, I have not been able to convince myself that we need those slowdowns and that many server restarts as there is no reload-dependent timing here, and things have been stable on everything I have tested (including a slow RPI). I have found a couple of things that can be simplified in the tests: - In src/test/authentication/, except for the trust method where there is no auth ID, all the other tests wrap a like() if $res == 0, or unlike() otherwise. I think that it is cleaner to make the matching pattern an argument of test_role(), and adapt the tests to that. - src/test/ldap/ can also embed a single logic within test_access(). - src/test/ssl/ is a different beast, but I think that there is more refactoring possible here in parallel of the recent work I have sent to have equivalents of test_connect_ok() and test_connect_fails() in PostgresNode.pm. For now, I think that we should just live in this set with a small routine able to check for pattern matches in the logs. Attached is an updated patch, with a couple of comments tweaks, the reworked tests and an indentation done. -- Michael --UeHKblSzlqVy4lQf Content-Type: text/x-diff; charset=us-ascii Content-Disposition: attachment; filename="v15-0001-Log-authenticated-identity-from-all-auth-backend.patch" Content-Transfer-Encoding: quoted-printable =46rom 0f308c892cb4bb120572e996b1eb612682134c03 Mon Sep 17 00:00:00 2001 =46rom: Michael Paquier Date: Wed, 31 Mar 2021 16:05:33 +0900 Subject: [PATCH v15] 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=3D[local] LOG: connection authenticated: identity=3D"pchampion" method=3Dpeer (/= data/pg_hba.conf:88) LOG: connection authorized: user=3Dadmin database=3Dpostgres applicati= on_name=3Dpsql 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: either the down-level (SAM-compatible) logon name, if compat_realm=3D1, or the User Principal Name if compat_realm=3D0 The trust auth method does not set an authenticated identity. Neither does using clientcert=3Dverify-full (use the cert auth method instead). The Kerberos test suite has been modified to let tests match multiple log lines. --- src/include/libpq/hba.h | 1 + src/include/libpq/libpq-be.h | 13 +++ src/backend/libpq/auth.c | 136 ++++++++++++++++++++-- src/backend/libpq/hba.c | 24 ++++ src/test/authentication/t/001_password.pl | 76 +++++++++--- src/test/kerberos/t/001_auth.pl | 47 ++++++-- src/test/ldap/t/001_auth.pl | 42 +++++-- src/test/ssl/t/001_ssltests.pl | 61 +++++++++- src/test/ssl/t/002_scram.pl | 18 ++- doc/src/sgml/config.sgml | 3 +- 10 files changed, 381 insertions(+), 40 deletions(-) diff --git a/src/include/libpq/hba.h b/src/include/libpq/hba.h index 1ec8603da7..63f2962139 100644 --- a/src/include/libpq/hba.h +++ b/src/include/libpq/hba.h @@ -137,6 +137,7 @@ typedef struct Port hbaPort; =20 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 713c34fedd..02015efe13 100644 --- a/src/include/libpq/libpq-be.h +++ b/src/include/libpq/libpq-be.h @@ -159,6 +159,19 @@ typedef struct Port */ HbaLine *hba; =20 + /* + * Authenticated identity. The meaning of this identifier is dependent on + * hba->auth_method; it is the identity (if any) that the user presented + * during the authentication cycle, before they were assigned a database + * role. (It is 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/backend/libpq/auth.c b/src/backend/libpq/auth.c index 9dc28e19aa..dee056b0d6 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" =20 @@ -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); =20 =20 /*---------------------------------------------------------------- @@ -337,6 +340,51 @@ auth_failed(Port *port, int status, char *logdetail) } =20 =20 +/* + * Sets the authenticated identity for the current user. The provided str= ing + * will be copied into the TopMemoryContext. The ID will be logged if + * log_connections is enabled. + * + * Auth methods should call this routine exactly once, as soon as the user= is + * successfully authenticated, even if they have reasons to know that + * authorization will fail later. + * + * The provided string will be copied into TopMemoryContext, to match the + * lifetime of the Port, so it is safe to pass a string that is managed by= an + * external library. + */ +static void +set_authn_id(Port *port, const char *id) +{ + Assert(id); + + 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 =3D MemoryContextStrdup(TopMemoryContext, id); + + if (Log_connections) + { + ereport(LOG, + errmsg("connection authenticated: identity=3D\"%s\" method=3D%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. @@ -757,6 +805,9 @@ CheckPasswordAuth(Port *port, char **logdetail) pfree(shadow_pass); pfree(passwd); =20 + if (result =3D=3D STATUS_OK) + set_authn_id(port, port->user_name); + return result; } =20 @@ -816,6 +867,10 @@ CheckPWChallengeAuth(Port *port, char **logdetail) Assert(auth_result !=3D STATUS_OK); return STATUS_ERROR; } + + if (auth_result =3D=3D STATUS_OK) + set_authn_id(port, port->user_name); + return auth_result; } =20 @@ -1174,8 +1229,13 @@ pg_GSS_checkauth(Port *port) /* * Copy the original name of the authenticated principal into our backend * memory for display later. + * + * This is also our authenticated identity. Set it now, rather than + * waiting for the usermap check below, because authentication has already + * succeeded and we want the log file to reflect that. */ port->gss->princ =3D MemoryContextStrdup(TopMemoryContext, gbuf.value); + set_authn_id(port, gbuf.value); =20 /* * Split the username at the realm separator @@ -1285,6 +1345,7 @@ pg_SSPI_recvauth(Port *port) DWORD domainnamesize =3D sizeof(domainname); SID_NAME_USE accountnameuse; HMODULE secur32; + char *authn_id; =20 QUERY_SECURITY_CONTEXT_TOKEN_FN _QuerySecurityContextToken; =20 @@ -1514,6 +1575,26 @@ pg_SSPI_recvauth(Port *port) return status; } =20 + /* + * We have all of the information necessary to construct the authenticated + * identity. Set it now, rather than waiting for check_usermap below, + * because authentication has already succeeded and we want the log file + * to reflect that. + */ + if (port->hba->compat_realm) + { + /* SAM-compatible format. */ + authn_id =3D psprintf("%s\\%s", domainname, accountname); + } + else + { + /* Kerberos principal format. */ + authn_id =3D 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. @@ -1901,8 +1982,15 @@ ident_inet_done: pg_freeaddrinfo_all(local_addr.addr.ss_family, la); =20 if (ident_return) - /* Success! Check the usermap */ + { + /* + * Success! Store the identity, then check the usermap. Note that + * setting the authenticated identity is done before checking the + * usermap, because at this point authentication has succeeded. + */ + set_authn_id(port, ident_user); return check_usermap(port->hba->usermap, port->user_name, ident_user, fa= lse); + } return STATUS_ERROR; } =20 @@ -1926,7 +2014,6 @@ auth_peer(hbaPort *port) gid_t gid; #ifndef WIN32 struct passwd *pw; - char *peer_user; int ret; #endif =20 @@ -1958,12 +2045,14 @@ auth_peer(hbaPort *port) return STATUS_ERROR; } =20 - /* Make a copy of static getpw*() result area. */ - peer_user =3D pstrdup(pw->pw_name); + /* + * Make a copy of static getpw*() result area; this is our authenticated + * identity. Set it before calling check_usermap, because authentication + * has already succeeded and we want the log file to reflect that. + */ + set_authn_id(port, pw->pw_name); =20 - ret =3D check_usermap(port->hba->usermap, port->user_name, peer_user, fal= se); - - pfree(peer_user); + ret =3D check_usermap(port->hba->usermap, port->user_name, port->authn_id= , false); =20 return ret; #else @@ -2220,6 +2309,9 @@ CheckPAMAuth(Port *port, const char *user, const char= *password) =20 pam_passwd =3D NULL; /* Unset pam_passwd */ =20 + if (retval =3D=3D PAM_SUCCESS) + set_authn_id(port, user); + return (retval =3D=3D PAM_SUCCESS ? STATUS_OK : STATUS_ERROR); } #endif /* USE_PAM */ @@ -2255,6 +2347,7 @@ CheckBSDAuth(Port *port, char *user) if (!retval) return STATUS_ERROR; =20 + set_authn_id(port, user); return STATUS_OK; } #endif /* USE_BSD_AUTH */ @@ -2761,6 +2854,9 @@ CheckLDAPAuth(Port *port) return STATUS_ERROR; } =20 + /* Save the original bind DN as the authenticated identity. */ + set_authn_id(port, fulluser); + ldap_unbind(ldap); pfree(passwd); pfree(fulluser); @@ -2824,6 +2920,30 @@ CheckCertAuth(Port *port) return STATUS_ERROR; } =20 + if (port->hba->auth_method =3D=3D uaCert) + { + /* + * For cert auth, the client's Subject DN is always our authenticated + * identity, even if we're only using its CN for authorization. Set + * it now, rather than waiting for check_usermap() below, because + * authentication has already succeeded and we want the log file to + * reflect that. + */ + if (!port->peer_dn) + { + /* + * This should not happen as both peer_dn and peer_cn should be + * set in this context. + */ + 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/dn to the usermap check */ status_check_usermap =3D check_usermap(port->hba->usermap, port->user_nam= e, peer_username, false); if (status_check_usermap !=3D STATUS_OK) @@ -2995,6 +3115,8 @@ CheckRADIUSAuth(Port *port) */ if (ret =3D=3D 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 feb711a6ef..b720b03e9a 100644 --- a/src/backend/libpq/hba.c +++ b/src/backend/libpq/hba.c @@ -3141,3 +3141,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) a= nd + * should not be freed. + */ +const char * +hba_authname(hbaPort *port) +{ + UserAuth auth_method; + + Assert(port->hba); + auth_method =3D port->hba->auth_method; + + if (auth_method < 0 || USER_AUTH_LAST < auth_method) + { + /* Should never happen. */ + elog(FATAL, "port has out-of-bounds UserAuth: %d", auth_method); + } + + return UserAuthName[auth_method]; +} diff --git a/src/test/authentication/t/001_password.pl b/src/test/authentic= ation/t/001_password.pl index 36a616d7c7..f75d555ae5 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 =3D> 13; + plan tests =3D> 22; } =20 =20 @@ -38,25 +38,50 @@ sub reset_pg_hba # Test access for a single role, useful to wrap all tests into one. sub test_role { - my $node =3D shift; - my $role =3D shift; - my $method =3D shift; - my $expected_res =3D shift; - my $status_string =3D 'failed'; + my $node =3D shift; + my $role =3D shift; + my $method =3D shift; + my $expected_res =3D shift; + my $expected_log_msg =3D shift; + my $status_string =3D 'failed'; =20 $status_string =3D 'success' if ($expected_res eq 0); =20 local $Test::Builder::Level =3D $Test::Builder::Level + 1; =20 - my $res =3D $node->psql('postgres', undef, extra_params =3D> [ '-U', $rol= e, '-w' ]); - is($res, $expected_res, - "authentication $status_string for method $method, role $role"); + my $res =3D + $node->psql('postgres', undef, extra_params =3D> [ '-U', $role, '-w' ]); + my $testname =3D + "authentication $status_string for method $method, role $role"; + is($res, $expected_res, $testname); + + # Check if any log generated by authentication matches or not. + if ($expected_log_msg ne '') + { + my $log_contents =3D slurp_file($node->logfile); + if ($res =3D=3D 0) + { + like($log_contents, $expected_log_msg, + "$testname: logs matching"); + } + else + { + unlike($log_contents, $expected_log_msg, + "$testname: logs not matching"); + } + + # Clean up any existing contents in the node's log file so as + # future tests don't step on each other's generated contents. + truncate $node->logfile, 0; + } + return; } =20 # Initialize primary node my $node =3D get_new_node('primary'); $node->init; +$node->append_conf('postgresql.conf', "log_connections =3D on\n"); $node->start; =20 # Create 3 roles with different password methods for each one. The same @@ -74,21 +99,42 @@ reset_pg_hba($node, 'trust'); test_role($node, 'scram_role', 'trust', 0); test_role($node, 'md5_role', 'trust', 0); =20 +# Particular case here, the logs should have generated nothing related +# to authenticated users. +my $log_contents =3D slurp_file($node->logfile); +unlike( + $log_contents, + qr/connection authenticated:/, + "trust method does not authenticate users"); +truncate $node->logfile, 0; + # 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); +test_role($node, 'scram_role', 'password', 0, + qr/connection authenticated: identity=3D"scram_role" method=3Dpassword/); +test_role($node, 'md5_role', 'password', 0, + qr/connection authenticated: identity=3D"md5_role" method=3Dpassword/); =20 # 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); +test_role($node, 'scram_role', 'scram-sha-256', 0, + qr/connection authenticated: identity=3D"scram_role" method=3Dscram-sha-2= 56/); +test_role($node, 'md5_role', 'scram-sha-256', 2, + qr/connection authenticated: identity=3D"md5_role"/); + +# Test that bad passwords are rejected. +$ENV{"PGPASSWORD"} =3D 'badpass'; +test_role($node, 'scram_role', 'scram-sha-256', 2, + qr/connection authenticated:/); +$ENV{"PGPASSWORD"} =3D 'pass'; =20 # 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); +test_role($node, 'scram_role', 'md5', 0, + qr/connection authenticated: identity=3D"scram_role" method=3Dmd5/); +test_role($node, 'md5_role', 'md5', 0, + qr/connection authenticated: identity=3D"md5_role" method=3Dmd5/); =20 # Tests for channel binding without SSL. # Using the password authentication method; channel binding can't work diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth= =2Epl index 38e9ef7b1f..d970cf3186 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); =20 if ($ENV{with_gssapi} eq 'yes') { - plan tests =3D> 26; + plan tests =3D> 38; } else { @@ -182,7 +182,8 @@ note "running tests"; # Test connection success or failure, and if success, that query returns t= rue. sub test_access { - my ($node, $role, $query, $expected_res, $gssencmode, $test_name, $expect= _log_msg) =3D @_; + my ($node, $role, $query, $expected_res, $gssencmode, $test_name, + @expect_log_msgs) =3D @_; =20 # need to connect over TCP/IP for Kerberos my ($res, $stdoutres, $stderrres) =3D $node->psql( @@ -206,8 +207,8 @@ sub test_access is($res, $expected_res, $test_name); } =20 - # 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. + while (my $expect_log_msg =3D shift @expect_log_msgs) { my $first_logfile =3D slurp_file($node->logfile); =20 @@ -249,11 +250,19 @@ $node->append_conf('pg_hba.conf', qq{host all all $hostaddr/32 gss map=3Dmymap}); $node->restart; =20 -test_access($node, 'test1', 'SELECT true', 2, '', 'fails without ticket', = ''); +test_access($node, 'test1', 'SELECT true', 2, '', 'fails without ticket'); =20 run_log [ $kinit, 'test1' ], \$test1_password or BAIL_OUT($?); =20 -test_access($node, 'test1', 'SELECT true', 2, '', 'fails without mapping',= ''); +test_access( + $node, + 'test1', + 'SELECT true', + 2, + '', + 'fails without mapping', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", + "no match in usermap \"mymap\" for user \"test1\""); =20 $node->append_conf('pg_ident.conf', qq{mymap /^(.*)\@$realm\$ \\1}); $node->restart; @@ -265,6 +274,7 @@ test_access( 0, '', 'succeeds with mapping with default gssencmode and host hba', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dyes, principal=3Dt= est1\@$realm)" ); =20 @@ -275,6 +285,7 @@ test_access( 0, 'gssencmode=3Dprefer', 'succeeds with GSS-encrypted access preferred with host hba', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dyes, principal=3Dt= est1\@$realm)" ); test_access( @@ -284,6 +295,7 @@ test_access( 0, 'gssencmode=3Drequire', 'succeeds with GSS-encrypted access required with host hba', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dyes, principal=3Dt= est1\@$realm)" ); =20 @@ -320,6 +332,7 @@ test_access( 0, 'gssencmode=3Dprefer', 'succeeds with GSS-encrypted access preferred and hostgssenc hba', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dyes, principal=3Dt= est1\@$realm)" ); test_access( @@ -329,6 +342,7 @@ test_access( 0, 'gssencmode=3Drequire', 'succeeds with GSS-encrypted access required and hostgssenc hba', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dyes, principal=3Dt= est1\@$realm)" ); test_access($node, 'test1', 'SELECT true', 2, 'gssencmode=3Ddisable', @@ -346,10 +360,11 @@ test_access( 0, 'gssencmode=3Dprefer', 'succeeds with GSS-encrypted access preferred and hostnogssenc hba, but n= o encryption', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dno, principal=3Dte= st1\@$realm)" ); test_access($node, 'test1', 'SELECT true', 2, 'gssencmode=3Drequire', - 'fails with GSS-encrypted access required and hostnogssenc hba', ''); + 'fails with GSS-encrypted access required and hostnogssenc hba'); test_access( $node, 'test1', @@ -357,6 +372,7 @@ test_access( 0, 'gssencmode=3Ddisable', 'succeeds with GSS encryption disabled and hostnogssenc hba', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dno, principal=3Dte= st1\@$realm)" ); =20 @@ -373,5 +389,22 @@ test_access( 0, '', 'succeeds with include_realm=3D0 and defaults', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss", "connection authorized: user=3D$username database=3D$dbname application_n= ame=3D$application GSS (authenticated=3Dyes, encrypted=3Dyes, principal=3Dt= est1\@$realm)" ); + +# Reset pg_hba.conf, and cause a usermap failure with an authentication +# that has passed. +unlink($node->data_dir . '/pg_hba.conf'); +$node->append_conf('pg_hba.conf', + qq{host all all $hostaddr/32 gss include_realm=3D0 krb_realm=3DEXAMPLE.OR= G}); +$node->restart; + +test_access( + $node, + 'test1', + 'SELECT true', + 2, + '', + 'fails with wrong krb_realm, but still authenticates', + "connection authenticated: identity=3D\"test1\@$realm\" method=3Dgss"); diff --git a/src/test/ldap/t/001_auth.pl b/src/test/ldap/t/001_auth.pl index 3bc7672451..e98c8fe965 100644 --- a/src/test/ldap/t/001_auth.pl +++ b/src/test/ldap/t/001_auth.pl @@ -6,7 +6,7 @@ use Test::More; =20 if ($ENV{with_ldap} eq 'yes') { - plan tests =3D> 22; + plan tests =3D> 25; } else { @@ -152,6 +152,7 @@ note "setting up PostgreSQL instance"; =20 my $node =3D get_new_node('node'); $node->init; +$node->append_conf('postgresql.conf', "log_connections =3D on\n"); $node->start; =20 $node->safe_psql('postgres', 'CREATE USER test0;'); @@ -162,12 +163,32 @@ note "running tests"; =20 sub test_access { - my ($node, $role, $expected_res, $test_name) =3D @_; + my ($node, $role, $expected_res, $test_name, $expected_log_msg) =3D @_; =20 my $res =3D $node->psql('postgres', undef, extra_params =3D> [ '-U', $role, '-c', 'SELECT 1' ]); is($res, $expected_res, $test_name); + + # Check if any log generated by authentication matches or not. + if ($expected_log_msg ne '') + { + my $log_contents =3D slurp_file($node->logfile); + if ($res =3D=3D 0) + { + like($log_contents, $expected_log_msg, + "$test_name: logs matching"); + } + else + { + unlike($log_contents, $expected_log_msg, + "$test_name: logs not matching"); + } + + # Clean up any existing contents in the node's log file so as + # future tests don't step on each other's generated contents. + truncate $node->logfile, 0; + } return; } =20 @@ -180,12 +201,19 @@ $node->append_conf('pg_hba.conf', $node->restart; =20 $ENV{"PGPASSWORD"} =3D 'wrong'; -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'); +test_access( + $node, 'test0', 2, + 'simple bind authentication fails if user not found in LDAP', + qr/connection authenticated:/); +test_access( + $node, 'test1', 2, + 'simple bind authentication fails with wrong password', + qr/connection authenticated:/); + $ENV{"PGPASSWORD"} =3D 'secret1'; -test_access($node, 'test1', 0, 'simple bind authentication succeeds'); +test_access($node, 'test1', 0, 'simple bind authentication succeeds', + qr/connection authenticated: identity=3D"uid=3Dtest1,dc=3Dexample,dc=3Dne= t" method=3Dldap/ +); =20 note "search+bind"; =20 diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl index adaa1b4e9b..80be22fb95 100644 --- a/src/test/ssl/t/001_ssltests.pl +++ b/src/test/ssl/t/001_ssltests.pl @@ -17,7 +17,33 @@ if ($ENV{with_ssl} ne 'openssl') } else { - plan tests =3D> 103; + plan tests =3D> 108; +} + +# Check for matching patterns in the logs of a node. This should +# be used after a connection attempt. $res indicates if the pattern +# should match or not. +sub check_auth_logs +{ + my $node =3D shift; + my $expected_log_msg =3D shift; + my $test_name =3D shift; + my $res =3D shift; + + my $log_contents =3D slurp_file($node->logfile); + + if ($res =3D=3D 0) + { + like($log_contents, $expected_log_msg, $test_name); + } + else + { + unlike($log_contents, $expected_log_msg, $test_name); + } + + # Clean up any existing contents in the node's log file so as + # future tests don't step on each other's generated contents. + truncate $node->logfile, 0; } =20 #### Some configuration @@ -463,6 +489,12 @@ test_connect_ok( "certificate authorization succeeds with DN mapping" ); =20 +check_auth_logs( + $node, + qr/connection authenticated: identity=3D"CN=3Dssltestuser-dn,OU=3DTesting= ,OU=3DEngineering,O=3DPGDG" method=3Dcert/, + "certificate authorization with DN mapping logged", + 0); + # same thing but with a regex $dn_connstr =3D "$common_connstr dbname=3Dcertdb_dn_re"; =20 @@ -481,6 +513,11 @@ test_connect_ok( "certificate authorization succeeds with CN mapping" ); =20 +check_auth_logs( + $node, + qr/connection authenticated: identity=3D"CN=3Dssltestuser-dn,OU=3DTesting= ,OU=3DEngineering,O=3DPGDG" method=3Dcert/, + "certificate authorization with CN mapping logged with DN info", + 0); =20 =20 TODO: @@ -547,12 +584,23 @@ test_connect_fails( "certificate authorization fails with client cert belonging to another us= er" ); =20 +check_auth_logs( + $node, + qr/connection authenticated: identity=3D"CN=3Dssltestuser" method=3Dcert/, + "certificate authorization logged even on failure", 0); + # revoked client cert test_connect_fails( $common_connstr, "user=3Dssltestuser sslcert=3Dssl/client-revoked.crt sslkey=3Dssl/client-= revoked_tmp.key", qr/SSL error/, - "certificate authorization fails with revoked client cert"); + "certificate authorization fails with revoked client cert", + 0); + +check_auth_logs( + $node, + qr/connection authenticated:/, + "certificate authentication with revoked client cert not logged", 1); =20 # Check that connecting with auth-option verify-full in pg_hba: # works, iff username matches Common Name @@ -575,12 +623,21 @@ test_connect_fails( =20 # Check that connecting with auth-optionverify-ca in pg_hba : # works, when username doesn't match Common Name +# Clean up once the logs to have a clean check state. +truncate $node->logfile, 0; test_connect_ok( $common_connstr, "user=3Dyetanotheruser sslcert=3Dssl/client.crt sslkey=3Dssl/client_tmp.k= ey", "auth_option clientcert=3Dverify-ca succeeds with mismatching username an= d Common Name" ); =20 +# None of the above connections to verifydb should have resulted in +# authentication. +check_auth_logs( + $node, + qr/connection authenticated:/, + "trust auth method does not set authenticated identity", 1); + # 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 =3D diff --git a/src/test/ssl/t/002_scram.pl b/src/test/ssl/t/002_scram.pl index 410b9e910d..0d0f4fe674 100644 --- a/src/test/ssl/t/002_scram.pl +++ b/src/test/ssl/t/002_scram.pl @@ -27,7 +27,7 @@ my $SERVERHOSTCIDR =3D '127.0.0.1/32'; my $supports_tls_server_end_point =3D check_pg_config("#define HAVE_X509_GET_SIGNATURE_NID 1"); =20 -my $number_of_tests =3D $supports_tls_server_end_point ? 9 : 10; +my $number_of_tests =3D $supports_tls_server_end_point ? 11 : 12; =20 # Allocation of base connection string shared among multiple tests. my $common_connstr; @@ -102,6 +102,22 @@ test_connect_fails( qr/channel binding required, but server authenticated client without chan= nel binding/, "Cert authentication and channel_binding=3Drequire"); =20 +# Certificate verification at the connection level should still work fine. +# Truncate once the logs, to ensure that we check what is generated for th= is +# specific connection. +truncate $node->logfile, 0; +test_connect_ok( + "sslcert=3Dssl/client.crt sslkey=3D$client_tmp_key sslrootcert=3Dinvalid = hostaddr=3D$SERVERHOSTADDR", + "dbname=3Dverifydb user=3Dssltestuser channel_binding=3Drequire", + "SCRAM with clientcert=3Dverify-full and channel_binding=3Drequire"); + +my $log_contents =3D slurp_file($node->logfile); +like( + $log_contents, + qr/connection authenticated: identity=3D"ssltestuser" method=3Dscram-sha-= 256/, + "SCRAM with clientcert=3Dverify-full sets the username as the authenticat= ed identity" +); + # clean up unlink($client_tmp_key); =20 diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index ddc6d789d8..a322729098 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6678,7 +6678,8 @@ local0.* /var/log/postgresql Causes each attempted connection to the server to be logged, - as well as successful completion of client authentication. + as well as successful completion of both client authentication (if + necessary) and authorization. Only superusers can change this parameter at session start, and it cannot be changed at all within a session. The default is off. --=20 2.31.0 --UeHKblSzlqVy4lQf-- --b8Sq8VBMU+z1HUC/ Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmBkJ+gACgkQnvQgOdby QH39SA//TFhCD9I0qA57/He6C4/yH0UVX7Am8pEzuJtm0VzHfMYNXHFxBpB2fKX+ wonbCzeFZR1HuC4lewjuqBywQ8r06DhxbDU/c+JwR4RtrjUZBCuOw6/rruuvEtp4 9PK9osnPsfcMGJJU6Ve4Chkvb6WJl/oOjEiFDbTjR6dkuOuHCK6yD9yeIa8mmYRr p4kqWxdVctmuWOvPOXdDlahGC2/wDL8ZlWxj6Ml6o9jwMnaEKDegW3FUk9a5QUJn 4mjLldiqkKF/4UTvaPJbmI4rRmVX8+OhqBXLStZLwrYXvUjuOIF0yNElWsQqhses NnQ1bJ04sJ11R/rGXYyZ4Az1ZT/71QJJFQJXJjUJtkSGpsIABu0BOo0LXabLCz62 NJ39bBV8FI56totDD55/VFmvsC1kQFIVyrr+SHNtd+HbXdViBKY2dwNPWtCuHWzz NzU42KRZgJQiZrBfDhwvTPtDiY6xKutpbUV281qQaRodDdNzYAX1QnMKLivCI6o5 XS+HXV78e/n/YNknV8jrVMU2kpRH2slka0PuI156uTAqysretCwDftKi3s6ygsCC q/GjW9O3uJtWH2VkWdWBWQyMAmUsmnnW29grTtH56KGALKohqi7x0QHeV/EBp7k0 LJSTmr1p5Y46KqQdI3VeIUxMmw2/MImFn+uSrkNiRH3K/O6qC+4= =S63d -----END PGP SIGNATURE----- --b8Sq8VBMU+z1HUC/--