[KLUG Members] debug ldap failure

[Adam Williams]

> I wanted to start playing with my ldap goals and found this nice article 
> on ldap and exim...it's just something to start playing with at the moment.

I don't know anything about exim,  but if you've seen one MTA you've
seen 'em all.

> I have courier and ldap set up. I managed to add a user and set up the 
> users mailbox. Once you have courier set up to authenticate to ldap the 
> instructions have a line to test telnetting in with the ldap account, 
> which is failing.

Is courier calling out to PAM, using saslauthd's direct LDAP support, or
attempting to perform it's own bind test?

> Now to debug this the author suggests running  slapd from the command 
> line like so:
> slapd -d1
> Now when I do this and try to telnet to port 143 on another terminal I 
> see all kinds of work being done in the ldap query, but I am having a 
> really hard time making heads or tails of it.

Yep, alot of it is noise, makes it hard to pick out the relevant parts.
I think a debug level other than "1" would be more appopriate.

I'd start at 256.

Do you see anything in /var/log/messages or maillog from courier about
why it thinks the authentication failed?  I know that cyrus imapd puts
out rather helpful messages (truly shocking!).

> Here is the output when I try to auth in its entirety.
> ldap_pvt_gethostbyname_a: host=localhost, r=0
> put_filter: "(objectclass=*)"
> put_filter: simple
> put_simple_filter: "objectclass=*"

A rather scarey filter.  Seems you should skinny this down somehow.

> ber_scanf fmt (m) ber:
> connection_get(12): got connid=0
> connection_read(12): checking for input on id=0
> ber_get_next
> ber_get_next: tag 0x30 len 54 contents:
> ber_get_next
> ber_get_next on fd 12 failed errno=11 (Resource temporarily unavailable)

This is cause by blocking on the network transaction,  perfectly normal.

> do_bind
> ber_scanf fmt ({imt) ber:
> ber_scanf fmt (m}) ber:
>  >>> dnPrettyNormal: <cn=admin,dc=home,dc=ricksweb,dc=com>
> => ldap_bv2dn(cn=admin,dc=home,dc=ricksweb,dc=com,0)
> <= ldap_bv2dn(cn=admin,dc=home,dc=ricksweb,dc=com,0)=0
> => ldap_dn2bv(272)
> <= ldap_dn2bv(cn=admin,dc=home,dc=ricksweb,dc=com,272)=0
> => ldap_dn2bv(272)
> <= ldap_dn2bv(cn=admin,dc=home,dc=ricksweb,dc=com,272)=0
> <<< dnPrettyNormal: <cn=admin,dc=home,dc=ricksweb,dc=com>, 
> <cn=admin,dc=home,dc=ricksweb,dc=com>
> do_bind: version=2 dn="cn=admin,dc=home,dc=ricksweb,dc=com" method=128
> send_ldap_result: conn=0 op=0 p=2
> send_ldap_response: msgid=1 tag=97 err=2
> ber_flush: 52 bytes to sd 12
> connection_get(12): got connid=0
> connection_read(12): checking for input on id=0
> ber_get_next
> ber_get_next: tag 0x30 len 5 contents:
> deferring operation
> connection_get(12): got connid=0
> connection_read(12): checking for input on id=0
> ber_get_next
> ber_get_next on fd 12 failed errno=0 (Success)
> connection_read(12): input error=-2 id=0, closing.
> connection_closing: readying conn=0 sd=12 for close
> connection_close: deferring conn=0 sd=12
> connection_resched: attempting closing conn=0 sd=12
> connection_close: conn=0 sd=12