- dovecot - dovecot.org

no login with MySQL
by Andreas Meyer 14 Sep '15

14 Sep '15

Hello! Setup again to authenticate my users with MySQL but can't login. Sep 13 11:55:49 auth: Info: passwd-file(a.meyer(a)nimmini.de,95.88.63.177,<R7Qe9J0fTgBfWD+x>): unknown user Sep 13 11:55:49 auth: Info: passwd-file(a.meyer(a)nimmini.de,95.88.63.177,<R7Qe9J0fTgBfWD+x>): unknown user Sep 13 11:55:49 imap-login: Info: Login: user=<a.meyer(a)nimmini.de>, method=CRAM-MD5, rip=95.88.63.177, lip=46.38.231.143, mpid=30826, TLS, TLSv1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits) Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Error: user a.meyer(a)nimmini.de: Initialization failed: Namespace '': Home directory not set for user. Can't expand ~/ for mail root dir in: ~/ Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Error: Invalid user settings. Refer to server log for more information. Sep 13 11:55:49 auth: Debug: auth client connected (pid=30825) Sep 13 11:55:49 auth: Debug: client in: AUTH 1 CRAM-MD5 service=imap secured session=R7Qe9J0fTgBfWD+x lip=46.38.231.143 rip=95.88.63.177 lport=143 rport=45646 Sep 13 11:55:49 auth: Debug: client passdb out: CONT 1 PDkzMDcwNTI5Mzk5NTk1NTYuMTQ0MjEzODE0OUBiaXRtYWNoaW5lMT4= Sep 13 11:55:49 auth: Debug: client in: CONT<hidden> Sep 13 11:55:49 auth: Debug: passwd-file(a.meyer(a)nimmini.de,95.88.63.177,<R7Qe9J0fTgBfWD+x>): lookup: user=a.meyer(a)nimmini.de file=/etc/dovecot/passwd Sep 13 11:55:49 auth-worker(30822): Debug: sql(a.meyer(a)nimmini.de,95.88.63.177): query: SELECT username AS username, password FROM mailbox WHERE username = 'a.meyer(a)nimmini.de' AND active = 1 Sep 13 11:55:49 auth: Debug: client passdb out: OK 1 user=a.meyer(a)nimmini.de Sep 13 11:55:49 auth: Debug: master in: REQUEST 997457921 30821 1 dc2456b4ee1453e5458806ab92da9ee7 session_pid=30826 request_auth_token Sep 13 11:55:49 auth: Debug: passwd-file(a.meyer(a)nimmini.de,95.88.63.177,<R7Qe9J0fTgBfWD+x>): lookup: user=a.meyer(a)nimmini.de file=/etc/dovecot/passwd Sep 13 11:55:49 auth-worker(30822): Debug: passwd-file(a.meyer(a)nimmini.de,95.88.63.177): SELECT maildir, uid, gid, concat('*:storage=', quota) AS quota_rule, concat('Trash:storage=+', quota_trash) AS quota_rule2 FROM mailbox WHERE username = 'a.meyer(a)nimmini.de' Sep 13 11:55:49 auth: Debug: master userdb out: USER 997457921 a.meyer(a)nimmini.de maildir=/var/spool/vhosts/nimmini.de/ uid=5000 gid=5000 quota_rule=*:storage=5242880 quota_rule2=Trash:storage=+100 auth_token=2a4c8e78ff8fcf3f9599eecbefb6a5605f22abe5 Sep 13 11:55:49 imap: Debug: Loading modules from directory: /usr/lib64/dovecot/modules Sep 13 11:55:49 imap: Debug: Module loaded: /usr/lib64/dovecot/modules/lib01_acl_plugin.so Sep 13 11:55:49 imap: Debug: Module loaded: /usr/lib64/dovecot/modules/lib02_imap_acl_plugin.so Sep 13 11:55:49 imap: Debug: Module loaded: /usr/lib64/dovecot/modules/lib10_quota_plugin.so Sep 13 11:55:49 imap: Debug: Module loaded: /usr/lib64/dovecot/modules/lib11_imap_quota_plugin.so Sep 13 11:55:49 imap: Debug: Added userdb setting: plugin/maildir=/var/spool/vhosts/nimmini.de/ Sep 13 11:55:49 imap: Debug: Added userdb setting: plugin/quota_rule=*:storage=5242880 Sep 13 11:55:49 imap: Debug: Added userdb setting: plugin/quota_rule2=Trash:storage=+100 Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Debug: Effective uid=5000, gid=5000, home= Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Debug: Quota root: name=User quota backend=maildir args= Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Debug: Quota rule: root=User quota mailbox=* bytes=5368709120 messages=0 Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Debug: Quota rule: root=User quota mailbox=Trash bytes=+102400 messages=0 Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Debug: Quota grace: root=User quota bytes=53687091 (1%) Sep 13 11:55:49 imap(a.meyer(a)nimmini.de): Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/ This is what claws-mail says: [12:22:48] IMAP4< * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=CRAM-MD5] Dovecot ready. [12:22:48] IMAP4> 1 STARTTLS [12:22:48] IMAP4< 1 OK Begin TLS negotiation now. * IMAP connection is un-authenticated [12:22:48] IMAP4> 2 CAPABILITY [12:22:48] IMAP4< * CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE AUTH=PLAIN AUTH=CRAM-MD5 [12:22:48] IMAP4< 2 OK Pre-login capabilities listed, post-login capabilities have more. [12:22:48] IMAP4> Logging a.meyer(a)nimmini.de to mail.nimmini.de using CRAM-MD5 ** IMAP Fehler auf mail.nimmini.de: parse error (sehr wahrscheinlich ein nicht RFC-konformer Server) ** IMAP4-Verbindung unterbrochen [12:22:48] IMAP4< Error logging in to mail.nimmini.de When I set auth_type PLAIN in Roundcube, login fails too. The SELECTS in the database are ok: mysql> SELECT maildir, uid, gid, concat('*:storage=', quota) AS quota_rule, concat('Trash:storage=+', quota_trash) AS quota_rule2 FROM mailbox WHERE username = 'a.meyer(a)nimmini.de'; +-------------------------------+------+------+-------------------+--------------------+ | maildir | uid | gid | quota_rule | quota_rule2 | +-------------------------------+------+------+-------------------+--------------------+ | /var/spool/vhosts/nimmini.de/ | 5000 | 5000 | *:storage=5242880 | Trash:storage=+100 | +-------------------------------+------+------+-------------------+--------------------+ 1 row in set (0,00 sec) mysql> SELECT username AS username, password FROM mailbox WHERE username = 'a.meyer(a)nimmini.de' AND active = 1 -> ; +--------------------+----------+ | username | password | +--------------------+----------+ | a.meyer(a)nimmini.de | hidden | +--------------------+----------+ 1 row in set (0,00 sec) mysql> quit What's wrong? Any help appreciated! Regards Andreas

