[Dovecot] LDAP auth_bind hangs and times out
I have _almost_ got Dovecot working! One little snag...
My users login using their email address as username. Each domain hastheir own LDAP subtree. Each user has an entry in the ou=users subtree of the domain subtree, and has a mail: field (inetOrgPerson) listing their email address/login name. I am trying to use auth_bind: when I login with jackmc@lorentz.com, dovecot should search for mail=jackmc@lorentz.com in the onelevel below ou=users,dc=lorentz,dc=com and find me as "cn=Jack McKinney,ou=users,dc=lorentz,dc=com". I have created an entry in LDAP (varmail) that should be able to do this query. Indeed, from the command line, it works:
ldapsearch -h ldap.lrtz -b 'ou=users, dc=lorentz, dc=com' -D 'cn=varmail,ou=users,dc=lorentz,dc=com' -x -W -s onelevel '(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com))' Enter LDAP Password: # extended LDIF # # LDAPv3 # base <ou=users, dc=lorentz, dc=com> with scope oneLevel # filter: (&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com)) # requesting: ALL #
# Jack McKinney, users, lorentz.com dn: cn=Jack McKinney,ou=users,dc=lorentz,dc=com objectClass: top objectClass: person objectClass: organizationalPerson objectClass: inetOrgPerson cn: Jack McKinney givenName: Jack McKinney sn: McKinney mail: jackmc@lorentz.com
# search result search: 2 result: 0 Success
# numResponses: 2 # numEntries: 1
' However, it appears that dovecot performs the above query successfully, but then never uses the password and retrieved DN to attempt to bind and authenticate the user. Instead, it just times out.
My dovecot-ldap.conf is:hosts = ldap.lrtz dn = cn=varmail,ou=users,dc=lorentz,dc=com dnpass = ********* ldap_version = 3 auth_bind = yes pass_filter = (&(objectClass=inetOrgPerson)(mail=%Lu)) base = ou=users, dc=%Dd scope = onelevel
The dovecot log shows:Apr 3 08:13:21 fourier dovecot: auth(default): new auth connection: pid=15774 Apr 3 08:13:30 fourier dovecot: auth(default): client in: AUTH^I1^IPLAIN^Iservice=IMAP^Isecured^Ilip=x.x.x.x^Irip=y.y.y.y^Iresp=<hidden> Apr 3 08:13:30 fourier dovecot: auth(default): ldap(jackmc@lorentz.com,y.y.y.y): bind search: base=ou=users, dc=lorentz,dc=com filter=(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com)) Apr 3 08:16:30 fourier dovecot: imap-login: Disconnected: Inactivity: method=PLAIN, rip=y.y.y.y, lip=x.x.x.x, TLS
The OpenLDAP log shows that the query is received and that it returns amatch:
Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SRCH base="ou=users,dc=lorentz,dc=com" scope=1 deref=0 filter="(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com))" Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SRCH attr=uid Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SEARCH RESULT tag=101 err=0 nentries=1 text=
When I do the query from the command line, there is an additional pairof lines:
Apr 3 08:18:10 fourier slapd[16106]: conn=22 op=2 UNBIND Apr 3 08:18:10 fourier slapd[16106]: conn=22 fd=28 closed
I thus conclude that Dovecot is not closing the connection.-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform still more excellently." -Mario Cuomo, on the lack of a clock in baseball
Red Hat Linux release 7.2 (Enigma) OpenLDAP 2.3.38 Dovecot 1.0.12
On Thu, 2008-04-03 at 23:43 +0300, Timo Sirainen wrote:
On Thu, 2008-04-03 at 09:46 -0500, Jack McKinney wrote:
I have _almost_ got Dovecot working! One little snag...
What version?
-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform still more excellently." -Mario Cuomo, on the lack of a clock in baseball
On Thu, 2008-04-03 at 09:46 -0500, Jack McKinney wrote:
ldap(jackmc@lorentz.com,y.y.y.y): bind search: base=ou=users, dc=lorentz,dc=com filter=(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com))
Here should be a line saying "result: <returned fields>". Since there isn't, Dovecot never appears to receive the reply. You could verify this by adding to src/auth/db-ldap.c ldap_input() around line 372:
msgid = ldap_msgid(res);// added line: i_info("LDAP: Received reply %d", msgid);
msgid might be the same as this tag:
Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SEARCH RESULT tag=101
But I'm not sure. If you anyway receive a reply after the "bind search", there's something wrong in Dovecot's error handling.
I am not sure that I understand you, here. Are you saying that I ammissing something from my configuration after the "filter=" line like a pass_attrs listing fields to return? I do not have one, as there are no fields that I need returned. The only thing that dovecot needs is the DN of the match itself.
According to http://wiki.dovecot.org/AuthDatabase/LDAP ,"The pass_filter is used to find the LDAP entry, and the DN is taken from the reply."
Should I add a dummy pass_attrs entry? What field is safe to grab?E.g., I do not want to overwrite "user"...
On Thu, 2008-04-03 at 23:59 +0300, Timo Sirainen wrote:
On Thu, 2008-04-03 at 09:46 -0500, Jack McKinney wrote:
ldap(jackmc@lorentz.com,y.y.y.y): bind search: base=ou=users, dc=lorentz,dc=com filter=(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com))
Here should be a line saying "result: <returned fields>". Since there isn't, Dovecot never appears to receive the reply. You could verify this by adding to src/auth/db-ldap.c ldap_input() around line 372:
msgid = ldap_msgid(res);// added line: i_info("LDAP: Received reply %d", msgid);
msgid might be the same as this tag:
Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SEARCH RESULT tag=101
But I'm not sure. If you anyway receive a reply after the "bind search", there's something wrong in Dovecot's error handling.
-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform still more excellently." -Mario Cuomo, on the lack of a clock in baseball
No, I mean this appears to be a bug somewhere since a LDAP request is
sent, but it's never received by Dovecot. So either Dovecot does
something wrong, OpenLDAP library does something wrong or your network
blocks the reply for some reason. For example on my system:
auth(default): ldap(foo,127.0.0.1): bind search: base=... auth(default): ldap(foo,127.0.0.1): result: uid(user)=foo
If Dovecot receives a reply to the "bind search", it logs the "result"
line, which your logs show is missing.
On Apr 4, 2008, at 12:06 AM, Jack McKinney wrote:
I am not sure that I understand you, here. Are you saying that I am missing something from my configuration after the "filter=" line
like a pass_attrs listing fields to return? I do not have one, as there
are no fields that I need returned. The only thing that dovecot needs is the DN of the match itself.According to http://wiki.dovecot.org/AuthDatabase/LDAP ,
"The pass_filter is used to find the LDAP entry, and the DN is taken from the reply."
Should I add a dummy pass_attrs entry? What field is safe to grab? E.g., I do not want to overwrite "user"...
On Thu, 2008-04-03 at 23:59 +0300, Timo Sirainen wrote:
On Thu, 2008-04-03 at 09:46 -0500, Jack McKinney wrote:
ldap(jackmc@lorentz.com,y.y.y.y): bind search: base=ou=users, dc=lorentz,dc=com filter=(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com))
Here should be a line saying "result: <returned fields>". Since there isn't, Dovecot never appears to receive the reply. You could verify
this by adding to src/auth/db-ldap.c ldap_input() around line 372:msgid = ldap_msgid(res);// added line: i_info("LDAP: Received reply %d", msgid);
msgid might be the same as this tag:
Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SEARCH RESULT
tag=101But I'm not sure. If you anyway receive a reply after the "bind
search", there's something wrong in Dovecot's error handling.-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform
still more excellently." -Mario Cuomo, on the lack of a clock in baseball
I added the i_info line below and copied over the new dovecot-auth. Itis hanging at the same place; the "LDAP: Received reply" line is not in the log. Again, exactly 180 seconds after the last log entry, the connection drops. However, that line _does_ appear in the log back at startup...
Apr 3 15:19:05 fourier dovecot: Dovecot v1.0.12 starting up Apr 3 15:19:05 fourier dovecot: auth(default): LDAP: Received reply 1 Apr 3 15:19:06 fourier dovecot: auth(default): new auth connection: pid=30934 Apr 3 15:19:06 fourier dovecot: auth(default): new auth connection: pid=30935 Apr 3 15:19:06 fourier dovecot: auth(default): new auth connection: pid=30936 Apr 3 15:19:21 fourier dovecot: auth(default): new auth connection: pid=30974 Apr 3 15:19:28 fourier dovecot: auth(default): client in: AUTH^I1^IPLAIN^Iservice=IMAP^Isecured^Ilip=x.x.x.x^Irip=y.y.y.y^Iresp=<hidden> Apr 3 15:19:28 fourier dovecot: auth(default): ldap(jackmc@lorentz.com,y.y.y.y): bind search: base=ou=users, dc=lorentz,dc=com filter=(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com)) Apr 3 15:22:28 fourier dovecot: imap-login: Disconnected: Inactivity: method=PLAIN, rip=y.y.y.y, lip=x.x.x.x, TLS
On Fri, 2008-04-04 at 00:11 +0300, Timo Sirainen wrote:
No, I mean this appears to be a bug somewhere since a LDAP request is
sent, but it's never received by Dovecot. So either Dovecot does
something wrong, OpenLDAP library does something wrong or your network
blocks the reply for some reason. For example on my system:auth(default): ldap(foo,127.0.0.1): bind search: base=... auth(default): ldap(foo,127.0.0.1): result: uid(user)=foo
If Dovecot receives a reply to the "bind search", it logs the "result"
line, which your logs show is missing.On Apr 4, 2008, at 12:06 AM, Jack McKinney wrote:
I am not sure that I understand you, here. Are you saying that I am missing something from my configuration after the "filter=" line
like a pass_attrs listing fields to return? I do not have one, as there
are no fields that I need returned. The only thing that dovecot needs is the DN of the match itself.According to http://wiki.dovecot.org/AuthDatabase/LDAP ,
"The pass_filter is used to find the LDAP entry, and the DN is taken from the reply."
Should I add a dummy pass_attrs entry? What field is safe to grab? E.g., I do not want to overwrite "user"...
On Thu, 2008-04-03 at 23:59 +0300, Timo Sirainen wrote:
On Thu, 2008-04-03 at 09:46 -0500, Jack McKinney wrote:
ldap(jackmc@lorentz.com,y.y.y.y): bind search: base=ou=users, dc=lorentz,dc=com filter=(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com))
Here should be a line saying "result: <returned fields>". Since there isn't, Dovecot never appears to receive the reply. You could verify
this by adding to src/auth/db-ldap.c ldap_input() around line 372:msgid = ldap_msgid(res);// added line: i_info("LDAP: Received reply %d", msgid);
msgid might be the same as this tag:
Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SEARCH RESULT
tag=101But I'm not sure. If you anyway receive a reply after the "bind
search", there's something wrong in Dovecot's error handling.-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform
still more excellently." -Mario Cuomo, on the lack of a clock in baseball
-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform still more excellently." -Mario Cuomo, on the lack of a clock in baseball
Hmmm... what versions of OpenLDAP and Dovecot are you using? I notethat you got a result of "uid(user)=foo", from which I guess that you had pass_attrs set to user=uid or some such. I tried adding a pass_attrs of user=mail, in case the problem is that without requested fields, the code in dovecot doesn't return anything. It didn't work; it still hangs and times out after 3 minutes.
On Fri, 2008-04-04 at 00:11 +0300, Timo Sirainen wrote:
No, I mean this appears to be a bug somewhere since a LDAP request is
sent, but it's never received by Dovecot. So either Dovecot does
something wrong, OpenLDAP library does something wrong or your network
blocks the reply for some reason. For example on my system:auth(default): ldap(foo,127.0.0.1): bind search: base=... auth(default): ldap(foo,127.0.0.1): result: uid(user)=foo
If Dovecot receives a reply to the "bind search", it logs the "result"
line, which your logs show is missing.On Apr 4, 2008, at 12:06 AM, Jack McKinney wrote:
I am not sure that I understand you, here. Are you saying that I am missing something from my configuration after the "filter=" line
like a pass_attrs listing fields to return? I do not have one, as there
are no fields that I need returned. The only thing that dovecot needs is the DN of the match itself.According to http://wiki.dovecot.org/AuthDatabase/LDAP ,
"The pass_filter is used to find the LDAP entry, and the DN is taken from the reply."
Should I add a dummy pass_attrs entry? What field is safe to grab? E.g., I do not want to overwrite "user"...
On Thu, 2008-04-03 at 23:59 +0300, Timo Sirainen wrote:
On Thu, 2008-04-03 at 09:46 -0500, Jack McKinney wrote:
ldap(jackmc@lorentz.com,y.y.y.y): bind search: base=ou=users, dc=lorentz,dc=com filter=(&(objectClass=inetOrgPerson)(mail=jackmc@lorentz.com))
Here should be a line saying "result: <returned fields>". Since there isn't, Dovecot never appears to receive the reply. You could verify
this by adding to src/auth/db-ldap.c ldap_input() around line 372:msgid = ldap_msgid(res);// added line: i_info("LDAP: Received reply %d", msgid);
msgid might be the same as this tag:
Apr 3 08:13:30 fourier slapd[14039]: conn=7 op=3 SEARCH RESULT
tag=101But I'm not sure. If you anyway receive a reply after the "bind
search", there's something wrong in Dovecot's error handling.-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform
still more excellently." -Mario Cuomo, on the lack of a clock in baseball
-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform still more excellently." -Mario Cuomo, on the lack of a clock in baseball
On Apr 4, 2008, at 12:50 AM, Jack McKinney wrote:
Hmmm... what versions of OpenLDAP and Dovecot are you using?
A lot of people have them working with different LDAP versions. I've
Debian unstable's OpenLDAP 2.1.30.dfsg-13.5.
I note that you got a result of "uid(user)=foo", from which I guess that you had pass_attrs set to user=uid or some such. I tried adding a pass_attrs of user=mail, in case the problem is that without requested fields, the code in dovecot doesn't return anything. It didn't work; it still hangs and times out after 3 minutes.
Check with wireshark if it shows that LDAP server really sends the
reply. Then you could find out if it's a problem on the OpenLDAP
client side or server/network side.
Is wireshark something like tcpdump?
My LDAP server and my Dovecot server are on the same machine, and theLDAP server claims to send the response. Since the same query from a CLI tool (ldapsearch) creates the same LDAP log entries, I suspect that OpenLDAP is indeed sending, but Dovecot is not receiving...
On Fri, 2008-04-04 at 09:54 +0300, Timo Sirainen wrote:
On Apr 4, 2008, at 12:50 AM, Jack McKinney wrote:
Hmmm... what versions of OpenLDAP and Dovecot are you using?
A lot of people have them working with different LDAP versions. I've
Debian unstable's OpenLDAP 2.1.30.dfsg-13.5.I note that you got a result of "uid(user)=foo", from which I guess that you had pass_attrs set to user=uid or some such. I tried adding a pass_attrs of user=mail, in case the problem is that without requested fields, the code in dovecot doesn't return anything. It didn't work; it still hangs and times out after 3 minutes.
Check with wireshark if it shows that LDAP server really sends the
reply. Then you could find out if it's a problem on the OpenLDAP
client side or server/network side.
-- Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform still more excellently." -Mario Cuomo, on the lack of a clock in baseball
On Fri, 2008-04-04 at 08:48 -0500, Jack McKinney wrote:
Is wireshark something like tcpdump?
Yes, except it parses the replies so it can show the LDAP request/reply values.
My LDAP server and my Dovecot server are on the same machine, and the LDAP server claims to send the response. Since the same query from a CLI tool (ldapsearch) creates the same LDAP log entries, I suspect that OpenLDAP is indeed sending, but Dovecot is not receiving...
But as you noticed with those i_info() lines, Dovecot didn't receive the reply from OpenLDAP. So there's something wrong in the middle.
Also a lot of people have LDAP working fine, so I doubt the problem is with Dovecot's code.
Me, too. I am sure that it is my configuration, but I cannot seewhat...
On Fri, 2008-04-04 at 17:20 +0300, Timo Sirainen wrote:
Jack McKinney GPG 1024D/99C6A174 jackmc@lorentz.com YM:lfaatsnat2006 AIM:jackmclorentz "There is no parameter that makes it impossible for you to perform still more excellently." -Mario Cuomo, on the lack of a clock in baseball
participants (2)
-
Jack McKinney
-
Timo Sirainen