[Date Prev][Date Next] [Chronological] [Thread] [Top]

Parsing Debug Output



Hi All,

I'm trying to figure out why Courier-IMAP is unable to authenticate to my OpenLDAP 2.2.17 server and am having trouble parsing the debug output. It looks like the bind and authentication is successful:

conn=5 op=1 BIND dn="uid=testuser,ou=people,dc=example,dc=com" mech=SIMPLE ssf=0
do_bind: v3 bind: "uid=testuser,ou=people,dc=example,dc=com" to "uid=testuser,ou=people,dc=example,dc=com"
send_ldap_result: conn=5 op=1 p=3
send_ldap_result: err=0 matched="" text=""
send_ldap_response: msgid=2 tag=97 err=0


And then, after a bit more debugging output there's this:

connection_get(18)
connection_get(18): got connid=5
connection_read(18): checking for input on id=5
ber_get_next
tls_read: want=5, got=5
0000: 17 03 01 00 20 ....
tls_read: want=32, got=32
0000: 05 46 d6 5d 4f ae 5f af 3a be 12 7a dc f6 ff fa .F.]O._.:..z....
0010: 8d c3 5e b5 7e 94 0c 57 75 bd 20 a1 69 35 11 5b ..^.~..Wu. .i5.[
tls_read: want=5, got=5
0000: 17 03 01 00 20 ....
tls_read: want=32, got=32
0000: e8 99 e5 d2 71 12 08 4b 22 fa 85 2e 39 81 b5 a3 ....q..K"...9...
0010: 5d 56 2e 0d ad d5 b7 70 f4 5a 2d 04 a9 c1 59 c5 ]V.....p.Z-...Y.
ldap_read: want=8, got=7
0000: 30 05 02 01 03 42 00 0....B.
ber_get_next: tag 0x30 len 5 contents:
ber_dump: buf=0x08186b10 ptr=0x08186b10 end=0x08186b15 len=5
0000: 02 01 03 42 00 ...B.
ber_get_next
tls_read: want=5, got=5
0000: 15 03 01 00 20 ....
tls_read: want=32, got=32
0000: 58 f5 45 0d 80 31 b9 cf b2 df ea 78 94 47 24 ac X.E..1.....x.G$.
0010: 27 79 99 09 45 75 bb ce b1 9f 8f 06 50 a0 3d 95 'y..Eu......P.=.
TLS trace: SSL3 alert read:warning:close notify
ldap_read: want=8, got=0
ber_get_next on fd 18 failed errno=0 (Undefined error: 0)


This looks like where the failure happens, but I have no idea what errno=0 could be (undefined error??) From there, the client unbinds:

connection_read(18): input error=-2 id=5, closing.
connection_closing: readying conn=5 sd=18 for close
connection_close: deferring conn=5 sd=18
do_unbind
conn=5 op=2 UNBIND
connection_resched: attempting closing conn=5 sd=18
connection_close: conn=5 sd=18
daemon: removing 18
conn=5 fd=18 closed

Any suggestions as to what might be causing this failure would be greatly appreciated. I can bind, authenticate, and search using ldapsearch, so I'm not at all sure what might be happening here.

Many TIA,

David