Thread: Better detail logging for password auth failures
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);
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
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
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
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
<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.
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