My dovecot works fine against Active Directory 2003, but not against AD2008

Fran cumc-4361-2 at chguadalquivir.es
Thu Sep 10 11:10:57 UTC 2015


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=


More information about the dovecot mailing list