1 (edited by Tony-admincujae 2016-10-06 20:37:35)

Topic: Problem authenticating with Active Directory

==== Required information ====
- iRedMail version (check /etc/iredmail-release): 0.9.5.1
- Linux/BSD distribution name and version: Ubuntu 16.04
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): LDAP
- Web server (Apache or Nginx): Apache
- Manage mail accounts with iRedAdmin-Pro? No
- Related log if you're reporting an issue: dovecot.log
====

Hi,

I'm trying to authenticate my iRedmail server with our organization AD. I'm following step by step this guide http://www.iredmail.org/docs/active.directory.html. So far I've managed to make postfix work with the AD, but dovecot doesn't. This is the dovecot.log when I try to login via telnet.

Oct 06 11:52:00 auth: Error: ldap(tony@domain.local,::1,<X4Lr6zA+7I4AAAAAAAAAAAAAAAAAAAAB>): Connection appears to be hanging, reconnecting
Oct 06 11:53:31 auth: Error: ldap(postmaster@domain.local): Connection appears to be hanging, reconnecting
Oct 06 11:53:31 auth: Error: ldap(tony@domain.local,::1,<X4Lr6zA+7I4AAAAAAAAAAAAAAAAAAAAB>): LDAP search returned multiple entries
Oct 06 11:53:31 auth: Error: ldap(tony@domain.local,::1,<X4Lr6zA+7I4AAAAAAAAAAAAAAAAAAAAB>): Request lost
Oct 06 11:53:31 auth: Error: LDAP: Reply with unknown msgid 2
Oct 06 11:53:31 auth: Error: ldap(postmaster@domain.local): ldap_search(base=dc=domain,dc=local filter=(&(userPrincipalName=postmaster@domain.local)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))) failed: Operations error
Oct 06 11:53:31 auth: Error: ldap(postmaster@domain.local): ldap_search(base=dc=domain,dc=local filter=(&(userPrincipalName=postmaster@domain.local)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))) failed: Operations error
Oct 06 11:53:31 auth: Error: ldap(postmaster@domain.local): ldap_search(base=dc=domain,dc=local filter=(&(userPrincipalName=postmaster@domain.local)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))) failed: Operations error

And this is the log when I run dovecot in debug mode:

Oct 06 12:29:33 auth: Debug: auth client connected (pid=11330)
Oct 06 12:29:46 auth: Debug: client in: AUTH    1       PLAIN   service=imap    secured session=TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB        lip=::1 rip=::1 lport=143       rport=38998   resp=AHRvbnlAaXNoLmxvY2FsAFJNaW51dG85MzEw (previous base64 data may contain sensitive data)
Oct 06 12:29:46 auth: Debug: ldap(tony@domain.local,::1,<TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB>): bind search: base=dc=domain,dc=local filter=(&(userPrincipalName=tony@domain.local)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))
Oct 06 12:29:46 auth: Error: ldap(tony@domain.local,::1,<TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB>): Connection appears to be hanging, reconnecting
Oct 06 12:29:46 auth: Debug: ldap(tony@domain.local,::1,<TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB>): result: objectClass=top,top,top,top cn=Antonio Alvarez sn=Alvarez givenName=Antonio distinguishedName=CN=Antonio Alvarez,OU=Administration,DC=domain,DC=local instanceType=4 whenCreated=20160425123533.0Z whenChanged=20161001142944.0Z displayName=Antonio Alvarez uSNCreated=8194309 memberOf=CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domainh,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local uSNCha{▒▒ userAccountControl=66048 badPwdCount=0 codePage=0 countryCode=0 badPasswordTime=131197297514602530 lastLogoff=0 lastLogon=131202278160588976 pwdLastSet=131099438694843513 primaryGroupID=513 objectSid=<no values> adminCount=1 accountExpires=9223372036854775807 logonCount=719 sAMAccountName=tony sAMAccountType=805306368 userPrincipalName=tony@domain.local objectCategory=CN=Person,CN=Schema,CN=Configuration,DC=domain,DC=local dSCorePropagationData=20160512220530.0Z,20160512220530.0Z lastLogonTimestamp=131198057848306697 mail=tony@domain.local kerio-Mail-Active=domain.local kerio-Mail-AccountEnabled=1; objectGUID,uSNCreated,objectCategory,objectClass,primaryGroupID,cn,givenName,objectSid,sAMAccountType,dSCorePropagationData,userAccountControl,name,mail,codePage,lastLogon,logonCount,countryCode,kerio-Mail-Active,lastLogoff,uSNChanged,pwdLastSet,distinguishedName,sAMAccountName,memberOf,whenChanged,userPrincipalName,kerio-Mail-AccountEnabled,instanceType,badPwdCount,accountExpires,adminCount,whenCreated,displayName,badPasswordTime,lastLogonTimestamp,sn unused
Oct 06 12:29:46 auth: Debug: ldap(tony@domain.local,::1,<TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB>): result: objectClass=top,top,top,top cn=Antonio Alvarez sn=Alvarez givenName=Antonio distinguishedName=CN=Antonio Alvarez,OU=Administration,DC=domain,DC=local instanceType=4 whenCreated=20160425123533.0Z whenChanged=20161001142944.0Z displayName=Antonio Alvarez uSNCreated=8194309 memberOf=CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local,CN=GoodByeMrMorris,DC=domain,DC=local uSNCha{▒▒ userAccountControl=66048 badPwdCount=0 codePage=0 countryCode=0 badPasswordTime=131197297514602530 lastLogoff=0 lastLogon=131202278160588976 pwdLastSet=131099438694843513 primaryGroupID=513 objectSid=<no values> adminCount=1 accountExpires=9223372036854775807 logonCount=719 sAMAccountName=tony sAMAccountType=805306368 userPrincipalName=tony@domain.local objectCategory=CN=Person,CN=Schema,CN=Configuration,DC=domain,DC=local dSCorePropagationData=20160512220530.0Z,20160512220530.0Z lastLogonTimestamp=131198057848306697 mail=tony@domain.local kerio-Mail-Active=domain.local kerio-Mail-AccountEnabled=1; objectGUID,uSNCreated,objectCategory,objectClass,primaryGroupID,cn,givenName,objectSid,sAMAccountType,dSCorePropagationData,userAccountControl,name,mail,codePage,lastLogon,logonCount,countryCode,kerio-Mail-Active,lastLogoff,uSNChanged,pwdLastSet,distinguishedName,sAMAccountName,memberOf,whenChanged,userPrincipalName,kerio-Mail-AccountEnabled,instanceType,badPwdCount,accountExpires,adminCount,whenCreated,displayName,badPasswordTime,lastLogonTimestamp,sn unused
Oct 06 12:29:46 auth: Error: ldap(tony@domain.local,::1,<TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB>): Connection appears to be hanging, reconnecting
Oct 06 12:29:46 auth: Error: ldap(postmaster@domain.local): Request lost
Oct 06 12:29:46 auth: Debug: userdb out: FAIL   1
Oct 06 12:29:46 auth: Debug: client passdb out: OK      1       user=tony@domain.local
Oct 06 12:29:46 auth: Debug: master in: REQUEST 290062337       11330   1       28b279e5b16208e873b7669e1caf62e4        session_pid=11331       request_auth_token
Oct 06 12:29:46 auth: Debug: ldap(tony@domain.local,::1,<TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB>): user search: base=dc=domain,dc=local scope=subtree filter=(&(userPrincipalName=tony@domain.local)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2))) fields=
Oct 06 12:31:16 imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes)
Oct 06 12:31:16 auth: Debug: client in: CANCEL  1
Oct 06 12:31:16 imap-login: Info: Internal login failure (pid=11330 id=1) (internal failure, 1 successful auths): user=<tony@domain.local>, method=PLAIN, rip=::1, lip=::1, secured, session=<TnH3cjE+VpgAAAAAAAAAAAAAAAAAAAAB>
Oct 06 12:31:16 imap: Error: Login client disconnected too early

This is my dovecot-ldap.conf
hosts           = myad.domain.local:389
ldap_version    = 3
auth_bind       = yes
dn              = vmail
dnpass          = XXX
base            = dc=domain,dc=local
scope           = subtree
deref           = never
user_filter     = (&(userPrincipalName=%u)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))
pass_filter     = (&(userPrincipalName=%u)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))
pass_attrs      = userPassword=password
default_pass_scheme = CRYPT
user_attrs      = =home=/var/vmail/vmail1/%Ld/%Ln/Maildir/,=mail=maildir:/var/vmail/vmail1/%Ld/%Ln/Maildir/

Some quick notes:
-My domain is a .local domain
-My base = dc=domain,dc=local is the same that I'm using with postfix (wich works fine)
-I've read this similar post on this site and the solution doesn't work for me http://www.iredmail.org/forum/topic2696 … ads-2.html
-I've found this old post in dovecot.org but is really old so it should be fix by now right?? http://www.dovecot.org/list/dovecot/201 … 36107.html

Any help please?? Regards.

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2

Re: Problem authenticating with Active Directory

Could someone explain to me what does it means the last part of this two linas from the dovecot-ldap.conf file (userAccountControl:1.2.840.113556.1.4.803:=2)?

user_filter     = (&(userPrincipalName=%u)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))
pass_filter     = (&(userPrincipalName=%u)(objectClass=person)(!(userAccountControl:1.2.840.113556.1.4.803:=2)))

3

Re: Problem authenticating with Active Directory

Tony-admincujae wrote:

Oct 06 11:52:00 auth: Error: ldap(tony@domain.local,::1,<X4Lr6zA+7I4AAAAAAAAAAAAAAAAAAAAB>): Connection appears to be hanging, reconnecting

Seems something wrong with LDAP connection, no clear idea yet.

Tony-admincujae wrote:

Could someone explain to me what does it means the last part of this two linas from the dovecot-ldap.conf file (userAccountControl:1.2.840.113556.1.4.803:=2)?

It means user is disabled.

4

Re: Problem authenticating with Active Directory

ZhangHuangbin wrote:
Tony-admincujae wrote:

Oct 06 11:52:00 auth: Error: ldap(tony@domain.local,::1,<X4Lr6zA+7I4AAAAAAAAAAAAAAAAAAAAB>): Connection appears to be hanging, reconnecting

Seems something wrong with LDAP connection, no clear idea yet.

Tony-admincujae wrote:

Could someone explain to me what does it means the last part of this two linas from the dovecot-ldap.conf file (userAccountControl:1.2.840.113556.1.4.803:=2)?

It means user is disabled.


Ok... After a while thinking about the problem I couldn't figure out what was going on, so I decided to start a clean installation. Eventually I got stuck (surprise, surprise!!!) in the same point as before. Dovecot didn't connect to the AD. The logs showed something like "The connection appears to be hanging".

At last (literally hours later) I figure what was wrong. The port that I was using was 389 (the one recommended), so I change it to 3268 and now it works beautifully. I still don't understand why port 389 didn't work, I mean that's the port through which I've authenticated all of my other services (Nextcloud, Kerio Connect Mail, Squid Proxy, etc. etc). If anybody knows the answer please feel free to tell me.

You can close this topic now.