4 7

concerning dovecot settings for high volume server
by Rajesh M 13 Sep '15

13 Sep '15

hi centos 6 64 bit hex core processor with hyperthreading ie display shows 12 cores 16 gb ram 600 gb 15000 rpm drive we are having around 4000 users on a server i wish to allow 1500 pop3 and 1500 imap connections simultaneously. need help regarding the settings to handle the above imap-login, pop3-login imap pop3 service settings i recently i got an error imap-login: Error: read(imap) failed: Remote closed connection (process_limit reached?) my current dovecot config file # 2.2.7: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-431.23.3.el6.x86_64 x86_64 CentOS release 6.5 (Final) auth_cache_negative_ttl = 0 auth_cache_ttl = 0 auth_mechanisms = plain login digest-md5 cram-md5 default_login_user = vpopmail disable_plaintext_auth = no first_valid_gid = 89 first_valid_uid = 89 log_path = /var/log/dovecot.log login_greeting = ready. mail_max_userip_connections = 50 mail_plugins = " quota" managesieve_notify_capability = mailto managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave namespace { inbox = yes location = prefix = separator = . type = private } passdb { args = cache_key=%u webmail=127.0.0.1 driver = vpopmail } plugin { quota = maildir:ignore=Trash quota_rule = ?:storage=0 } protocols = imap pop3 service imap-login { client_limit = 256 process_limit = 400 process_min_avail = 4 service_count = 0 vsz_limit = 512 M } service pop3-login { client_limit = 1000 process_limit = 400 process_min_avail = 12 service_count = 0 vsz_limit = 512 M } ssl_cert = </var/qmail/control/servercert.pem ssl_dh_parameters_length = 2048 ssl_key = </var/qmail/control/servercert.pem userdb { args = cache_key=%u quota_template=quota_rule=*:backend=%q driver = vpopmail } protocol imap { imap_client_workarounds = delay-newmail mail_plugins = " quota imap_quota" } protocol pop3 { pop3_client_workarounds = outlook-no-nuls oe-ns-eoh pop3_fast_size_lookups = yes pop3_lock_session = no pop3_no_flag_updates = yes } thanks very much, rajesh

