Thread: [HACKERS] Log LDAP "diagnostic messages"?
Hi hackers,
Some LDAP error codes are a bit vague. For example:
LDAP_CONNECT_ERROR Indicates a connection problem.
LDAP_PROTOCOL_ERROR A protocol violation was detected.
To learn more, you have to call
ldap_get_option(LDAP_OPT_DIAGNOSTIC_MESSAGE). Should we do that? For
example, instead of:
LOG: could not start LDAP TLS session: Protocol error
... you could see:
LOG: could not start LDAP TLS session: Protocol error
DETAIL: LDAP diagnostic message: unsupported extended operation
Well, that may not be the most illuminating example, but that's a
message sent back by the LDAP server that we're currently throwing
away, and can be used to distinguish between unsupported TLS versions,
missing StartTLS extension and various other cases. Perhaps that
particular message would also be available via your LDAP server's
logs, if you can access them, but in some cases we're throwing away
client-side messages that are not available anywhere else like "TLS:
unable to get CN from peer certificate", "TLS: hostname does not match
CN in peer certificate" and more.
Something like the attached.
--
Thomas Munro
http://www.enterprisedb.com
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Attachment
On Wed, Jul 26, 2017 at 6:51 AM, Thomas Munro <thomas.munro@enterprisedb.com> wrote: > Hi hackers, > > Some LDAP error codes are a bit vague. For example: > > LDAP_CONNECT_ERROR Indicates a connection problem. > LDAP_PROTOCOL_ERROR A protocol violation was detected. > > To learn more, you have to call > ldap_get_option(LDAP_OPT_DIAGNOSTIC_MESSAGE). Should we do that? For > example, instead of: > > LOG: could not start LDAP TLS session: Protocol error > > ... you could see: > > LOG: could not start LDAP TLS session: Protocol error > DETAIL: LDAP diagnostic message: unsupported extended operation > > Well, that may not be the most illuminating example, but that's a > message sent back by the LDAP server that we're currently throwing > away, and can be used to distinguish between unsupported TLS versions, > missing StartTLS extension and various other cases. Perhaps that > particular message would also be available via your LDAP server's > logs, if you can access them, but in some cases we're throwing away > client-side messages that are not available anywhere else like "TLS: > unable to get CN from peer certificate", "TLS: hostname does not match > CN in peer certificate" and more. > +1. > Something like the attached. The patch prints errdetail() as "No LDAP diagnostic message available." when LDAP doesn't provide diagnostics. May be some error messages do not have any diagnostic information. In that case above error detail may be confusing. May be we should just omit error details when diagnostic message is not available. -- Best Wishes, Ashutosh Bapat EnterpriseDB Corporation The Postgres Database Company
On Wed, Jul 26, 2017 at 10:40 PM, Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote: > On Wed, Jul 26, 2017 at 6:51 AM, Thomas Munro > <thomas.munro@enterprisedb.com> wrote: >> Something like the attached. > > The patch prints errdetail() as "No LDAP diagnostic message > available." when LDAP doesn't provide diagnostics. May be some error > messages do not have any diagnostic information. In that case above > error detail may be confusing. May be we should just omit error > details when diagnostic message is not available. Agreed. Here's a version that skips those useless detail messages using a coding pattern I found elsewhere. For example, on my system, trying to log in with the wrong password causes an "Invalid credentials" error with no extra "DETAIL:" line logged, but trying to use TLS when it hasn't been configured properly logs a helpful diagnostic message. Thanks for the review! I also noticed a couple of other things in passing and fixed them in this new version: 1. In one place we call ldap_get_option(LDAP_OPT_ERROR_NUMBER) after ldap_unbind_s(). My man page says "Once [ldap_unbind()] is called, the connection to the LDAP server is closed, and the ld structure is invalid." So I don't think we should do that, even if it didn't return LDAP_SUCCESS. I have no idea if any implementation would actually fail to unbind and what state the LDAP object would be in if it did: this is essentially the destructor function for LDAP connections, so what are you supposed to do after that? But using the LDAP object again seems wrong to me. 2. In several code paths we don't call ldap_unbind() on the way out, which is technically leaking a connection. Failure to authenticate is FATAL to the backend anyway so it probably doesn't matter much, but hanging up without saying goodbye is considered discourteous by some[1]. Thoughts anyone? [1] https://www.ldap.com/the-ldap-unbind-operation -- Thomas Munro http://www.enterprisedb.com -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Attachment
On Thu, Jul 27, 2017 at 5:20 PM, Thomas Munro <thomas.munro@enterprisedb.com> wrote: > Agreed. Here's a version that skips those useless detail messages > using a coding pattern I found elsewhere. Rebased after bf6b9e94. -- Thomas Munro http://www.enterprisedb.com -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Attachment
On Thu, Aug 10, 2017 at 5:09 AM, Thomas Munro <thomas.munro@enterprisedb.com> wrote: > On Thu, Jul 27, 2017 at 5:20 PM, Thomas Munro > <thomas.munro@enterprisedb.com> wrote: >> Agreed. Here's a version that skips those useless detail messages >> using a coding pattern I found elsewhere. > > Rebased after bf6b9e94. > Please add this to the next commitfest. -- Best Wishes, Ashutosh Bapat EnterpriseDB Corporation The Postgres Database Company
On Thu, Aug 10, 2017 at 1:16 PM, Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote: > Please add this to the next commitfest. Done: https://commitfest.postgresql.org/14/1229/ -- Thomas Munro http://www.enterprisedb.com
Re: Thomas Munro 2017-08-10 <CAEepm=09jnV7hK5rTxPp816bMuve7dJGbjtEcjeXrhAELHFxqw@mail.gmail.com>
> > Agreed. Here's a version that skips those useless detail messages
> > using a coding pattern I found elsewhere.
>
> Rebased after bf6b9e94.
> message ? errdetail("Diagnostic message: %s", message) : 0));
"Diagnostic message" doesn't really mean anything, and printing
"DETAIL: Diagnostic message: <something>" seems redundant to me. Maybe
drop that prefix? It should be clear from the context that this is a
message from the LDAP layer.
Or maybe simply append ": <message>" to the error message already shown?
Christoph
Christoph Berg wrote:
> Re: Thomas Munro 2017-08-10 <CAEepm=09jnV7hK5rTxPp816bMuve7dJGbjtEcjeXrhAELHFxqw@mail.gmail.com>
> > > Agreed. Here's a version that skips those useless detail messages
> > > using a coding pattern I found elsewhere.
> >
> > Rebased after bf6b9e94.
>
> > message ? errdetail("Diagnostic message: %s", message) : 0));
>
> "Diagnostic message" doesn't really mean anything, and printing
> "DETAIL: Diagnostic message: <something>" seems redundant to me. Maybe
> drop that prefix? It should be clear from the context that this is a
> message from the LDAP layer.
I think making it visible that the message comes from LDAP (rather than
Postgres or anything else) is valuable. How about this?
LOG: could not start LDAP TLS session: Protocol errorDETAIL: LDAP diagnostics: unsupported extended operation.
--
Álvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On Wed, Aug 16, 2017 at 8:44 AM, Alvaro Herrera
<alvherre@2ndquadrant.com> wrote:
> Christoph Berg wrote:
>> Re: Thomas Munro 2017-08-10 <CAEepm=09jnV7hK5rTxPp816bMuve7dJGbjtEcjeXrhAELHFxqw@mail.gmail.com>
>> > > Agreed. Here's a version that skips those useless detail messages
>> > > using a coding pattern I found elsewhere.
>> >
>> > Rebased after bf6b9e94.
>>
>> > message ? errdetail("Diagnostic message: %s", message) : 0));
>>
>> "Diagnostic message" doesn't really mean anything, and printing
>> "DETAIL: Diagnostic message: <something>" seems redundant to me. Maybe
>> drop that prefix? It should be clear from the context that this is a
>> message from the LDAP layer.
>
> I think making it visible that the message comes from LDAP (rather than
> Postgres or anything else) is valuable. How about this?
>
> LOG: could not start LDAP TLS session: Protocol error
> DETAIL: LDAP diagnostics: unsupported extended operation.
>
+1, pretty neat.
--
Best Wishes,
Ashutosh Bapat
EnterpriseDB Corporation
The Postgres Database Company
The patch needs to address some comments in the previous mails, so
marking it as "waiting for author".
On Wed, Aug 16, 2017 at 11:13 AM, Ashutosh Bapat
<ashutosh.bapat@enterprisedb.com> wrote:
> On Wed, Aug 16, 2017 at 8:44 AM, Alvaro Herrera
> <alvherre@2ndquadrant.com> wrote:
>> Christoph Berg wrote:
>>> Re: Thomas Munro 2017-08-10 <CAEepm=09jnV7hK5rTxPp816bMuve7dJGbjtEcjeXrhAELHFxqw@mail.gmail.com>
>>> > > Agreed. Here's a version that skips those useless detail messages
>>> > > using a coding pattern I found elsewhere.
>>> >
>>> > Rebased after bf6b9e94.
>>>
>>> > message ? errdetail("Diagnostic message: %s", message) : 0));
>>>
>>> "Diagnostic message" doesn't really mean anything, and printing
>>> "DETAIL: Diagnostic message: <something>" seems redundant to me. Maybe
>>> drop that prefix? It should be clear from the context that this is a
>>> message from the LDAP layer.
>>
>> I think making it visible that the message comes from LDAP (rather than
>> Postgres or anything else) is valuable. How about this?
>>
>> LOG: could not start LDAP TLS session: Protocol error
>> DETAIL: LDAP diagnostics: unsupported extended operation.
>>
> +1, pretty neat.
>
>
> --
> Best Wishes,
> Ashutosh Bapat
> EnterpriseDB Corporation
> The Postgres Database Company
--
Best Wishes,
Ashutosh Bapat
EnterpriseDB Corporation
The Postgres Database Company
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
On Tue, Sep 12, 2017 at 11:23 PM, Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote: > On Wed, Aug 16, 2017 at 11:13 AM, Ashutosh Bapat > <ashutosh.bapat@enterprisedb.com> wrote: >> On Wed, Aug 16, 2017 at 8:44 AM, Alvaro Herrera >> <alvherre@2ndquadrant.com> wrote: >>> Christoph Berg wrote: >>>> "Diagnostic message" doesn't really mean anything, and printing >>>> "DETAIL: Diagnostic message: <something>" seems redundant to me. Maybe >>>> drop that prefix? It should be clear from the context that this is a >>>> message from the LDAP layer. >>> >>> I think making it visible that the message comes from LDAP (rather than >>> Postgres or anything else) is valuable. How about this? >>> >>> LOG: could not start LDAP TLS session: Protocol error >>> DETAIL: LDAP diagnostics: unsupported extended operation. >>> >> +1, pretty neat. Here is a new version adopting Alvaro's wording. I'll set this back to "Needs review" status. -- Thomas Munro http://www.enterprisedb.com -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Attachment
On Wed, Sep 13, 2017 at 6:58 AM, Thomas Munro <thomas.munro@enterprisedb.com> wrote: > On Tue, Sep 12, 2017 at 11:23 PM, Ashutosh Bapat > <ashutosh.bapat@enterprisedb.com> wrote: >> On Wed, Aug 16, 2017 at 11:13 AM, Ashutosh Bapat >> <ashutosh.bapat@enterprisedb.com> wrote: >>> On Wed, Aug 16, 2017 at 8:44 AM, Alvaro Herrera >>> <alvherre@2ndquadrant.com> wrote: >>>> Christoph Berg wrote: >>>>> "Diagnostic message" doesn't really mean anything, and printing >>>>> "DETAIL: Diagnostic message: <something>" seems redundant to me. Maybe >>>>> drop that prefix? It should be clear from the context that this is a >>>>> message from the LDAP layer. >>>> >>>> I think making it visible that the message comes from LDAP (rather than >>>> Postgres or anything else) is valuable. How about this? >>>> >>>> LOG: could not start LDAP TLS session: Protocol error >>>> DETAIL: LDAP diagnostics: unsupported extended operation. >>>> >>> +1, pretty neat. > > Here is a new version adopting Alvaro's wording. I'll set this back > to "Needs review" status. > Thanks for the updated patches. Looks good to me. The patch applies cleanly on the latest HEAD, compiles without any errors or warnings and make check passes. Marking this as ready for committer. -- Best Wishes, Ashutosh Bapat EnterpriseDB Corporation The Postgres Database Company -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
I think the ldap_unbind() changes should be in a separate preliminary patch to be committed separately and backpatched. The other bits looks fine, with nitpicks 1. please move the new support function to the bottom of the section dedicated to LDAP, and include a prototype 2. please wrap lines longer than 80 chars, other than error message strings. (I don't know why this file plays fast & loose with project-wide line length rules, but I also see no reason to continue doing it.) -- Álvaro Herrera https://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
BTW I added --with-ldap and --with-pam to the configure line for the reports in coverage.postgresql.org and the % covered in auth.c went from 24% to 18.9% (from very bad to terribly sad). -- Álvaro Herrera https://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
On Thu, Sep 14, 2017 at 10:21 AM, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote: > BTW I added --with-ldap and --with-pam to the configure line for the > reports in coverage.postgresql.org and the % covered in auth.c went from > 24% to 18.9% (from very bad to terribly sad). Improved code coverage is becoming a fad. -- Robert Haas EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
On Fri, Sep 15, 2017 at 1:38 AM, Robert Haas <robertmhaas@gmail.com> wrote: > On Thu, Sep 14, 2017 at 10:21 AM, Alvaro Herrera > <alvherre@alvh.no-ip.org> wrote: >> BTW I added --with-ldap and --with-pam to the configure line for the >> reports in coverage.postgresql.org and the % covered in auth.c went from >> 24% to 18.9% (from very bad to terribly sad). > > Improved code coverage is becoming a fad. I don't think that this is necessarily bad for authentication. I mean, you write something and make sure that it actually works, but you also make sure that the code you have is *compatible* with libraries the code is linking to. The second part is important to me. For example with the SSL tests we can know if there is a breakage, and if this involves our code of OpenSSL's say after a version upgrade. Now I think as well that it is not completely the role of this patch to provide more test coverage for LDAP now because infrastructure lacks. One requirement that is showing up as a remark from Peter E (from the pg_receivewal --endpos thread https://www.postgresql.org/message-id/49b529c1-0f44-d905-b33c-005ec0114d09@2ndquadrant.com), is that we should have a simple perl module allowing to find easily if Postgres is compiled with a given dependency or not so as tests can decide if they have to be skipped or run. -- Michael -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
On Fri, Sep 15, 2017 at 2:12 AM, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote: > I think the ldap_unbind() changes should be in a separate preliminary > patch to be committed separately and backpatched. OK, here it is split into two patches. > The other bits looks fine, with nitpicks > > 1. please move the new support function to the bottom of the section > dedicated to LDAP, and include a prototype OK. > 2. please wrap lines longer than 80 chars, other than error message > strings. (I don't know why this file plays fast & loose with > project-wide line length rules, but I also see no reason to continue > doing it.) Done for all lines I touched in the patch. Thanks for the review! -- Thomas Munro http://www.enterprisedb.com -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Attachment
On 9/14/17 10:21, Alvaro Herrera wrote: > BTW I added --with-ldap and --with-pam to the configure line for the > reports in coverage.postgresql.org and the % covered in auth.c went from > 24% to 18.9% (from very bad to terribly sad). You can add src/test/ldap/ now to make up for some of that. -- Peter Eisentraut http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Peter Eisentraut wrote: > On 9/14/17 10:21, Alvaro Herrera wrote: > > BTW I added --with-ldap and --with-pam to the configure line for the > > reports in coverage.postgresql.org and the % covered in auth.c went from > > 24% to 18.9% (from very bad to terribly sad). > > You can add src/test/ldap/ now to make up for some of that. I did that (much to the chagrin of the sysadmin crew, because we now have a new daemon on that machine -- sorry about that), and coverage of auth.c jumped to 28%. However, if you look at the report for that file you can see that a lot of code is not even compiled in, yet. https://coverage.postgresql.org/src/backend/libpq/auth.c.gcov.html Clearly we have a lot of work to do in that area ... -- Álvaro Herrera https://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
On 9/15/17 08:43, Thomas Munro wrote:
> On Fri, Sep 15, 2017 at 2:12 AM, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:
>> I think the ldap_unbind() changes should be in a separate preliminary
>> patch to be committed separately and backpatched.
>
> OK, here it is split into two patches.
I've looked this over.
In the 0001 patch, I would move the ldap_unbind() calls after the
ereport(LOG) calls. We do all the other resource cleanup (pfree() etc.)
after the ereport() calls, so it would be weird to do this one
differently. Also, in the second patch you move one of the
ldap_unbind() calls down anyway.
In the 0002 patch, I think this is a bit repetitive and could be
refactored even more. The end result could look like
ereport(LOG, (errmsg("blah"), errdetail_for_ldap(ldap))); ldap_unbind(ldap);
--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
On Wed, Sep 20, 2017 at 7:57 AM, Peter Eisentraut
<peter.eisentraut@2ndquadrant.com> wrote:
> In the 0001 patch, I would move the ldap_unbind() calls after the
> ereport(LOG) calls. We do all the other resource cleanup (pfree() etc.)
> after the ereport() calls, so it would be weird to do this one
> differently. Also, in the second patch you move one of the
> ldap_unbind() calls down anyway.
Fair point. In that case there are a few others we should consider
moving down too for consistency, like in the attached.
> In the 0002 patch, I think this is a bit repetitive and could be
> refactored even more. The end result could look like
>
> ereport(LOG,
> (errmsg("blah"),
> errdetail_for_ldap(ldap)));
> ldap_unbind(ldap);
Thanks, that is much tidier. Done that way in the attached.
Here also is a small addition to your TAP test which exercises the
non-NULL code path because slapd rejects TLS by default with a
diagnostic message. I'm not sure if this is worth adding, since it
doesn't actually verify that the code path is reached (though you can
see that it is from the logs).
--
Thomas Munro
http://www.enterprisedb.com
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Attachment
On 9/24/17 07:00, Thomas Munro wrote: > Fair point. In that case there are a few others we should consider > moving down too for consistency, like in the attached. > Thanks, that is much tidier. Done that way in the attached. > > Here also is a small addition to your TAP test which exercises the > non-NULL code path because slapd rejects TLS by default with a > diagnostic message. I'm not sure if this is worth adding, since it > doesn't actually verify that the code path is reached (though you can > see that it is from the logs). Committed. -- Peter Eisentraut http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
On Fri, Oct 13, 2017 at 3:59 PM, Peter Eisentraut <peter.eisentraut@2ndquadrant.com> wrote: > On 9/24/17 07:00, Thomas Munro wrote: >> Fair point. In that case there are a few others we should consider >> moving down too for consistency, like in the attached. > >> Thanks, that is much tidier. Done that way in the attached. >> >> Here also is a small addition to your TAP test which exercises the >> non-NULL code path because slapd rejects TLS by default with a >> diagnostic message. I'm not sure if this is worth adding, since it >> doesn't actually verify that the code path is reached (though you can >> see that it is from the logs). > > Committed. Thanks, and thanks also for follow-up commit 7d1b8e75. Looks like the new macro arrived in OpenLDAP 2.4 but RHEL5 shipped with 2.3. -- Thomas Munro http://www.enterprisedb.com -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers