Fran
2015-Sep-08 09:00 UTC
My dovecot works fine against Active Directory 2003, but not against AD2008
Hello, my dovecot installation has been working fine against AD till we upgrade from AD 2003 to AD 2008. As http://wiki2.dovecot.org/AuthDatabase/LDAP said, now I'm not able to connect AD through 389 port. The port 3268 works fine though. (...) Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes) Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login failure (pid=4846 id=1) (internal failure, 1 successful auths): user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> (...) Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears to be hanging, reconnecting Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search returned multiple entries (...) Is there a technical reason for this problem? Does it exist any workaround? The use of Global Catalog (port 3268) is not a solution for me, since it misses many attributes. (ex. I use the field "initials" to set the quota and this field is not available through port 3268). I also noticed that, now, it uses any DC available in the domain, it doesn't care what I configured in "hosts = " parameter. This is using "hosts = dc03.domain:389": ----------------------------------------------- [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth tcp 22 0 <dovecotServer_IP>:55217 <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth tcp 22 0 <dovecotServer_IP>:57645 <dc06.domain_IP>:389 ESTABLISHED 4872/dovecot/auth tcp 0 0 <dovecotServer_IP>:55216 <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth It looks like it does a look up for other domains controller (I don't know how nor why) and it connect aleatory to any DC in my domain (in this case dc06.domain, but it changes any time), additionally to the configured one (dc03.domain). This is using "hosts = dc03.domain:3268": ------------------------------------------------ [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth tcp 0 0 <dovecotServer_IP>:58485 <dc03.domain_IP>:3268 ESTABLISHED 4982/dovecot/auth In this case, only the configured server in host parameter is used (I think this is the right behaviour) Aditional info: --------------- CentOS Linux release 7.0.1406 (Core) dovecot 2.2.10 Build options: ioloop=epoll notify=inotify ipv6 openssl io_block_size=8192 Mail storages: shared mdbox sdbox maildir mbox cydir imapc pop3c raw fail SQL driver plugins: mysql postgresql sqlite Passdb: checkpassword ldap pam passwd passwd-file shadow sql Userdb: checkpassword ldap(plugin) nss passwd prefetch passwd-file sql My /etc/dovecot/dovecot-ldap.conf.ext -------------------------------------- #hosts = dc03.domain:3268 hosts = dc03.domain:389 #uris = ldap://dc03.domain base = DC=domain #tls = yes tls = no ldap_version = 3 auth_bind = yes auth_bind_userdn = %u at domain #auth_bind_userdn = DOMAIN\%u dn = cn=<user>,cn=Users,dc=domain dnpass = <password> #scope = subtree #deref = never user_filter (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) pass_filter (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) pass_attrs = userPassword=password user_attrs = Initials=quota_rule=*:storage=%$MB --------------- -------------------------- Log trace using PORT 389: -------------------------- Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libauthdb_ldap.so Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: auth client connected (pid=4846) Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap secured session=T+grMCsfqgAKHyZV lip=<dovecotServer_IP> rip=<clientLAN_IP> lport=993 rport=59818 Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client in: CONT 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous base64 data may contain sensitive data) Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client passdb out: OK 1 user=<username> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: master in: REQUEST 4142792705 4846 1 cb2115241ccfd81959c15122ec062a8b session_pid=4849 request_auth_token Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): user search: base=DC=domain scope=subtree filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) fields=Initials Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: master(imap): Auth request timed out (received 0/12 bytes) Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login failure (pid=4846 id=1) (internal failure, 1 successful auths): user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: client in: CANCEL 1 Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL alert: close notify [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap: Error: Login client disconnected too early Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: auth client connected (pid=4868) Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap secured session=ZjyONSsf6QAKHyZV lip=<dovecotServer_IP> rip=<clientLAN_IP> lport=993 rport=59881 Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client in: CONT 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous base64 data may contain sensitive data) Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears to be hanging, reconnecting Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search returned multiple entries Sep 7 19:03:10 <dovecotServer> dovecot: imap: Error: Auth server request timed out after 155 secs (client-pid=4846 client-id=1) Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: close notify [<clientLAN_IP>] Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: close notify [<clientLAN_IP>] Sep 7 19:04:36 <dovecotServer> dovecot: auth: Error: PLAIN(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Request 4868.1 timed out after 150 secs, state=1 Sep 7 19:05:05 <dovecotServer> dovecot: imap-login: Disconnected: Inactivity during authentication (disconnected while authenticating, waited 179 secs): user=<>, method=PLAIN, rip=<clientLAN_IP>, lip=<dovecotServer_IP>, TLS, session=<ZjyONSsf6QAKHyZV> Sep 7 19:05:05 <dovecotServer> dovecot: auth: Debug: client in: CANCEL Sep 7 19:06:06 <dovecotServer> dovecot: auth: ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): Shutting down Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: master userdb out: FAIL 4142792705 Sep 7 19:06:06 <dovecotServer> dovecot: auth: ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Shutting down Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: client passdb out: FAIL 1 user=<username> temp -------------------------- Log trace using PORT 3268: -------------------------- Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libauthdb_ldap.so Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: auth client connected (pid=4971) Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap secured session=FAKKpCsf0AAKHyZV lip=<dovecotServer_IP> rip=<clientLAN_IP> lport=993 rport=61648 Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client in: CONT 1 AEN1bWMtNDM2MS0yAGZvcnRpbmV0LjIwMTQ= (previous base64 data may contain sensitive data) Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client passdb out: OK 1 user=<username> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master in: REQUEST 3261071361 4971 1 4755688f0bdd33a0fadcc5d3b8664e61 session_pid=4974 request_auth_token Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): user search: base=DC=domain scope=subtree filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) fields=Initials [Here start the difference between 389 and 3268 ports] Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): no fields returned by the server [Next line you can see missing attributes, due to I'm using port 3268] Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): result: Initials missing Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master userdb out: USER 3261071361 <username> uid=1000 gid=1000 home=/home/mailstorage/<domain>/<username> auth_token=9191cdf475600f0a47e185bb65817c0e0f495894 Sep 7 19:33:08 <dovecotServer> dovecot: imap-login: Login: user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, lip=<dovecotServer_IP>, mpid=4974, TLS, session=<FAKKpCsf0AAKHyZV> Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Loading modules from directory: /usr/lib64/dovecot Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: /usr/lib64/dovecot/lib11_imap_quota_plugin.so Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Effective uid=1000, gid=1000, home=/home/mailstorage/<domain>/<username> Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Quota root: name=CuotaUsuario backend=maildir argsSep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Quota rule: root=CuotaUsuario mailbox=* bytes=2097152 messages=0 Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Quota grace: root=CuotaUsuario bytes=209715 (10%) Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: maildir++: root=/home/mailstorage/<domain>/<username>/Maildir, index=, indexpvt=, control=, inbox=/home/mailstorage/<domain>/<username>/Maildir, alt=
Fran
2015-Sep-08 15:19 UTC
My dovecot works fine against Active Directory 2003, but not against AD2008
I've logged a session using the option debug_level = -1. The log is attached. I still don't understand what is happening and why all my domain controllers are being used even when I just use one of them in "host" parameter in my /etc/dovecot/dovecot-ldap.conf.ext. Thanks in advance, Regards El 08/09/2015 a las 11:00, Fran escribi?:> Hello, > > my dovecot installation has been working fine against AD till we upgrade > from AD 2003 to AD 2008. As http://wiki2.dovecot.org/AuthDatabase/LDAP > said, now I'm not able to connect AD through 389 port. The port 3268 > works fine though. > > (...) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: > master(imap): Auth request timed out (received 0/12 bytes) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login > failure (pid=4846 id=1) (internal failure, 1 successful auths): > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> > (...) > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears > to be hanging, reconnecting > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search returned > multiple entries > (...) > > Is there a technical reason for this problem? Does it exist any workaround? > > The use of Global Catalog (port 3268) is not a solution for me, since it > misses many attributes. (ex. I use the field "initials" to set the quota > and this field is not available through port 3268). > > I also noticed that, now, it uses any DC available in the domain, it > doesn't care what I configured in "hosts = " parameter. > > This is using "hosts = dc03.domain:389": > ----------------------------------------------- > > [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth > tcp 22 0 <dovecotServer_IP>:55217 > <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > tcp 22 0 <dovecotServer_IP>:57645 > <dc06.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > tcp 0 0 <dovecotServer_IP>:55216 > <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > > It looks like it does a look up for other domains controller (I don't > know how nor why) and it connect aleatory to any DC in my domain (in > this case dc06.domain, but it changes any time), additionally to the > configured one (dc03.domain). > > This is using "hosts = dc03.domain:3268": > ------------------------------------------------ > [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth > tcp 0 0 <dovecotServer_IP>:58485 > <dc03.domain_IP>:3268 ESTABLISHED 4982/dovecot/auth > > In this case, only the configured server in host parameter is used (I > think this is the right behaviour) > > > Aditional info: > --------------- > CentOS Linux release 7.0.1406 (Core) > > dovecot 2.2.10 > > Build options: ioloop=epoll notify=inotify ipv6 openssl io_block_size=8192 > Mail storages: shared mdbox sdbox maildir mbox cydir imapc pop3c raw fail > SQL driver plugins: mysql postgresql sqlite > Passdb: checkpassword ldap pam passwd passwd-file shadow sql > Userdb: checkpassword ldap(plugin) nss passwd prefetch passwd-file sql > > > My /etc/dovecot/dovecot-ldap.conf.ext > -------------------------------------- > #hosts = dc03.domain:3268 > hosts = dc03.domain:389 > #uris = ldap://dc03.domain > base = DC=domain > #tls = yes > tls = no > ldap_version = 3 > auth_bind = yes > auth_bind_userdn = %u at domain > #auth_bind_userdn = DOMAIN\%u > dn = cn=<user>,cn=Users,dc=domain > dnpass = <password> > > #scope = subtree > #deref = never > > user_filter > (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) > pass_filter > (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) > pass_attrs = userPassword=password > user_attrs = Initials=quota_rule=*:storage=%$MB > --------------- > > > -------------------------- > Log trace using PORT 389: > -------------------------- > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_sqlite.so > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libauthdb_ldap.so > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Read auth token > secret from /var/run/dovecot/auth-token-secret.dat > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: auth client > connected (pid=4846) > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x20, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client in: AUTH > 1 PLAIN service=imap secured session=T+grMCsfqgAKHyZV > lip=<dovecotServer_IP> rip=<clientLAN_IP> lport=993 rport=59818 > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client passdb out: > CONT 1 > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client in: CONT > 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous > base64 data may contain sensitive data) > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client passdb out: > OK 1 user=<username> > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: master in: > REQUEST 4142792705 4846 1 > cb2115241ccfd81959c15122ec062a8b session_pid=4849 > request_auth_token > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): user search: > base=DC=domain scope=subtree > filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) > fields=Initials > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: > master(imap): Auth request timed out (received 0/12 bytes) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login > failure (pid=4846 id=1) (internal failure, 1 successful auths): > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> > Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: client in: > CANCEL 1 > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > close notify [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap: Error: Login client > disconnected too early > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: auth client > connected (pid=4868) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x20, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client in: AUTH > 1 PLAIN service=imap secured session=ZjyONSsf6QAKHyZV > lip=<dovecotServer_IP> rip=<clientLAN_IP> lport=993 rport=59881 > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client passdb out: > CONT 1 > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client in: CONT > 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous > base64 data may contain sensitive data) > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears > to be hanging, reconnecting > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search returned > multiple entries > > Sep 7 19:03:10 <dovecotServer> dovecot: imap: Error: Auth server > request timed out after 155 secs (client-pid=4846 client-id=1) > > Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > close notify [<clientLAN_IP>] > Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > close notify [<clientLAN_IP>] > > Sep 7 19:04:36 <dovecotServer> dovecot: auth: Error: > PLAIN(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Request 4868.1 > timed out after 150 secs, state=1 > > Sep 7 19:05:05 <dovecotServer> dovecot: imap-login: Disconnected: > Inactivity during authentication (disconnected while authenticating, > waited 179 secs): user=<>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, TLS, session=<ZjyONSsf6QAKHyZV> > Sep 7 19:05:05 <dovecotServer> dovecot: auth: Debug: client in: CANCEL > > Sep 7 19:06:06 <dovecotServer> dovecot: auth: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): Shutting down > Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: master userdb out: > FAIL 4142792705 > Sep 7 19:06:06 <dovecotServer> dovecot: auth: > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Shutting down > Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: client passdb out: > FAIL 1 user=<username> temp > > > > > -------------------------- > Log trace using PORT 3268: > -------------------------- > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_sqlite.so > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libauthdb_ldap.so > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Read auth token > secret from /var/run/dovecot/auth-token-secret.dat > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: auth client > connected (pid=4971) > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x20, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=1: SSL negotiation finished successfully [<clientLAN_IP>] > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client in: AUTH > 1 PLAIN service=imap secured session=FAKKpCsf0AAKHyZV > lip=<dovecotServer_IP> rip=<clientLAN_IP> lport=993 rport=61648 > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client passdb out: > CONT 1 > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client in: CONT > 1 AEN1bWMtNDM2MS0yAGZvcnRpbmV0LjIwMTQ= (previous base64 data may > contain sensitive data) > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client passdb out: > OK 1 user=<username> > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master in: > REQUEST 3261071361 4971 1 > 4755688f0bdd33a0fadcc5d3b8664e61 session_pid=4974 > request_auth_token > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): user search: > base=DC=domain scope=subtree > filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) > fields=Initials > > [Here start the difference between 389 and 3268 ports] > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): no fields returned > by the server > > [Next line you can see missing attributes, due to I'm using port 3268] > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): result: Initials > missing > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master userdb out: > USER 3261071361 <username> uid=1000 gid=1000 > home=/home/mailstorage/<domain>/<username> > auth_token=9191cdf475600f0a47e185bb65817c0e0f495894 > Sep 7 19:33:08 <dovecotServer> dovecot: imap-login: Login: > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, mpid=4974, TLS, session=<FAKKpCsf0AAKHyZV> > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Loading modules > from directory: /usr/lib64/dovecot > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: > /usr/lib64/dovecot/lib10_quota_plugin.so > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: > /usr/lib64/dovecot/lib11_imap_quota_plugin.so > Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: > Effective uid=1000, gid=1000, home=/home/mailstorage/<domain>/<username> > Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Quota > root: name=CuotaUsuario backend=maildir args> Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Quota > rule: root=CuotaUsuario mailbox=* bytes=2097152 messages=0 > Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: Quota > grace: root=CuotaUsuario bytes=209715 (10%) > Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: > Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, > list=yes, subscriptions=yes location=maildir:~/Maildir > Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: > maildir++: root=/home/mailstorage/<domain>/<username>/Maildir, index=, > indexpvt=, control=, > inbox=/home/mailstorage/<domain>/<username>/Maildir, alt>-------------- next part -------------- Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Sep 8 12:43:19 dovecotServer dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Sep 8 12:43:19 dovecotServer dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libauthdb_ldap.so Sep 8 12:43:19 dovecotServer dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_bind Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_simple_bind Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_sasl_bind Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_send_initial_request Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_new_connection 1 1 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_int_open_connection Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_connect_to_host: TCP dc03server.dom:389 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_new_socket: 18 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_prepare_socket: 18 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_connect_to_host: Trying <dc03server_IP>:389 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_pvt_connect: fd: 18 tm: -1 async: 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: attempting to connect: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: connect success Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_open_defconn: successful Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:19 dovecotServer dovecot: auth: Debug: auth client connected (pid=9100) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:19 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:19 2015 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: * msgid 1, origid 1, status InProgress Sep 8 12:43:19 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 1 (abandoned 0) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:19 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 1 message type bind Sep 8 12:43:19 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 0 new referrals Sep 8 12:43:19 dovecotServer dovecot: auth: Error: read1msg: mark request completed, ld 0x7f8453ac1c10 msgid 1 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: request done: ld 0x7f8453ac1c10 msgid 1 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_free_request (origid 1, msgid 1) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_parse_result Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_msgfree Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:19 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:19 2015 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 0 (abandoned 0) Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:19 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:19 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [192.168.1.80] Sep 8 12:43:19 dovecotServer dovecot: imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [192.168.1.80] Sep 8 12:43:20 dovecotServer dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap secured session=SdnRCDof8gAKHyZV lip=<dovecotServer_IP> rip=192.168.1.80 lport=993 rport=4594 Sep 8 12:43:20 dovecotServer dovecot: auth: Debug: client passdb out: CONT 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Debug: client in: CONT 1 AEN1bWMtNDM2MS0yAGZvcnRpbmV0LjIwMTQ= (previous base64 data may contain sensitive data) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_simple_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_sasl_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_initial_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 2, origid 2, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 1 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 2 message type bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 0 new referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: mark request completed, ld 0x7f8453ac1c10 msgid 2 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: request done: ld 0x7f8453ac1c10 msgid 2 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_free_request (origid 2, msgid 2) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_parse_result Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_parse_result Sep 8 12:43:20 dovecotServer dovecot: auth: Debug: client passdb out: OK 1 user=user-2 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_msgfree Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 0 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Debug: master in: REQUEST 1247150081 9100 1 dcb51b5e41d9bcd1e08d6d04490172a3 session_pid=9103 request_auth_token Sep 8 12:43:20 dovecotServer dovecot: auth: Debug: ldap(user-2,192.168.1.80,<SdnRCDof8gAKHyZV>): user search: base=DC=dom scope=subtree filter=(&(userPrincipalName=user-2 at dom)(objectClass=person)(|(mail=user-2 at domain.dom)(othermailbox=user-2 at domain.dom))) fields=Initials Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_simple_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_sasl_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_initial_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 3, origid 3, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 1 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 3 message type bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 0 new referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: mark request completed, ld 0x7f8453ac1c10 msgid 3 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: request done: ld 0x7f8453ac1c10 msgid 3 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_free_request (origid 3, msgid 3) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_parse_result Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_search Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: "(&(userPrincipalName=user-2 at dom)(objectClass=person)(|(mail=user-2 at domain.dom)(othermailbox=user-2 at domain.dom)))" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: AND Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter_list "(userPrincipalName=user-2 at dom)(objectClass=person)(|(mail=user-2 at domain.dom)(othermailbox=user-2 at domain.dom))" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: "(userPrincipalName=user-2 at dom)" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: simple Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_simple_filter: "userPrincipalName=user-2 at dom" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: "(objectClass=person)" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: simple Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_simple_filter: "objectClass=person" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: "(|(mail=user-2 at domain.dom)(othermailbox=user-2 at domain.dom))" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: OR Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter_list "(mail=user-2 at domain.dom)(othermailbox=user-2 at domain.dom)" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: "(mail=user-2 at domain.dom)" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: simple Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_simple_filter: "mail=user-2 at domain.dom" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: "(othermailbox=user-2 at domain.dom)" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_filter: simple Sep 8 12:43:20 dovecotServer dovecot: auth: Error: put_simple_filter: "othermailbox=user-2 at domain.dom" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_build_search_req ATTRS: Initials Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_initial_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_msgfree Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 1 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 1 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 4 message type search-entry Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid -1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid -1 (timeout 0 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 1 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid -1 all 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 4 message type search-reference Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chase_v3referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_url_parse_ext(ldap://ForestDnsZones.dom/DC=ForestDnsZones,DC=dom) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: re_encode_request: new msgid 5, new dn <DC=ForestDnsZones,DC=dom> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: re_encode_request new request is: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ber_dump: buf=0x7f8453ad2ea0 ptr=0x7f8453ad2f76 end=0x7f8453ad3e7c len=214 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0000: 61 6c 73 61 6c 73 00 00 00 00 00 00 00 00 00 00 alsals.......... Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0090: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00d0: 00 00 00 00 00 00 ...... Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chase_v3referral: msgid 4, url "ldap://ForestDnsZones.dom/DC=ForestDnsZones,DC=dom" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_new_connection 0 1 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_open_connection Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_connect_to_host: TCP ForestDnsZones.dom:389 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_new_socket: 21 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_prepare_socket: 21 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_connect_to_host: Trying <dc01server_IP>:389 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_pvt_connect: fd: 21 tm: -1 async: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: attempting to connect: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: connect success Sep 8 12:43:20 dovecotServer dovecot: auth: Error: anonymous rebind via ldap_sasl_bind("") Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_sasl_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_initial_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid 6 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid 6 (timeout 100000 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid 6 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: ForestDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 3 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 6, origid 6, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 1, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 2 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid 6 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 6 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 4 message type search-reference Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chase_v3referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_url_parse_ext(ldap://DomainDnsZones.dom/DC=DomainDnsZones,DC=dom) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: re_encode_request: new msgid 7, new dn <DC=DomainDnsZones,DC=dom> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: re_encode_request new request is: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ber_dump: buf=0x7f8453ad53c0 ptr=0x7f8453ad5496 end=0x7f8453ad639c len=214 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0000: 61 6c 73 61 6c 73 00 00 00 00 00 00 00 00 00 00 alsals.......... Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0090: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00d0: 00 00 00 00 00 00 ...... Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chase_v3referral: msgid 4, url "ldap://DomainDnsZones.dom/DC=DomainDnsZones,DC=dom" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_new_connection 0 1 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_open_connection Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_connect_to_host: TCP DomainDnsZones.dom:389 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_new_socket: 22 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_prepare_socket: 22 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_connect_to_host: Trying <dc03server_IP>:389 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_pvt_connect: fd: 22 tm: -1 async: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: attempting to connect: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: connect success Sep 8 12:43:20 dovecotServer dovecot: auth: Error: anonymous rebind via ldap_sasl_bind("") Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_sasl_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_initial_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid 8 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid 8 (timeout 100000 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid 8 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: DomainDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: ForestDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 4 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 8, origid 8, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 6, origid 6, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 2, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 3 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid 8 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 8 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 6 message type bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 0 new referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: mark request completed, ld 0x7f8453ac1c10 msgid 6 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: request done: ld 0x7f8453ac1c10 msgid 6 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_free_request (origid 6, msgid 6) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 8 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 4 message type search-reference Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chase_v3referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_url_parse_ext(ldap://dom/CN=Configuration,DC=dom) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: re_encode_request: new msgid 9, new dn <CN=Configuration,DC=dom> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: re_encode_request new request is: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ber_dump: buf=0x7f8453ad7840 ptr=0x7f8453ad7915 end=0x7f8453ad881c len=213 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0000: 61 6c 73 61 6c 73 00 00 00 00 00 00 00 00 00 00 alsals.......... Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 0090: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Sep 8 12:43:20 dovecotServer dovecot: auth: Error: 00d0: 00 00 00 00 00 ..... Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chase_v3referral: msgid 4, url "ldap://dom/CN=Configuration,DC=dom" Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_new_connection 0 1 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_open_connection Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_connect_to_host: TCP dom:389 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_new_socket: 23 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_prepare_socket: 23 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_connect_to_host: Trying <dc02server_IP>:389 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_pvt_connect: fd: 23 tm: -1 async: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: attempting to connect: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: connect success Sep 8 12:43:20 dovecotServer dovecot: auth: Error: anonymous rebind via ldap_sasl_bind("") Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_sasl_bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_initial_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_send_server_request Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_result ld 0x7f8453ac1c10 msgid 10 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 msgid 10 (timeout 100000 usec) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid 10 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: DomainDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: ForestDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 5 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 10, origid 10, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 8, origid 8, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 3, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 3 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 6, type 97 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid 10 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 10 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 8 message type bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 0 new referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: mark request completed, ld 0x7f8453ac1c10 msgid 8 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: request done: ld 0x7f8453ac1c10 msgid 8 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_free_request (origid 8, msgid 8) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 10 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 4 message type search-result Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 0 new referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: mark request completed, ld 0x7f8453ac1c10 msgid 4 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 0 s 99737 us to go Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid 10 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: DomainDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: ForestDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 4 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 10, origid 10, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status RequestCompleted Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 3, parent count 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 2 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 8, type 97 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 6, type 97 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 2 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid 10 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 NULL Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_int_select Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 10 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 msgid 10 message type bind Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: ld 0x7f8453ac1c10 0 new referrals Sep 8 12:43:20 dovecotServer dovecot: auth: Error: read1msg: mark request completed, ld 0x7f8453ac1c10 msgid 10 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: request done: ld 0x7f8453ac1c10 msgid 10 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_free_request (origid 10, msgid 10) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_parse_result Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_msgfree Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 0 s 95007 us to go Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid 8 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: DomainDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: ForestDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 3 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 9, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, origid 4, status RequestCompleted Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 3, parent count 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 request count 2 (abandoned 0) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Response Queue: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 4, type 115 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 8, type 97 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 6, type 97 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ld 0x7f8453ac1c10 response count 3 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList ld 0x7f8453ac1c10 msgid 8 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_chkResponseList returns ld 0x7f8453ac1c10 msgid 8, type 0x61 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_parse_result Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ldap_msgfree Sep 8 12:43:20 dovecotServer dovecot: auth: Error: adding response ld 0x7f8453ac1c10 msgid 4 type 115: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg ld 0x7f8453ac1c10 0 s 91828 us to go Sep 8 12:43:20 dovecotServer dovecot: auth: Error: wait4msg continue ld 0x7f8453ac1c10 msgid 6 all 1 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Connections: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: DomainDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: ForestDnsZones.dom port: 0 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 1 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: rebind in progress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: queue is empty Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * host: dc03server.dom port: 389 (default) Sep 8 12:43:20 dovecotServer dovecot: auth: Error: refcnt: 2 status: Connected Sep 8 12:43:20 dovecotServer dovecot: auth: Error: last used: Tue Sep 8 12:43:20 2015 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: ** ld 0x7f8453ac1c10 Outstanding Requests: Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 7, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 2 Sep 8 12:43:20 dovecotServer dovecot: auth: Error: * msgid 9, origid 4, status InProgress Sep 8 12:43:20 dovecotServer dovecot: auth: Error: outstanding referrals 0, parent count 1
Matthias Lay
2015-Sep-09 15:22 UTC
My dovecot works fine against Active Directory 2003, but not against AD2008
hi, check your /etc/openldap/ldap.conf for REFERRALS off I had this errors with "referrals on" in misconfigured dns environments. you can debug the dns packets by strace-ing the auth process On Tue, 8 Sep 2015 11:00:37 +0200 Fran <cumc-4361-2 at chguadalquivir.es> wrote:> Hello, > > my dovecot installation has been working fine against AD till we > upgrade from AD 2003 to AD 2008. As > http://wiki2.dovecot.org/AuthDatabase/LDAP said, now I'm not able to > connect AD through 389 port. The port 3268 works fine though. > > (...) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: > master(imap): Auth request timed out (received 0/12 bytes) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login > failure (pid=4846 id=1) (internal failure, 1 successful auths): > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> > (...) > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears > to be hanging, reconnecting > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search > returned multiple entries > (...) > > Is there a technical reason for this problem? Does it exist any > workaround? > > The use of Global Catalog (port 3268) is not a solution for me, since > it misses many attributes. (ex. I use the field "initials" to set the > quota and this field is not available through port 3268). > > I also noticed that, now, it uses any DC available in the domain, it > doesn't care what I configured in "hosts = " parameter. > > This is using "hosts = dc03.domain:389": > ----------------------------------------------- > > [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth > tcp 22 0 <dovecotServer_IP>:55217 > <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > tcp 22 0 <dovecotServer_IP>:57645 > <dc06.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > tcp 0 0 <dovecotServer_IP>:55216 > <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > > It looks like it does a look up for other domains controller (I don't > know how nor why) and it connect aleatory to any DC in my domain (in > this case dc06.domain, but it changes any time), additionally to the > configured one (dc03.domain). > > This is using "hosts = dc03.domain:3268": > ------------------------------------------------ > [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth > tcp 0 0 <dovecotServer_IP>:58485 > <dc03.domain_IP>:3268 ESTABLISHED 4982/dovecot/auth > > In this case, only the configured server in host parameter is used (I > think this is the right behaviour) > > > Aditional info: > --------------- > CentOS Linux release 7.0.1406 (Core) > > dovecot 2.2.10 > > Build options: ioloop=epoll notify=inotify ipv6 openssl > io_block_size=8192 Mail storages: shared mdbox sdbox maildir mbox > cydir imapc pop3c raw fail SQL driver plugins: mysql postgresql sqlite > Passdb: checkpassword ldap pam passwd passwd-file shadow sql > Userdb: checkpassword ldap(plugin) nss passwd prefetch passwd-file sql > > > My /etc/dovecot/dovecot-ldap.conf.ext > -------------------------------------- > #hosts = dc03.domain:3268 > hosts = dc03.domain:389 > #uris = ldap://dc03.domain > base = DC=domain > #tls = yes > tls = no > ldap_version = 3 > auth_bind = yes > auth_bind_userdn = %u at domain > #auth_bind_userdn = DOMAIN\%u > dn = cn=<user>,cn=Users,dc=domain > dnpass = <password> > > #scope = subtree > #deref = never > > user_filter > (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) > pass_filter > (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) > pass_attrs = userPassword=password > user_attrs = Initials=quota_rule=*:storage=%$MB > --------------- > > > -------------------------- > Log trace using PORT 389: > -------------------------- > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_sqlite.so > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libauthdb_ldap.so > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Read auth token > secret from /var/run/dovecot/auth-token-secret.dat > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: auth client > connected (pid=4846) > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x20, ret=1: SSL negotiation finished successfully > [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: > Debug: SSL: where=0x2002, ret=1: SSL negotiation finished > successfully [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> > dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap > secured session=T+grMCsfqgAKHyZV lip=<dovecotServer_IP> > rip=<clientLAN_IP> lport=993 rport=59818 Sep 7 19:00:35 > <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client in: CONT > 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous > base64 data may contain sensitive data) > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client passdb > out: OK 1 user=<username> > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: master in: > REQUEST 4142792705 4846 1 > cb2115241ccfd81959c15122ec062a8b session_pid=4849 > request_auth_token > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): user search: > base=DC=domain scope=subtree > filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) > fields=Initials > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: > master(imap): Auth request timed out (received 0/12 bytes) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login > failure (pid=4846 id=1) (internal failure, 1 successful auths): > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> > Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: client in: > CANCEL 1 > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > close notify [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap: Error: Login client > disconnected too early > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: auth client > connected (pid=4868) > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x20, ret=1: SSL negotiation finished successfully > [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: > Debug: SSL: where=0x2002, ret=1: SSL negotiation finished > successfully [<clientLAN_IP>] Sep 7 19:02:06 <dovecotServer> > dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap > secured session=ZjyONSsf6QAKHyZV lip=<dovecotServer_IP> > rip=<clientLAN_IP> lport=993 rport=59881 Sep 7 19:02:06 > <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client in: CONT > 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous > base64 data may contain sensitive data) > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears > to be hanging, reconnecting > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search > returned multiple entries > > Sep 7 19:03:10 <dovecotServer> dovecot: imap: Error: Auth server > request timed out after 155 secs (client-pid=4846 client-id=1) > > Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > close notify [<clientLAN_IP>] > Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > close notify [<clientLAN_IP>] > > Sep 7 19:04:36 <dovecotServer> dovecot: auth: Error: > PLAIN(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Request 4868.1 > timed out after 150 secs, state=1 > > Sep 7 19:05:05 <dovecotServer> dovecot: imap-login: Disconnected: > Inactivity during authentication (disconnected while authenticating, > waited 179 secs): user=<>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, TLS, session=<ZjyONSsf6QAKHyZV> > Sep 7 19:05:05 <dovecotServer> dovecot: auth: Debug: client in: > CANCEL > > Sep 7 19:06:06 <dovecotServer> dovecot: auth: > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): Shutting down > Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: master userdb > out: FAIL 4142792705 > Sep 7 19:06:06 <dovecotServer> dovecot: auth: > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Shutting down > Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: client passdb > out: FAIL 1 user=<username> temp > > > > > -------------------------- > Log trace using PORT 3268: > -------------------------- > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_sqlite.so > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules > from directory: /usr/lib64/dovecot/auth > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libauthdb_ldap.so > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Read auth token > secret from /var/run/dovecot/auth-token-secret.dat > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: auth client > connected (pid=4971) > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > where=0x20, ret=1: SSL negotiation finished successfully > [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: > Debug: SSL: where=0x2002, ret=1: SSL negotiation finished > successfully [<clientLAN_IP>] Sep 7 19:33:08 <dovecotServer> > dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap > secured session=FAKKpCsf0AAKHyZV lip=<dovecotServer_IP> > rip=<clientLAN_IP> lport=993 rport=61648 Sep 7 19:33:08 > <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client in: CONT > 1 AEN1bWMtNDM2MS0yAGZvcnRpbmV0LjIwMTQ= (previous base64 data may > contain sensitive data) > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client passdb > out: OK 1 user=<username> > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master in: > REQUEST 3261071361 4971 1 > 4755688f0bdd33a0fadcc5d3b8664e61 session_pid=4974 > request_auth_token > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): user search: > base=DC=domain scope=subtree > filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) > fields=Initials > > [Here start the difference between 389 and 3268 ports] > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): no fields returned > by the server > > [Next line you can see missing attributes, due to I'm using port 3268] > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): result: Initials > missing > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master userdb > out: USER 3261071361 <username> uid=1000 > gid=1000 home=/home/mailstorage/<domain>/<username> > auth_token=9191cdf475600f0a47e185bb65817c0e0f495894 > Sep 7 19:33:08 <dovecotServer> dovecot: imap-login: Login: > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > lip=<dovecotServer_IP>, mpid=4974, TLS, session=<FAKKpCsf0AAKHyZV> > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Loading modules > from directory: /usr/lib64/dovecot > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: > /usr/lib64/dovecot/lib10_quota_plugin.so > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: > /usr/lib64/dovecot/lib11_imap_quota_plugin.so > Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: > Effective uid=1000, gid=1000, > home=/home/mailstorage/<domain>/<username> Sep 7 19:33:08 > <dovecotServer> dovecot: imap(<username>): Debug: Quota root: > name=CuotaUsuario backend=maildir args= Sep 7 19:33:08 > <dovecotServer> dovecot: imap(<username>): Debug: Quota rule: > root=CuotaUsuario mailbox=* bytes=2097152 messages=0 Sep 7 19:33:08 > <dovecotServer> dovecot: imap(<username>): Debug: Quota grace: > root=CuotaUsuario bytes=209715 (10%) Sep 7 19:33:08 <dovecotServer> > dovecot: imap(<username>): Debug: Namespace inbox: type=private, > prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes > location=maildir:~/Maildir Sep 7 19:33:08 <dovecotServer> dovecot: > imap(<username>): Debug: maildir++: > root=/home/mailstorage/<domain>/<username>/Maildir, index=, > indexpvt=, control=, > inbox=/home/mailstorage/<domain>/<username>/Maildir, alt=
Mark Foley
2015-Sep-10 02:51 UTC
My dovecot works fine against Active Directory 2003, but not against AD2008
Fran and/or Matthias, Could you publish your doveconf -n? I can't get dovecot to authenticate with my AD. Maybe you have a solution I could try. What mail client(s) are you using? I assume by "AD 2003/8" You mean SBS2003/8 and are therefore using Outlook? --Mark -----Original Message-----> Date: Wed, 9 Sep 2015 17:22:34 +0200 > From: Matthias Lay <matthias.lay at securepoint.de> > To: Dovecot Mailing List <dovecot at dovecot.org> > Subject: Re: My dovecot works fine against Active Directory 2003, but not > against AD2008 > > > hi, > > check your > > /etc/openldap/ldap.conf > > for > > REFERRALS off > > I had this errors with "referrals on" in misconfigured dns environments. > > > you can debug the dns packets by strace-ing the auth process > > > > > On Tue, 8 Sep 2015 11:00:37 +0200 > Fran <cumc-4361-2 at chguadalquivir.es> wrote: > > > Hello, > > > > my dovecot installation has been working fine against AD till we > > upgrade from AD 2003 to AD 2008. As > > http://wiki2.dovecot.org/AuthDatabase/LDAP said, now I'm not able to > > connect AD through 389 port. The port 3268 works fine though. > > > > (...) > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: > > master(imap): Auth request timed out (received 0/12 bytes) > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login > > failure (pid=4846 id=1) (internal failure, 1 successful auths): > > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > > lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> > > (...) > > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears > > to be hanging, reconnecting > > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search > > returned multiple entries > > (...) > > > > Is there a technical reason for this problem? Does it exist any > > workaround? > > > > The use of Global Catalog (port 3268) is not a solution for me, since > > it misses many attributes. (ex. I use the field "initials" to set the > > quota and this field is not available through port 3268). > > > > I also noticed that, now, it uses any DC available in the domain, it > > doesn't care what I configured in "hosts = " parameter. > > > > This is using "hosts = dc03.domain:389": > > ----------------------------------------------- > > > > [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth > > tcp 22 0 <dovecotServer_IP>:55217 > > <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > > tcp 22 0 <dovecotServer_IP>:57645 > > <dc06.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > > tcp 0 0 <dovecotServer_IP>:55216 > > <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth > > > > It looks like it does a look up for other domains controller (I don't > > know how nor why) and it connect aleatory to any DC in my domain (in > > this case dc06.domain, but it changes any time), additionally to the > > configured one (dc03.domain). > > > > This is using "hosts = dc03.domain:3268": > > ------------------------------------------------ > > [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth > > tcp 0 0 <dovecotServer_IP>:58485 > > <dc03.domain_IP>:3268 ESTABLISHED 4982/dovecot/auth > > > > In this case, only the configured server in host parameter is used (I > > think this is the right behaviour) > > > > > > Aditional info: > > --------------- > > CentOS Linux release 7.0.1406 (Core) > > > > dovecot 2.2.10 > > > > Build options: ioloop=epoll notify=inotify ipv6 openssl > > io_block_size=8192 Mail storages: shared mdbox sdbox maildir mbox > > cydir imapc pop3c raw fail SQL driver plugins: mysql postgresql sqlite > > Passdb: checkpassword ldap pam passwd passwd-file shadow sql > > Userdb: checkpassword ldap(plugin) nss passwd prefetch passwd-file sql > > > > > > My /etc/dovecot/dovecot-ldap.conf.ext > > -------------------------------------- > > #hosts = dc03.domain:3268 > > hosts = dc03.domain:389 > > #uris = ldap://dc03.domain > > base = DC=domain > > #tls = yes > > tls = no > > ldap_version = 3 > > auth_bind = yes > > auth_bind_userdn = %u at domain > > #auth_bind_userdn = DOMAIN\%u > > dn = cn=<user>,cn=Users,dc=domain > > dnpass = <password> > > > > #scope = subtree > > #deref = never > > > > user_filter > > (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) > > pass_filter > > (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) > > pass_attrs = userPassword=password > > user_attrs = Initials=quota_rule=*:storage=%$MB > > --------------- > > > > > > -------------------------- > > Log trace using PORT 389: > > -------------------------- > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules > > from directory: /usr/lib64/dovecot/auth > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: > > /usr/lib64/dovecot/auth/libdriver_sqlite.so > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules > > from directory: /usr/lib64/dovecot/auth > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: > > /usr/lib64/dovecot/auth/libauthdb_ldap.so > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Read auth token > > secret from /var/run/dovecot/auth-token-secret.dat > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: auth client > > connected (pid=4846) > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > > Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x20, ret=1: SSL negotiation finished successfully > > [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: > > Debug: SSL: where=0x2002, ret=1: SSL negotiation finished > > successfully [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> > > dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap > > secured session=T+grMCsfqgAKHyZV lip=<dovecotServer_IP> > > rip=<clientLAN_IP> lport=993 rport=59818 Sep 7 19:00:35 > > <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client in: CONT > > 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous > > base64 data may contain sensitive data) > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client passdb > > out: OK 1 user=<username> > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: master in: > > REQUEST 4142792705 4846 1 > > cb2115241ccfd81959c15122ec062a8b session_pid=4849 > > request_auth_token > > Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: > > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): user search: > > base=DC=domain scope=subtree > > filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) > > fields=Initials > > > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: > > master(imap): Auth request timed out (received 0/12 bytes) > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login > > failure (pid=4846 id=1) (internal failure, 1 successful auths): > > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > > lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> > > Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: client in: > > CANCEL 1 > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > > close notify [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap: Error: Login client > > disconnected too early > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > > Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: auth client > > connected (pid=4868) > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > > Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x20, ret=1: SSL negotiation finished successfully > > [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: > > Debug: SSL: where=0x2002, ret=1: SSL negotiation finished > > successfully [<clientLAN_IP>] Sep 7 19:02:06 <dovecotServer> > > dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap > > secured session=ZjyONSsf6QAKHyZV lip=<dovecotServer_IP> > > rip=<clientLAN_IP> lport=993 rport=59881 Sep 7 19:02:06 > > <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 > > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client in: CONT > > 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous > > base64 data may contain sensitive data) > > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears > > to be hanging, reconnecting > > Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: > > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search > > returned multiple entries > > > > Sep 7 19:03:10 <dovecotServer> dovecot: imap: Error: Auth server > > request timed out after 155 secs (client-pid=4846 client-id=1) > > > > Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > > close notify [<clientLAN_IP>] > > Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: > > close notify [<clientLAN_IP>] > > > > Sep 7 19:04:36 <dovecotServer> dovecot: auth: Error: > > PLAIN(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Request 4868.1 > > timed out after 150 secs, state=1 > > > > Sep 7 19:05:05 <dovecotServer> dovecot: imap-login: Disconnected: > > Inactivity during authentication (disconnected while authenticating, > > waited 179 secs): user=<>, method=PLAIN, rip=<clientLAN_IP>, > > lip=<dovecotServer_IP>, TLS, session=<ZjyONSsf6QAKHyZV> > > Sep 7 19:05:05 <dovecotServer> dovecot: auth: Debug: client in: > > CANCEL > > > > Sep 7 19:06:06 <dovecotServer> dovecot: auth: > > ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): Shutting down > > Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: master userdb > > out: FAIL 4142792705 > > Sep 7 19:06:06 <dovecotServer> dovecot: auth: > > ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Shutting down > > Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: client passdb > > out: FAIL 1 user=<username> temp > > > > > > > > > > -------------------------- > > Log trace using PORT 3268: > > -------------------------- > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules > > from directory: /usr/lib64/dovecot/auth > > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: > > /usr/lib64/dovecot/auth/libdriver_sqlite.so > > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules > > from directory: /usr/lib64/dovecot/auth > > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: > > /usr/lib64/dovecot/auth/libauthdb_ldap.so > > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Read auth token > > secret from /var/run/dovecot/auth-token-secret.dat > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: auth client > > connected (pid=4971) > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] > > Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: > > where=0x20, ret=1: SSL negotiation finished successfully > > [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: > > Debug: SSL: where=0x2002, ret=1: SSL negotiation finished > > successfully [<clientLAN_IP>] Sep 7 19:33:08 <dovecotServer> > > dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap > > secured session=FAKKpCsf0AAKHyZV lip=<dovecotServer_IP> > > rip=<clientLAN_IP> lport=993 rport=61648 Sep 7 19:33:08 > > <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client in: CONT > > 1 AEN1bWMtNDM2MS0yAGZvcnRpbmV0LjIwMTQ= (previous base64 data may > > contain sensitive data) > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client passdb > > out: OK 1 user=<username> > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master in: > > REQUEST 3261071361 4971 1 > > 4755688f0bdd33a0fadcc5d3b8664e61 session_pid=4974 > > request_auth_token > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): user search: > > base=DC=domain scope=subtree > > filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) > > fields=Initials > > > > [Here start the difference between 389 and 3268 ports] > > > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): no fields returned > > by the server > > > > [Next line you can see missing attributes, due to I'm using port 3268] > > > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: > > ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): result: Initials > > missing > > Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master userdb > > out: USER 3261071361 <username> uid=1000 > > gid=1000 home=/home/mailstorage/<domain>/<username> > > auth_token=9191cdf475600f0a47e185bb65817c0e0f495894 > > Sep 7 19:33:08 <dovecotServer> dovecot: imap-login: Login: > > user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, > > lip=<dovecotServer_IP>, mpid=4974, TLS, session=<FAKKpCsf0AAKHyZV> > > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Loading modules > > from directory: /usr/lib64/dovecot > > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: > > /usr/lib64/dovecot/lib10_quota_plugin.so > > Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: > > /usr/lib64/dovecot/lib11_imap_quota_plugin.so > > Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: > > Effective uid=1000, gid=1000, > > home=/home/mailstorage/<domain>/<username> Sep 7 19:33:08 > > <dovecotServer> dovecot: imap(<username>): Debug: Quota root: > > name=CuotaUsuario backend=maildir args= Sep 7 19:33:08 > > <dovecotServer> dovecot: imap(<username>): Debug: Quota rule: > > root=CuotaUsuario mailbox=* bytes=2097152 messages=0 Sep 7 19:33:08 > > <dovecotServer> dovecot: imap(<username>): Debug: Quota grace: > > root=CuotaUsuario bytes=209715 (10%) Sep 7 19:33:08 <dovecotServer> > > dovecot: imap(<username>): Debug: Namespace inbox: type=private, > > prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes > > location=maildir:~/Maildir Sep 7 19:33:08 <dovecotServer> dovecot: > > imap(<username>): Debug: maildir++: > > root=/home/mailstorage/<domain>/<username>/Maildir, index=, > > indexpvt=, control=, > > inbox=/home/mailstorage/<domain>/<username>/Maildir, alt>
Fran
2015-Sep-10 11:10 UTC
My dovecot works fine against Active Directory 2003, but not against AD2008
Hi Matthias, thank you very much! that fixed the problem. I had workaround the problem by using "base = ou=xxxx, dc=dom", instead of "base = dc=dom" in the dovecot-ldap.conf.ext file, because that also worked (I don't know why, but the problem happen if you use as base just the domain, but not if you add a second level). But that forced to me to use several userdb/passdb blocks definitions, one for each OU in which I have users, so I think that your fix is better. I'm not able to understand the actual reason behind all this though... What's the technical explanation behind this behaviour?? I mean, it seems to be that the problem is that the Domain controller (DC) was sending a "referrals" answer and dovecot auth made a connection to these others DC but something wrong happened (dovecot can't deal correctly with that kind of answers?? I don't know). Anyways, as far as I know: 1) A referral answer should be done by a DC when it can't provide the object that the client are requesting 2) REFERRALS off in ldap.conf means that the client should not follow referrals returned by the DC So, if a referral answer is given from my DC, I think that is because such DC can't provide the object which the client is looking for, so, why works fine just by telling dovecot: "Don't follow referrals"? Regards El 09/09/2015 a las 17:22, Matthias Lay escribi?:> hi, > > check your > > /etc/openldap/ldap.conf > > for > > REFERRALS off > > I had this errors with "referrals on" in misconfigured dns environments. > > > you can debug the dns packets by strace-ing the auth process > > > > > On Tue, 8 Sep 2015 11:00:37 +0200 > Fran <cumc-4361-2 at chguadalquivir.es> wrote: > >> Hello, >> >> my dovecot installation has been working fine against AD till we >> upgrade from AD 2003 to AD 2008. As >> http://wiki2.dovecot.org/AuthDatabase/LDAP said, now I'm not able to >> connect AD through 389 port. The port 3268 works fine though. >> >> (...) >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: >> master(imap): Auth request timed out (received 0/12 bytes) >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login >> failure (pid=4846 id=1) (internal failure, 1 successful auths): >> user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, >> lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> >> (...) >> Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: >> ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears >> to be hanging, reconnecting >> Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: >> ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search >> returned multiple entries >> (...) >> >> Is there a technical reason for this problem? Does it exist any >> workaround? >> >> The use of Global Catalog (port 3268) is not a solution for me, since >> it misses many attributes. (ex. I use the field "initials" to set the >> quota and this field is not available through port 3268). >> >> I also noticed that, now, it uses any DC available in the domain, it >> doesn't care what I configured in "hosts = " parameter. >> >> This is using "hosts = dc03.domain:389": >> ----------------------------------------------- >> >> [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth >> tcp 22 0 <dovecotServer_IP>:55217 >> <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth >> tcp 22 0 <dovecotServer_IP>:57645 >> <dc06.domain_IP>:389 ESTABLISHED 4872/dovecot/auth >> tcp 0 0 <dovecotServer_IP>:55216 >> <dc03.domain_IP>:389 ESTABLISHED 4872/dovecot/auth >> >> It looks like it does a look up for other domains controller (I don't >> know how nor why) and it connect aleatory to any DC in my domain (in >> this case dc06.domain, but it changes any time), additionally to the >> configured one (dc03.domain). >> >> This is using "hosts = dc03.domain:3268": >> ------------------------------------------------ >> [root@<dovecotServer> ~]# netstat -anp | grep dovecot | grep auth >> tcp 0 0 <dovecotServer_IP>:58485 >> <dc03.domain_IP>:3268 ESTABLISHED 4982/dovecot/auth >> >> In this case, only the configured server in host parameter is used (I >> think this is the right behaviour) >> >> >> Aditional info: >> --------------- >> CentOS Linux release 7.0.1406 (Core) >> >> dovecot 2.2.10 >> >> Build options: ioloop=epoll notify=inotify ipv6 openssl >> io_block_size=8192 Mail storages: shared mdbox sdbox maildir mbox >> cydir imapc pop3c raw fail SQL driver plugins: mysql postgresql sqlite >> Passdb: checkpassword ldap pam passwd passwd-file shadow sql >> Userdb: checkpassword ldap(plugin) nss passwd prefetch passwd-file sql >> >> >> My /etc/dovecot/dovecot-ldap.conf.ext >> -------------------------------------- >> #hosts = dc03.domain:3268 >> hosts = dc03.domain:389 >> #uris = ldap://dc03.domain >> base = DC=domain >> #tls = yes >> tls = no >> ldap_version = 3 >> auth_bind = yes >> auth_bind_userdn = %u at domain >> #auth_bind_userdn = DOMAIN\%u >> dn = cn=<user>,cn=Users,dc=domain >> dnpass = <password> >> >> #scope = subtree >> #deref = never >> >> user_filter >> (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) >> pass_filter >> (&(userPrincipalName=%u at domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) >> pass_attrs = userPassword=password >> user_attrs = Initials=quota_rule=*:storage=%$MB >> --------------- >> >> >> -------------------------- >> Log trace using PORT 389: >> -------------------------- >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules >> from directory: /usr/lib64/dovecot/auth >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: >> /usr/lib64/dovecot/auth/libdriver_sqlite.so >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Loading modules >> from directory: /usr/lib64/dovecot/auth >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Module loaded: >> /usr/lib64/dovecot/auth/libauthdb_ldap.so >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: Read auth token >> secret from /var/run/dovecot/auth-token-secret.dat >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: auth client >> connected (pid=4846) >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] >> Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x20, ret=1: SSL negotiation finished successfully >> [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> dovecot: imap-login: >> Debug: SSL: where=0x2002, ret=1: SSL negotiation finished >> successfully [<clientLAN_IP>] Sep 7 19:00:35 <dovecotServer> >> dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap >> secured session=T+grMCsfqgAKHyZV lip=<dovecotServer_IP> >> rip=<clientLAN_IP> lport=993 rport=59818 Sep 7 19:00:35 >> <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client in: CONT >> 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous >> base64 data may contain sensitive data) >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: client passdb >> out: OK 1 user=<username> >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: master in: >> REQUEST 4142792705 4846 1 >> cb2115241ccfd81959c15122ec062a8b session_pid=4849 >> request_auth_token >> Sep 7 19:00:35 <dovecotServer> dovecot: auth: Debug: >> ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): user search: >> base=DC=domain scope=subtree >> filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) >> fields=Initials >> >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Error: >> master(imap): Auth request timed out (received 0/12 bytes) >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Internal login >> failure (pid=4846 id=1) (internal failure, 1 successful auths): >> user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, >> lip=<dovecotServer_IP>, TLS, session=<T+grMCsfqgAKHyZV> >> Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: client in: >> CANCEL 1 >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL alert: >> close notify [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap: Error: Login client >> disconnected too early >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges >> Sep 7 19:02:05 <dovecotServer> dovecot: auth: Debug: auth client >> connected (pid=4868) >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] >> Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x20, ret=1: SSL negotiation finished successfully >> [<clientLAN_IP>] Sep 7 19:02:05 <dovecotServer> dovecot: imap-login: >> Debug: SSL: where=0x2002, ret=1: SSL negotiation finished >> successfully [<clientLAN_IP>] Sep 7 19:02:06 <dovecotServer> >> dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap >> secured session=ZjyONSsf6QAKHyZV lip=<dovecotServer_IP> >> rip=<clientLAN_IP> lport=993 rport=59881 Sep 7 19:02:06 >> <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 >> Sep 7 19:02:06 <dovecotServer> dovecot: auth: Debug: client in: CONT >> 1 AEN1bWMtNDM2MS0yLXBydWViYQBDb3JyZW9DaGcuMTIzNDU2 (previous >> base64 data may contain sensitive data) >> Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: >> ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Connection appears >> to be hanging, reconnecting >> Sep 7 19:02:06 <dovecotServer> dovecot: auth: Error: >> ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): LDAP search >> returned multiple entries >> >> Sep 7 19:03:10 <dovecotServer> dovecot: imap: Error: Auth server >> request timed out after 155 secs (client-pid=4846 client-id=1) >> >> Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: >> close notify [<clientLAN_IP>] >> Sep 7 19:04:18 <dovecotServer> dovecot: imap-login: Debug: SSL alert: >> close notify [<clientLAN_IP>] >> >> Sep 7 19:04:36 <dovecotServer> dovecot: auth: Error: >> PLAIN(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Request 4868.1 >> timed out after 150 secs, state=1 >> >> Sep 7 19:05:05 <dovecotServer> dovecot: imap-login: Disconnected: >> Inactivity during authentication (disconnected while authenticating, >> waited 179 secs): user=<>, method=PLAIN, rip=<clientLAN_IP>, >> lip=<dovecotServer_IP>, TLS, session=<ZjyONSsf6QAKHyZV> >> Sep 7 19:05:05 <dovecotServer> dovecot: auth: Debug: client in: >> CANCEL >> >> Sep 7 19:06:06 <dovecotServer> dovecot: auth: >> ldap(<username>,<clientLAN_IP>,<T+grMCsfqgAKHyZV>): Shutting down >> Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: master userdb >> out: FAIL 4142792705 >> Sep 7 19:06:06 <dovecotServer> dovecot: auth: >> ldap(<username>,<clientLAN_IP>,<ZjyONSsf6QAKHyZV>): Shutting down >> Sep 7 19:06:06 <dovecotServer> dovecot: auth: Debug: client passdb >> out: FAIL 1 user=<username> temp >> >> >> >> >> -------------------------- >> Log trace using PORT 3268: >> -------------------------- >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x10, ret=1: before/accept initialization [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: before/accept initialization [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read client hello A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write server hello A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write certificate A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules >> from directory: /usr/lib64/dovecot/auth >> Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: >> /usr/lib64/dovecot/auth/libdriver_sqlite.so >> Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Loading modules >> from directory: /usr/lib64/dovecot/auth >> Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Module loaded: >> /usr/lib64/dovecot/auth/libauthdb_ldap.so >> Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: Read auth token >> secret from /var/run/dovecot/auth-token-secret.dat >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write key exchange A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write server done A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2002, ret=-1: SSLv3 read client certificate A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: auth: Debug: auth client >> connected (pid=4971) >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read client key exchange A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 read finished A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write session ticket A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write change cipher spec A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 write finished A [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x2001, ret=1: SSLv3 flush data [<clientLAN_IP>] >> Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: Debug: SSL: >> where=0x20, ret=1: SSL negotiation finished successfully >> [<clientLAN_IP>] Sep 7 19:33:07 <dovecotServer> dovecot: imap-login: >> Debug: SSL: where=0x2002, ret=1: SSL negotiation finished >> successfully [<clientLAN_IP>] Sep 7 19:33:08 <dovecotServer> >> dovecot: auth: Debug: client in: AUTH 1 PLAIN service=imap >> secured session=FAKKpCsf0AAKHyZV lip=<dovecotServer_IP> >> rip=<clientLAN_IP> lport=993 rport=61648 Sep 7 19:33:08 >> <dovecotServer> dovecot: auth: Debug: client passdb out: CONT 1 >> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client in: CONT >> 1 AEN1bWMtNDM2MS0yAGZvcnRpbmV0LjIwMTQ= (previous base64 data may >> contain sensitive data) >> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: client passdb >> out: OK 1 user=<username> >> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master in: >> REQUEST 3261071361 4971 1 >> 4755688f0bdd33a0fadcc5d3b8664e61 session_pid=4974 >> request_auth_token >> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: >> ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): user search: >> base=DC=domain scope=subtree >> filter=(&(userPrincipalName=<username>@domain)(objectClass=person)(|(mail=<username>@<domain>)(othermailbox=<username>@<domain>))) >> fields=Initials >> >> [Here start the difference between 389 and 3268 ports] >> >> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: >> ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): no fields returned >> by the server >> >> [Next line you can see missing attributes, due to I'm using port 3268] >> >> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: >> ldap(<username>,<clientLAN_IP>,<FAKKpCsf0AAKHyZV>): result: Initials >> missing >> Sep 7 19:33:08 <dovecotServer> dovecot: auth: Debug: master userdb >> out: USER 3261071361 <username> uid=1000 >> gid=1000 home=/home/mailstorage/<domain>/<username> >> auth_token=9191cdf475600f0a47e185bb65817c0e0f495894 >> Sep 7 19:33:08 <dovecotServer> dovecot: imap-login: Login: >> user=<<username>>, method=PLAIN, rip=<clientLAN_IP>, >> lip=<dovecotServer_IP>, mpid=4974, TLS, session=<FAKKpCsf0AAKHyZV> >> Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Loading modules >> from directory: /usr/lib64/dovecot >> Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: >> /usr/lib64/dovecot/lib10_quota_plugin.so >> Sep 7 19:33:08 <dovecotServer> dovecot: imap: Debug: Module loaded: >> /usr/lib64/dovecot/lib11_imap_quota_plugin.so >> Sep 7 19:33:08 <dovecotServer> dovecot: imap(<username>): Debug: >> Effective uid=1000, gid=1000, >> home=/home/mailstorage/<domain>/<username> Sep 7 19:33:08 >> <dovecotServer> dovecot: imap(<username>): Debug: Quota root: >> name=CuotaUsuario backend=maildir args= Sep 7 19:33:08 >> <dovecotServer> dovecot: imap(<username>): Debug: Quota rule: >> root=CuotaUsuario mailbox=* bytes=2097152 messages=0 Sep 7 19:33:08 >> <dovecotServer> dovecot: imap(<username>): Debug: Quota grace: >> root=CuotaUsuario bytes=209715 (10%) Sep 7 19:33:08 <dovecotServer> >> dovecot: imap(<username>): Debug: Namespace inbox: type=private, >> prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes >> location=maildir:~/Maildir Sep 7 19:33:08 <dovecotServer> dovecot: >> imap(<username>): Debug: maildir++: >> root=/home/mailstorage/<domain>/<username>/Maildir, index=, >> indexpvt=, control=, >> inbox=/home/mailstorage/<domain>/<username>/Maildir, alt=
Seemingly Similar Threads
- My dovecot works fine against Active Directory 2003, but not against AD2008
- My dovecot works fine against Active Directory 2003, but not against AD2008
- My dovecot works fine against Active Directory 2003, but not against AD2008
- TLS not working with iOS beta?
- Dovecot IMAPS : Thunderbird SSL cert issue / Evolution OK