Quoth Jeroen Scheerder (28 Feb 2014, 11:57):
tcpdump of Dovecot LDAP session
I've since captured to a file, and used wireshark to get a bit more grasp on the LDAP transactions:
js@tchotchke:s003(31) tshark -o tcp.check_checksum:FALSE -ta -r Downloads/dc2.pcap 1 13:14:37.274193 172.17.50.13 -> 172.17.10.2 LDAP 197 bindRequest(7) "CN=Jabber Server LDAP Koppeling,OU=Service Accounts,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net" simple 2 13:14:37.276072 172.17.10.2 -> 172.17.50.13 LDAP 88 bindResponse(7) success 3 13:14:37.276160 172.17.50.13 -> 172.17.10.2 LDAP 180 searchRequest(8) "dc=office,dc=on2it,dc=net" wholeSubtree 4 13:14:37.276965 172.17.10.2 -> 172.17.50.13 LDAP 502 searchResEntry(8) "CN=Jeroen Scheerder,OU=Users,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net" | searchResRef(8) | searchResRef(8) | searchResRef(8) | searchResDone(8) success 5 13:14:37.372560 172.17.50.13 -> 172.17.10.2 TCP 66 49416 > 389 [ACK] Seq=246 Ack=459 Win=1037 Len=0 TSval=602425599 TSecr=124473537 6 13:18:22.424078 172.17.50.13 -> 172.17.10.2 LDAP 166 bindRequest(12) "CN=Jeroen Scheerder,OU=Users,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net" simple 7 13:18:22.426516 172.17.10.2 -> 172.17.50.13 LDAP 88 bindResponse(12) success
So from the looks of it all is hunky-dory, LDAP-wise.
- An authenticated bind (using a service account) as intended is done in frame 1
- Successfully, frame 2 indicates
- The DN is searched successfully (frames 3, 4)
- Frame 5 (length 0) is some kind of TCP keepalive, performed by the LDAP client library, or so I suspect
- Then we have a succesful bind to the user DN (as obtained in frame 4), we see this in frames 6 and 7
- But frames 6 and 7 occur after a long, long delay, as shown with relative timing:
js@tchotchke:s003(32) tshark -o tcp.check_checksum:FALSE -tr -r Downloads/dc2.pcap 1 0.000000 172.17.50.13 -> 172.17.10.2 LDAP 197 bindRequest(7) "CN=Jabber Server LDAP Koppeling,OU=Service Accounts,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net" simple 2 0.001879 172.17.10.2 -> 172.17.50.13 LDAP 88 bindResponse(7) success 3 0.001967 172.17.50.13 -> 172.17.10.2 LDAP 180 searchRequest(8) "dc=office,dc=on2it,dc=net" wholeSubtree 4 0.002772 172.17.10.2 -> 172.17.50.13 LDAP 502 searchResEntry(8) "CN=Jeroen Scheerder,OU=Users,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net" | searchResRef(8) | searchResRef(8) | searchResRef(8) | searchResDone(8) success 5 0.098367 172.17.50.13 -> 172.17.10.2 TCP 66 49416 > 389 [ACK] Seq=246 Ack=459 Win=1037 Len=0 TSval=602425599 TSecr=124473537 6 225.149885 172.17.50.13 -> 172.17.10.2 LDAP 166 bindRequest(12) "CN=Jeroen Scheerder,OU=Users,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net" simple 7 225.152323 172.17.10.2 -> 172.17.50.13 LDAP 88 bindResponse(12) success
I think it's just weird, and I'm beginning to guess a little source dive will do me some good. :-)