Quoth Bob Miller (27 Feb 2014, 17:58):
have you verified from you AD logs that dovecot is sending the same
thing as your ldapsearch?
I have limited access to my AD server. I've verified everything I can
using ldapsearch, and I have tcpdump'ed dovecot's LDAP authentication to
it. This is what I see:
---- Snip, IMAP user session ----
$ telnet localhost 143
[...]
* OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE
IDLE AUTH=PLAIN AUTH=LOGIN] Dovecot ready.
a1 login js passphrase
* OK Waiting for authentication process to respond..
* BYE Disconnected for inactivity during authentication.
Connection closed by foreign host.
--- Snip ---
--- Snip, Dovecot log ---
Feb 28 11:34:48 auth: Debug: auth client connected (pid=77528)
Feb 28 11:34:52 auth: Debug: client in:
AUTH 1 PLAIN service=imap secured session=Raj3/HTzkgB/AAAB lip=127.0.0.1 rip=127.0.0.1 lport=143 rport=24210 resp=<hidden>
Feb 28 11:34:52 auth: Debug: ldap(js,127.0.0.1,<Raj3/HTzkgB/AAAB>): bind
search: base=dc=office,dc=on2it,dc=net
filter=(&(objectClass=person)(sAMAccountName=js))
=== LONG PAUSE ===
Feb 28 11:37:48 imap-login: Info: Disconnected: Inactivity during
authentication (disconnected while authenticating, waited 176 secs):
user=<>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured,
session=<Raj3/HTzkgB/AAAB>
Feb 28 11:38:37 auth: Debug: ldap(js,127.0.0.1,<Raj3/HTzkgB/AAAB>):
result: sAMAccountName=js; sAMAccountName unused
Feb 28 11:38:37 auth: Debug: ldap(js,127.0.0.1,<Raj3/HTzkgB/AAAB>):
result: sAMAccountName=js
Feb 28 11:38:37 auth: Error: PLAIN(js,127.0.0.1,<Raj3/HTzkgB/AAAB>):
Request 77528.1 timed out after 225 secs, state=1
Feb 28 11:38:37 auth: Debug: client in: CANCEL 1
Feb 28 11:38:39 auth: Debug: client passdb out: FAIL 1 user=js temp
--- Snip ---
--- Snip, tcpdump of Dovecot LDAP session (commented, omitting tcp
setup/teardown, passphrases replaced ---
#
# Immediately after issuing the IMAP login.
# We see the successful bind here
# We also see a successful user DN lookup
#
11:34:52.687896 IP (tos 0x0, ttl 64, id 42561, offset 0, flags [DF],
proto TCP (6), length 183)
172.17.50.13.53438 > 172.17.10.2.389: Flags [P.], seq 100:231, ack
23, win 1040, options [nop,nop,TS val 596440913 ecr 123872255], length
131
.....A@.@.....2
.....(......W...........
#..Q.b#.0.....`{....eCN=Jabber Server LDAP Koppeling,OU=Service
Accounts,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net..passphrase
11:34:52.689710 IP (tos 0x0, ttl 127, id 5023, offset 0, flags [DF],
proto TCP (6), length 74)
172.17.10.2.389 > 172.17.50.13.53438: Flags [P.], seq 23:45, ack
231, win 258, options [nop,nop,TS val 123875052 ecr 596440913], length
22
E..J..@...S...
.......W(..6....c......
.b..#..Q0........a.....
......
11:34:52.689816 IP (tos 0x0, ttl 64, id 42564, offset 0, flags [DF],
proto TCP (6), length 166)
172.17.50.13.53438 > 172.17.10.2.389: Flags [P.], seq 231:345, ack
45, win 1040, options [nop,nop,TS val 596440913 ecr 123875052], length
114
.....D@.@.....2
.....(..6...m...........
#..Q.b..0p...ck..dc=office,dc=on2it,dc=net
..
............-....objectClass..person....sAMAccountName..js0...sAMAccountName
11:34:52.690695 IP (tos 0x0, ttl 127, id 5024, offset 0, flags [DF],
proto TCP (6), length 488)
172.17.10.2.389 > 172.17.50.13.53438: Flags [P.], seq 45:481, ack
345, win 258, options [nop,nop,TS val 123875053 ecr 596440913], length
436
E.....@...R>..
.......m(..............
.b..#..Q0........d....v.NCN=Jeroen
Scheerder,OU=Users,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net0....
0.......sAMAccountName1.......js0....]...s....T.Rldap://DomainDnsZones.office.on2it.net/DC=DomainDnsZones,DC=office,DC=on2it,DC=net0....]...s....T.Rldap://ForestDnsZones.office.on2it.net/DC=ForestDnsZones,DC=office,DC=on2it,DC=net0....M...s....D.Bldap://office.on2it.net/CN=Configuration,DC=office,DC=on2it,DC=net0........e.....
......
#
# We've obtained the expected result from our query.
#
=== Pause, and we get the "OK Waiting for authentication process to
respond.." response in sync with... ===
11:34:52.784578 IP (tos 0x0, ttl 64, id 42568, offset 0, flags [DF],
proto TCP (6), length 52)
172.17.50.13.53438 > 172.17.10.2.389: Flags [.], seq 345, ack 481,
win 1037, options [nop,nop,TS val 596441011 ecr 123875053], length 0
...4.H@.@..J..2
.X..........!...
#....b..
=== LONG PAUSE ===
#
#
# Then 1m45s after authentication, we *do* see the expected LDAP auth
attempt ("finally")
# Why the delay?
#
11:38:37.825390 IP (tos 0x0, ttl 64, id 42651, offset 0, flags [DF],
proto TCP (6), length 152)
172.17.50.13.53438 > 172.17.10.2.389: Flags [P.], seq 345:445, ack
481, win 1040, options [nop,nop,TS val 596666051 ecr 123875053], length
100
......@.@.....2
.....(......!...........
#.f..b..0b...`]....NCN=Jeroen
Scheerder,OU=Users,OU=Netherlands,OU=ON2IT,DC=office,DC=on2it,DC=net..passphrase
11:38:37.827354 IP (tos 0x0, ttl 127, id 9765, offset 0, flags [DF],
proto TCP (6), length 74)
172.17.10.2.389 > 172.17.50.13.53438: Flags [P.], seq 481:503, ack
445, win 258, options [nop,nop,TS val 123897567 ecr 596666051], length
22
E..J&%@...AW..
.......!(..............
.b..#.f.0........a.....
......
11:38:37.924458 IP (tos 0x0, ttl 64, id 42653, offset 0, flags [DF],
proto TCP (6), length 52)
172.17.50.13.53438 > 172.17.10.2.389: Flags [.], seq 445, ack 503,
win 1040, options [nop,nop,TS val 596666151 ecr 123897567], length 0
...4..@.@.....2
.....(......7.....X.....
#.g'.b..
11:39:38.119947 IP (tos 0x0, ttl 64, id 42656, offset 0, flags [DF],
proto TCP (6), length 59)
172.17.50.13.53438 > 172.17.10.2.389: Flags [P.], seq 445:452, ack
503, win 1040, options [nop,nop,TS val 596726346 ecr 123897567], length
7
...;..@.@.....2
.....(......7....._.....
B.RJ.b..0...
11:39:38.120029 IP (tos 0x0, ttl 64, id 42657, offset 0, flags [DF],
proto TCP (6), length 52)
172.17.50.13.53438 > 172.17.10.2.389: Flags [F.], seq 452, ack 503,
win 1040, options [nop,nop,TS val 596726346 ecr 123897567], length 0
...4..@.@.....2
.....(......7.....X.....
#.RJ.b..
11:39:38.120173 IP (tos 0x0, ttl 64, id 42658, offset 0, flags [DF],
proto TCP (6), length 59)
172.17.50.13.64429 > 172.17.10.2.389: Flags [P.], seq
1491639458:1491639465, ack 1700255044, win 1040, options [nop,nop,TS val
596726346 ecr 123849133], length 7
...;..@.@.....2
.....X...eW.D....._.....
#.RJ.a..0....B.
--- Snip ---