5 4

Re: concerning dovecot settings for high volume server
by Rajesh M 13 Sep '15

13 Sep '15

----- Original Message ----- From: Tony Morehen [mailto:tmorehen@ajmconsulting.ca] To: dovecot(a)dovecot.org Sent: Sat, 12 Sep 2015 17:57:27 -0400 Subject: Re: concerning dovecot settings for high volume server You may be running up against Linux system/user limits. Run $ cat /proc/sys/kernel/pid_max and $ ulimit -a That should give some insight into your problem. On 12/09/2015 2:53 PM, Rajesh M wrote: > hi > > centos 6 64 bit > > hex core processor with hyperthreading ie display shows 12 cores > 16 gb ram > 600 gb 15000 rpm drive > > we are having around 4000 users on a server > > > i wish to allow 1500 pop3 and 1500 imap connections simultaneously. > > need help regarding the settings to handle the above > > imap-login, pop3-login > imap pop3 service settings > > i recently i got an error > imap-login: Error: read(imap) failed: Remote closed connection (process_limit reached?) > > > my current dovecot config file > > # 2.2.7: /etc/dovecot/dovecot.conf > # OS: Linux 2.6.32-431.23.3.el6.x86_64 x86_64 CentOS release 6.5 (Final) > auth_cache_negative_ttl = 0 > auth_cache_ttl = 0 > auth_mechanisms = plain login digest-md5 cram-md5 > default_login_user = vpopmail > disable_plaintext_auth = no > first_valid_gid = 89 > first_valid_uid = 89 > log_path = /var/log/dovecot.log > login_greeting = ready. > mail_max_userip_connections = 50 > mail_plugins = " quota" > managesieve_notify_capability = mailto > managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave > namespace { > inbox = yes > location = > prefix = > separator = . > type = private > } > passdb { > args = cache_key=%u webmail=127.0.0.1 > driver = vpopmail > } > plugin { > quota = maildir:ignore=Trash > quota_rule = ?:storage=0 > } > protocols = imap pop3 > service imap-login { > client_limit = 256 > process_limit = 400 > process_min_avail = 4 > service_count = 0 > vsz_limit = 512 M > } > service pop3-login { > client_limit = 1000 > process_limit = 400 > process_min_avail = 12 > service_count = 0 > vsz_limit = 512 M > } > ssl_cert = </var/qmail/control/servercert.pem > ssl_dh_parameters_length = 2048 > ssl_key = </var/qmail/control/servercert.pem > userdb { > args = cache_key=%u quota_template=quota_rule=*:backend=%q > driver = vpopmail > } > protocol imap { > imap_client_workarounds = delay-newmail > mail_plugins = " quota imap_quota" > } > protocol pop3 { > pop3_client_workarounds = outlook-no-nuls oe-ns-eoh > pop3_fast_size_lookups = yes > pop3_lock_session = no > pop3_no_flag_updates = yes > } > > > thanks very much, > > rajesh this is the first time i got this message since past over an year. the error went away as soon as i restarted dovecot.. surprisingly this happened in the night ie off-office hours. here are the values i got also could you provide me the settings for the limits if wish to handle around 1500 simultaneous connections of pop3 and imap each ? the current values are as follows [root@ns1 log]# cat /proc/sys/kernel/pid_max 49152 [root@ns1 log]# ulimit -a core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 127047 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 1024 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 127047 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited thanks rajesh

2 1

Need help on checkpassword userdb/passdb
by Mark Foley 13 Sep '15

13 Sep '15

I'm experimenting with checkpassword as an auth method for usedb and passdb (http://wiki2.dovecot.org/AuthDatabase/CheckPassword) I've set up the userdb and passdb *exactly* as the wiki suggests as the "standard way": passdb { driver = checkpassword args = /user/util/bin/checkpassword } userdb { driver = prefetch } I've created a checkpassword program that does receive the correct user and password from dovecot. And I am successfully authenticating with ntlm_auth and exiting with status 0. My debug output: AUTHORIZED: (null) USER: (null) userdb_uid: (null) userdb_gid: (null) arg1=/usr/local/libexec/dovecot/checkpassword-reply CMD: /usr/bin/ntlm_auth --username="mark" --password='mypass' ntlm_auth status: 0 Now, the wiki says 2 things that have me stumped: 1. It says that, "Dovecot calls the script with AUTHORIZED=1 environment set when performing a userdb lookup. The script must acknowledge this by changing the environment to AUTHORIZED=2, otherwise the lookup fails." As you can see from my program log, "AUTHORIZED" is not set. Why? Nor are any of the other environment variables mentioned in the wiki. I've listed all the environment variables that *are* passed to the program at the bottom of this message. 2. The wiki says, "Your program received a path to checkpassword-reply binary as the first parameter. Execute it." I did so as a fork() and then execve("/usr/local/libexec/dovecot/checkpassword-reply") How do I know it worked ... or failed? What am I doing wrong? Dovecot log entries: Sep 10 22:54:04 auth: Debug: auth client connected (pid=14748) Sep 10 22:54:04 auth: Debug: client in: AUTH 1 PLAIN service=imap session=AkYg1G8f8QDAqAA6 lip=192.168.0.2 rip=192.168.0.58 lport=143 rport=49649 resp=AG1hcmsAZ2xhY29uXzk= (previous base64 data may contain sensitive data) Sep 10 22:54:04 auth: Debug: checkpassword(mark,192.168.0.58,<AkYg1G8f8QDAqAA6>): execute: /user/util/bin/checkpassword /usr/local/libexec/dovecot/checkpassword-reply Sep 10 22:54:04 auth: Debug: checkpassword(mark,192.168.0.58,<AkYg1G8f8QDAqAA6>): exit_status=0 Sep 10 22:54:04 auth: Debug: checkpassword(mark,192.168.0.58,<AkYg1G8f8QDAqAA6>): Received input: Sep 10 22:54:06 auth: Debug: client passdb out: FAIL 1 user=mark temp ENV variables passed to the checkpassword program: DOVECOT_PRESERVE_ENVS=TZ CORE_OUTOFMEM CORE_ERROR DOVECOT_CHILD_PROCESS=1 CONFIG_FILE=/usr/local/var/run/dovecot/config CLIENT_LIMIT=1000 PROCESS_LIMIT=1 PROCESS_MIN_AVAIL=0 IDLE_KILL=60 GENERATION=2991 DOVECOT_HOSTNAME=mail DOVECOT_HOSTDOMAIN=mail.hprs.local DOVECOT_VERSION=2.2.15 LOG_SERVICE=1 SOCKET_COUNT=6 SSL_SOCKET_COUNT=0 SOCKET_NAMES=login tokenlogin auth-login auth-client auth-userdb auth-master PROTO=TCP ORIG_UID=151 SERVICE=imap TCPLOCALIP=192.168.0.2 LOCAL_IP=192.168.0.2 TCPREMOTEIP=192.168.0.58 REMOTE_IP=192.168.0.58 TCPLOCALPORT=143 TCPREMOTEPORT=49649 AUTH_USER=mark AUTH_USERNAME=mark AUTH_SERVICE=imap AUTH_LIP=192.168.0.2 AUTH_RIP=192.168.0.58 AUTH_PID=14748 AUTH_MECH=PLAIN AUTH_SECURED= AUTH_LPORT=143 AUTH_RPORT=49649 AUTH_CERT= AUTH_SESSION=AkYg1G8f8QDAqAA6 AUTH_REAL_LIP=192.168.0.2 AUTH_REAL_RIP=192.168.0.58 AUTH_REAL_LPORT=143 AUTH_REAL_RPORT=49649 AUTH_ORIG_USER=mark AUTH_ORIG_USERNAME=mark --Mark

