Обсуждение: Better detail logging for password auth failures

Поиск
Список
Период
Сортировка

Better detail logging for password auth failures

От
Tom Lane
Дата:
We often tell people to look in the postmaster log for more information
about authentication problems; but an off-list question prompted me to
notice that many of the common authentication failure cases don't actually
get any useful commentary in the log.  The attached proposed patch
remedies this by adding specific log detail messages for all the
non-out-of-memory cases processed by md5_crypt_verify().  Essentially,
this is just covering cases that I omitted to cover in commit 64e43c59,
for reasons that no longer seem very good to me.

I did not bother with going through the other auth methods in similar
detail.  It seems like only password authentication is in use by people
who are in need of this kind of help.  (But if someone else wants to do
something similar for other auth methods, feel free.)

In passing, the patch gets rid of a vestigial CHECK_FOR_INTERRUPTS()
call; it was added by e710b65c and IMO should have been removed again
by 6647248e.  There's certainly no very good reason to have one right
at that spot anymore.

Any objections?

            regards, tom lane

diff --git a/src/backend/libpq/crypt.c b/src/backend/libpq/crypt.c
index 97be944..64c25e8 100644
*** a/src/backend/libpq/crypt.c
--- b/src/backend/libpq/crypt.c
*************** md5_crypt_verify(const Port *port, const
*** 50,56 ****
--- 50,60 ----
      /* Get role info from pg_authid */
      roleTup = SearchSysCache1(AUTHNAME, PointerGetDatum(role));
      if (!HeapTupleIsValid(roleTup))
+     {
+         *logdetail = psprintf(_("Role \"%s\" does not exist."),
+                               role);
          return STATUS_ERROR;    /* no such user */
+     }

      datum = SysCacheGetAttr(AUTHNAME, roleTup,
                              Anum_pg_authid_rolpassword, &isnull);
*************** md5_crypt_verify(const Port *port, const
*** 71,83 ****
      ReleaseSysCache(roleTup);

      if (*shadow_pass == '\0')
          return STATUS_ERROR;    /* empty password */
!
!     CHECK_FOR_INTERRUPTS();

      /*
       * Compare with the encrypted or plain password depending on the
!      * authentication method being used for this connection.
       */
      switch (port->hba->auth_method)
      {
--- 75,92 ----
      ReleaseSysCache(roleTup);

      if (*shadow_pass == '\0')
+     {
+         *logdetail = psprintf(_("User \"%s\" has an empty password."),
+                               role);
          return STATUS_ERROR;    /* empty password */
!     }

      /*
       * Compare with the encrypted or plain password depending on the
!      * authentication method being used for this connection.  (We do not
!      * bother setting logdetail for pg_md5_encrypt failure: the only possible
!      * error is out-of-memory, which is unlikely, and if it did happen adding
!      * a psprintf call would only make things worse.)
       */
      switch (port->hba->auth_method)
      {
*************** md5_crypt_verify(const Port *port, const
*** 154,159 ****
--- 163,171 ----
          else
              retval = STATUS_OK;
      }
+     else
+         *logdetail = psprintf(_("Password does not match for user \"%s\"."),
+                               role);

      if (port->hba->auth_method == uaMD5)
          pfree(crypt_pwd);

Re: Better detail logging for password auth failures

От
Michael Paquier
Дата:
On Wed, Dec 30, 2015 at 1:07 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> We often tell people to look in the postmaster log for more information
> about authentication problems; but an off-list question prompted me to
> notice that many of the common authentication failure cases don't actually
> get any useful commentary in the log.  The attached proposed patch
> remedies this by adding specific log detail messages for all the
> non-out-of-memory cases processed by md5_crypt_verify().  Essentially,
> this is just covering cases that I omitted to cover in commit 64e43c59,
> for reasons that no longer seem very good to me.
>
> Any objections?

Not really. +1. And the patch looks good.
-- 
Michael



Re: Better detail logging for password auth failures

От
Andres Freund
Дата:
On 2015-12-29 11:07:26 -0500, Tom Lane wrote:
> In passing, the patch gets rid of a vestigial CHECK_FOR_INTERRUPTS()
> call; it was added by e710b65c and IMO should have been removed again
> by 6647248e.  There's certainly no very good reason to have one right
> at that spot anymore.

Why? Doesn't seem like the worst place for an explicit interrupt check?
I think we don't really have a problem with too many such checks... We
surely could move it, but I don't really see how it's related to the
topic at hand nor do I think it's really worth pondering about
extensively.

Andres



Re: Better detail logging for password auth failures

От
Tom Lane
Дата:
Andres Freund <andres@anarazel.de> writes:
> On 2015-12-29 11:07:26 -0500, Tom Lane wrote:
>> In passing, the patch gets rid of a vestigial CHECK_FOR_INTERRUPTS()
>> call; it was added by e710b65c and IMO should have been removed again
>> by 6647248e.  There's certainly no very good reason to have one right
>> at that spot anymore.

> Why? Doesn't seem like the worst place for an explicit interrupt check?

The only reason there was one there at all was that e710b65c added
code like this:

+   /*
+    * Disable immediate interrupts while doing database access.  (Note
+    * we don't bother to turn this back on if we hit one of the failure
+    * conditions, since we can expect we'll just exit right away anyway.)
+    */
+   ImmediateInterruptOK = false;
   ... some catalog access here ...

+   /* Re-enable immediate response to SIGTERM/SIGINT/timeout interrupts */
+   ImmediateInterruptOK = true;
+   /* And don't forget to detect one that already arrived */
+   CHECK_FOR_INTERRUPTS();

In 6647248e you got rid of nine of these ten lines, leaving something
that's both pointless and undocumented.  There are more than enough
CHECK_FOR_INTERRUPTS calls already in the auth code; there's not a
reason to expend code space on one here.  (If MD5 ran long enough to
be worth interrupting, there would be an argument for a check inside
its hashing loop, but that still wouldn't be this check.)
        regards, tom lane



Re: Better detail logging for password auth failures

От
Noah Misch
Дата:
On Wed, Dec 30, 2015 at 10:18:35AM -0500, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > On 2015-12-29 11:07:26 -0500, Tom Lane wrote:
> >> In passing, the patch gets rid of a vestigial CHECK_FOR_INTERRUPTS()
> >> call; it was added by e710b65c and IMO should have been removed again
> >> by 6647248e.  There's certainly no very good reason to have one right
> >> at that spot anymore.
> 
> > Why? Doesn't seem like the worst place for an explicit interrupt check?
> > I think we don't really have a problem with too many such checks... We
> > surely could move it, but I don't really see how it's related to the
> > topic at hand nor do I think it's really worth pondering about
> > extensively.

Agreed.

> The only reason there was one there at all was that e710b65c added
> code like this:
> 
> +   /*
> +    * Disable immediate interrupts while doing database access.  (Note
> +    * we don't bother to turn this back on if we hit one of the failure
> +    * conditions, since we can expect we'll just exit right away anyway.)
> +    */
> +   ImmediateInterruptOK = false;
> 
>     ... some catalog access here ...
> 
> +   /* Re-enable immediate response to SIGTERM/SIGINT/timeout interrupts */
> +   ImmediateInterruptOK = true;
> +   /* And don't forget to detect one that already arrived */
> +   CHECK_FOR_INTERRUPTS();
> 
> In 6647248e you got rid of nine of these ten lines, leaving something
> that's both pointless and undocumented.  There are more than enough
> CHECK_FOR_INTERRUPTS calls already in the auth code; there's not a
> reason to expend code space on one here.  (If MD5 ran long enough to
> be worth interrupting, there would be an argument for a check inside
> its hashing loop, but that still wouldn't be this check.)

I see no general benefit from being parsimonious with CHECK_FOR_INTERRUPTS
calls or documenting them.  As you explain, it's probably fine to remove the
two calls that commit e710b65 had added.  However, the sole connection to
$SUBJECT is one of those two calls sharing a screenful with lines $SUBJECT
changed.  The removal, if worthwhile, is worth a freestanding patch.
Squashing the changes makes both topics harder to review.

nm



Re: Better detail logging for password auth failures

От
Edson - Amplosoft Software
Дата:
<br /><br /><div class="gmail_quote">Em 31 de dezembro de 2015 04:56:55 BRST, Noah Misch <noah@leadboat.com>
escreveu:<blockquoteclass="gmail_quote" style="margin: 0pt 0pt 0pt 0.8ex; border-left: 1px solid rgb(204, 204, 204);
padding-left:1ex;"><pre class="k9mail">On Wed, Dec 30, 2015 at 10:18:35AM -0500, Tom Lane wrote:<br /><blockquote
class="gmail_quote"style="margin: 0pt 0pt 1ex 0.8ex; border-left: 1px solid #729fcf; padding-left: 1ex;"> Andres Freund
<andres@anarazel.de>writes:<br /><blockquote class="gmail_quote" style="margin: 0pt 0pt 1ex 0.8ex; border-left:
1pxsolid #ad7fa8; padding-left: 1ex;"> On 2015-12-29 11:07:26 -0500, Tom Lane wrote:<br /><blockquote
class="gmail_quote"style="margin: 0pt 0pt 1ex 0.8ex; border-left: 1px solid #8ae234; padding-left: 1ex;"> In passing,
thepatch gets rid of a vestigial CHECK_FOR_INTERRUPTS()<br /> call; it was added by e710b65c and IMO should have been
removedagain<br /> by 6647248e.  There's certainly no very good reason to have one right<br /> at that spot anymore.<br
/></blockquote></blockquote><br /><blockquote class="gmail_quote" style="margin: 0pt 0pt 1ex 0.8ex; border-left: 1px
solid#ad7fa8; padding-left: 1ex;"> Why? Doesn't seem like the worst place for an
 
explicit interrupt check?<br /> I think we don't really have a problem with too many such checks... We<br /> surely
couldmove it, but I don't really see how it's related to the<br /> topic at hand nor do I think it's really worth
ponderingabout<br /> extensively.<br /></blockquote></blockquote><br />Agreed.<br /><br /><blockquote
class="gmail_quote"style="margin: 0pt 0pt 1ex 0.8ex; border-left: 1px solid #729fcf; padding-left: 1ex;"> The only
reasonthere was one there at all was that e710b65c added<br /> code like this:<br /> <br /> +   /*<br /> +    * Disable
immediateinterrupts while doing database access.  (Note<br /> +    * we don't bother to turn this back on if we hit one
ofthe failure<br /> +    * conditions, since we can expect we'll just exit right away anyway.)<br /> +    */<br /> +
ImmediateInterruptOK= false;<br /> <br />     ... some catalog access here ...<br /> <br /> +   /* Re-enable immediate
responseto SIGTERM/SIGINT/timeout interrupts */<br /> +  
 
ImmediateInterruptOK = true;<br /> +   /* And don't forget to detect one that already arrived */<br /> +
CHECK_FOR_INTERRUPTS();<br/> <br /> In 6647248e you got rid of nine of these ten lines, leaving something<br /> that's
bothpointless and undocumented.  There are more than enough<br /> CHECK_FOR_INTERRUPTS calls already in the auth code;
there'snot a<br /> reason to expend code space on one here.  (If MD5 ran long enough to<br /> be worth interrupting,
therewould be an argument for a check inside<br /> its hashing loop, but that still wouldn't be this check.)<br
/></blockquote><br/>I see no general benefit from being parsimonious with CHECK_FOR_INTERRUPTS<br />calls or
documentingthem.  As you explain, it's probably fine to remove the<br />two calls that commit e710b65 had added.
However,the sole connection to<br />$SUBJECT is one of those two calls sharing a screenful with lines $SUBJECT<br
/>changed. The removal, if worthwhile, is worth a freestanding patch.<br />Squashing the changes makes both topics
harderto review.<br /><br />nm<br /><br /></pre></blockquote></div><br /> -- <br /> Sent from my Android device with
K-9Mail. Please excuse my brevity. 

Re: Better detail logging for password auth failures

От
Robert Haas
Дата:
On Thu, Dec 31, 2015 at 11:09 AM, Edson - Amplosoft Software
<edson@openmailbox.org> wrote:
> [ quote of an existing message in its entirety ]
> --
> Sent from my Android device with K-9 Mail. Please excuse my brevity.

Yes, that was extremely brief.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company