1 2

Is it a bug when you move mail between namespaces....
by Larry Rosenman 11 Sep '15

11 Sep '15

that the fts data gets lost? doveconf -n attached -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 214-642-9640 (c) E-Mail: larryrtx(a)gmail.com US Mail: 7011 W Parmer Ln, Apt 1115, Austin, TX 78729-6961

2 8

Dovecot CalDAV server
by Timo Sirainen 11 Sep '15

11 Sep '15

I've been once in a while over the years thinking about implementing CalDAV (and CardDAV) to Dovecot. It might be time to start that soon. Does anyone have any suggestions? So far my main goals would be: - scalable, of course - configurable storage (object storage, regular fs, maybe some key-value dbs, maybe storing as emails) - efficient indexes (potentially using key-value dbs? or maybe just local files. not sure yet what kind of indexing is needed) - have it work with dsync (= replication & migration) Some things I wonder about: - Maybe there is already some code out there that could be used to implement it faster? - Maybe even use something else besides C to implement it.. Then again that makes integration to Dovecot more difficult. - Is anybody interested in helping to develop this? :) I think I still have too much other work that I won't spend a lot of time coding it.. One thing that makes this easier is that Open-Xchange has already implemented a CalDAV server, so they can help to avoid the biggest design mistakes. (There are a couple of reasons why they'd want to replace that.)

11 13

Re: Message moved to Spam folder mysteriously
by Alfredo Saldanha 11 Sep '15

11 Sep '15

Hello Robert, I've checked, there is no client connected according my imap logs. So weird. ----- Mensagem original ----- De: "Robert Schetterer" <rs(a)sys4.de> Para: dovecot(a)dovecot.org Enviadas: Quinta-feira, 10 de setembro de 2015 15:48:47 Assunto: Re: Message moved to Spam folder mysteriously Am 10.09.2015 um 20:02 schrieb Alfredo Saldanha: > Hi there, > > How dovecot move the message to Spam without antispam plugin installed or sieve rule to move to this folder? > I have no configuration to do this. > > My logs: > Sep 10 12:12:44 mda02 dovecot: imap(my.user(a)mydomain.com): Warning: Inotify instance limit for user 5000 (UID vmail) exceeded, disabling. Increase /proc/sys/fs/inotify/max_user_instances > Sep 10 12:12:45 mda02 dovecot: imap(my.user(a)mydomain.com): copy from INBOX: box=Spam, uid=134, msgid=<466c888b2179f7e2c0fc74b186396785(a)mydomain.com>, size=2838 > Sep 10 12:12:45 mda02 dovecot: imap(my.user(a)mydomain.com): expunge: box=INBOX, uid=826, msgid=<466c888b2179f7e2c0fc74b186396785(a)mydomain.com>, size=2838 > > I don't have any client connected at the imap server in this time. Double check this, usally i.e Thunderbird use its only antispam solution to move mails into spam folder if they exist and configured > > Some tip? > > BR, > > Alfredo > Best Regards MfG Robert Schetterer -- [*] sys4 AG http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263 Vorstand: Patrick Ben Koetter, Marc Schiffbauer Aufsichtsratsvorsitzender: Florian Kirstein

1 0

Re: Message moved to Spam folder mysteriously
by Alfredo Saldanha 11 Sep '15

11 Sep '15

Hi Larry, I have nothing. ----- Mensagem original ----- De: "Larry Rosenman" <larryrtx(a)gmail.com> Para: "Alfredo Saldanha" <asaldanha(a)infolink.com.br> Cc: "Dovecot Mailing List" <dovecot(a)dovecot.org> Enviadas: Quinta-feira, 10 de setembro de 2015 15:04:38 Assunto: Re: Message moved to Spam folder mysteriously Do you have SIeve(pigeonhole) with rules? Or an Anti-Spam proxy in front of Dovecot? On Thu, Sep 10, 2015 at 1:02 PM, Alfredo Saldanha < asaldanha(a)infolink.com.br > wrote: Hi there, How dovecot move the message to Spam without antispam plugin installed or sieve rule to move to this folder? I have no configuration to do this. My logs: Sep 10 12:12:44 mda02 dovecot: imap( my.user(a)mydomain.com ): Warning: Inotify instance limit for user 5000 (UID vmail) exceeded, disabling. Increase /proc/sys/fs/inotify/max_user_instances Sep 10 12:12:45 mda02 dovecot: imap( my.user(a)mydomain.com ): copy from INBOX: box=Spam, uid=134, msgid=< 466c888b2179f7e2c0fc74b186396785(a)mydomain.com >, size=2838 Sep 10 12:12:45 mda02 dovecot: imap( my.user(a)mydomain.com ): expunge: box=INBOX, uid=826, msgid=< 466c888b2179f7e2c0fc74b186396785(a)mydomain.com >, size=2838 I don't have any client connected at the imap server in this time. Some tip? BR, Alfredo -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 214-642-9640 (c) E-Mail: larryrtx(a)gmail.com US Mail: 7011 W Parmer Ln, Apt 1115, Austin, TX 78729-6961

1 0

Message moved to Spam folder mysteriously
by Alfredo Saldanha 10 Sep '15

10 Sep '15

Hi there, How dovecot move the message to Spam without antispam plugin installed or sieve rule to move to this folder? I have no configuration to do this. My logs: Sep 10 12:12:44 mda02 dovecot: imap(my.user(a)mydomain.com): Warning: Inotify instance limit for user 5000 (UID vmail) exceeded, disabling. Increase /proc/sys/fs/inotify/max_user_instances Sep 10 12:12:45 mda02 dovecot: imap(my.user(a)mydomain.com): copy from INBOX: box=Spam, uid=134, msgid=<466c888b2179f7e2c0fc74b186396785(a)mydomain.com>, size=2838 Sep 10 12:12:45 mda02 dovecot: imap(my.user(a)mydomain.com): expunge: box=INBOX, uid=826, msgid=<466c888b2179f7e2c0fc74b186396785(a)mydomain.com>, size=2838 I don't have any client connected at the imap server in this time. Some tip? BR, Alfredo

3 2

My dovecot works fine against Active Directory 2003, but not against AD2008
by Fran 10 Sep '15

10 Sep '15

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@domain #auth_bind_userdn = DOMAIN\%u dn = cn=<user>,cn=Users,dc=domain dnpass = <password> #scope = subtree #deref = never user_filter = (&(userPrincipalName=%u@domain)(objectClass=person)(|(mail=%u@<domain>)(othermailbox=%u@<domain>))) pass_filter = (&(userPrincipalName=%u@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=

3 7