dovecot - May 2010 - dovecot from debian lenny-backports does not accept connections

hi,

dovecot from the debian lenny backports does not successfully accept 
incomming imap or imaps connections;
when the client connect i can see the clients ip address in an 
imap-process but the client cannot succesfully connect and retries this 
several times where an new imap-process is bound until the maximum 
connections per client is reached;
when the client is closed the imap-processes on the server stay opened, 
even when dovecot will be restarted or stopped - the processes needs to 
killed manually;


--- snip ---
2010-05-14 02:24:42 auth(default): Info: client in: AUTH        1       
PLAIN   service=imap    secured     lip=y.y.y.y      rip=x.x.x.x      
lport=993       rport=1411
2010-05-14 02:24:42 auth(default): Info: client out: CONT       1
2010-05-14 02:24:42 auth(default): Info: client in: CONT        1       
AGFsZXhAdXZzdCrhdAB5YWxpbWVybw=2010-05-14 02:24:42 auth-worker(default): Info: 
sql(alex at domain.tld,x.x.x.x): query: SELECT username AS user, password, 
'/var/vmail/domain.tld/alex' AS userdb_home, 
'maildir:/var/vmail/domain.tld/alex' AS userdb_mail, 150 AS userdb_uid, 
8 AS userdb_gid FROM mailbox WHERE username = 'alex at domain.tld' AND 
active = '1'
2010-05-14 02:24:42 auth(default): Info: client out: OK 1       
user=alex at domain.tld
2010-05-14 02:24:42 auth(default): Info: master in: REQUEST     2       
2177    1
2010-05-14 02:24:42 auth(default): Info: 
prefetch(alex at domain.tld,x.x.x.x): success
2010-05-14 02:24:42 auth(default): Info: master out: USER       2       
alex at domain.tld    home=/var/vmail/domain.tld/alex        
mail=maildir:/var/vmail/domain.tld/alex    uid=150 gid=8
2010-05-14 02:24:42 imap-login: Info: Login: user=<alex at domain.tld>, 
method=PLAIN, rip=x.x.x.x, lip=y.y.y.y, TLS
2010-05-14 02:24:42 IMAP(alex at domain.tld): Info: Loading modules from 
directory: /usr/lib/dovecot/modules/imap
2010-05-14 02:24:42 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib10_quota_plugin.so
2010-05-14 02:24:42 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib11_imap_quota_plugin.so
2010-05-14 02:24:42 IMAP(alex at domain.tld): Info: Effective uid=150, 
gid=8, home=/var/vmail/domain.tld/alex
2010-05-14 02:24:42 IMAP(alex at domain.tld): Info: Quota root: 
name=storage=102400 backend=maildir args2010-05-14 02:24:42 IMAP(alex at
domain.tld): Info: maildir:
data=/var/vmail/domain.tld/alex
2010-05-14 02:24:42 IMAP(alex at domain.tld): Info: maildir++: 
root=/var/vmail/domain.tld/alex, index=, control=, 
inbox=/var/vmail/domain.tld/alex
2010-05-14 02:24:42 auth(default): Info: new auth connection: pid=2186
2010-05-14 02:24:45 auth(default): Info: client in: AUTH        1       
PLAIN   service=imap    secured     lip=y.y.y.y      rip=x.x.x.x      
lport=993       rport=1412
2010-05-14 02:24:45 auth(default): Info: client out: CONT       1
2010-05-14 02:24:45 auth(default): Info: client in: CONT        1       
AGFsZXhAdXZzdCrhdAB5YWxpbWVybw=2010-05-14 02:24:45 auth-worker(default): Info: 
sql(alex at domain.tld,x.x.x.x): query: SELECT username AS user, password, 
'/var/vmail/domain.tld/alex' AS userdb_home, 
'maildir:/var/vmail/domain.tld/alex' AS userdb_mail, 150 AS userdb_uid, 
8 AS userdb_gid FROM mailbox WHERE username = 'alex at domain.tld' AND 
active = '1'
2010-05-14 02:24:45 auth(default): Info: client out: OK 1       
user=alex at domain.tld
2010-05-14 02:24:45 auth(default): Info: master in: REQUEST     3       
2075    1
2010-05-14 02:24:45 auth(default): Info: 
prefetch(alex at domain.tld,x.x.x.x): success
2010-05-14 02:24:45 auth(default): Info: master out: USER       3       
alex at domain.tld    home=/var/vmail/domain.tld/alex        
mail=maildir:/var/vmail/domain.tld/alex    uid=150 gid=8
2010-05-14 02:24:45 imap-login: Info: Login: user=<alex at domain.tld>, 
method=PLAIN, rip=x.x.x.x, lip=y.y.y.y, TLS
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Loading modules from 
directory: /usr/lib/dovecot/modules/imap
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib10_quota_plugin.so
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib11_imap_quota_plugin.so
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Effective uid=150, 
gid=8, home=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Quota root: 
name=storage=102400 backend=maildir args2010-05-14 02:24:45 IMAP(alex at
domain.tld): Info: maildir:
data=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: maildir++: 
root=/var/vmail/domain.tld/alex, index=, control=, 
inbox=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 auth(default): Info: new auth connection: pid=2189
2010-05-14 02:24:45 auth(default): Info: new auth connection: pid=2188
2010-05-14 02:24:45 auth(default): Info: client in: AUTH        1       
PLAIN   service=imap    secured     lip=y.y.y.y      rip=x.x.x.x      
lport=993       rport=1413
2010-05-14 02:24:45 auth(default): Info: client out: CONT       1
2010-05-14 02:24:45 auth(default): Info: client in: CONT        1       
AGFsZXhAdXZzdC5hdABrYWxpbWVybw=2010-05-14 02:24:45 auth-worker(default): Info: 
sql(alex at domain.tld,x.x.x.x): query: SELECT username AS user, password, 
'/var/vmail/domain.tld/alex' AS userdb_home, 
'maildir:/var/vmail/domain.tld/alex' AS userdb_mail, 150 AS userdb_uid, 
8 AS userdb_gid FROM mailbox WHERE username = 'alex at domain.tld' AND 
active = '1'
2010-05-14 02:24:45 auth(default): Info: client out: OK 1       
user=alex at domain.tld
2010-05-14 02:24:45 auth(default): Info: master in: REQUEST     4       
2186    1
2010-05-14 02:24:45 auth(default): Info: 
prefetch(alex at domain.tld,x.x.x.x): success
2010-05-14 02:24:45 auth(default): Info: master out: USER       4       
alex at domain.tld    home=/var/vmail/domain.tld/alex        
mail=maildir:/var/vmail/domain.tld/alex    uid=150 gid=8
2010-05-14 02:24:45 imap-login: Info: Login: user=<alex at domain.tld>, 
method=PLAIN, rip=x.x.x.x, lip=y.y.y.y, TLS
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Loading modules from 
directory: /usr/lib/dovecot/modules/imap
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib10_quota_plugin.so
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib11_imap_quota_plugin.so
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Effective uid=150, 
gid=8, home=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Quota root: 
name=storage=102400 backend=maildir args2010-05-14 02:24:45 IMAP(alex at
domain.tld): Info: maildir:
data=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: maildir++: 
root=/var/vmail/domain.tld/alex, index=, control=, 
inbox=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 auth(default): Info: client in: AUTH        1       
PLAIN   service=imap    secured     lip=y.y.y.y      rip=x.x.x.x      
lport=993       rport=1414
2010-05-14 02:24:45 auth(default): Info: client out: CONT       1
2010-05-14 02:24:45 auth(default): Info: client in: CONT        1       
AGFsZXhAdXZzdC5hdABrYWxpbWVybw=2010-05-14 02:24:45 auth-worker(default): Info: 
sql(alex at domain.tld,x.x.x.x): query: SELECT username AS user, password, 
'/var/vmail/domain.tld/alex' AS userdb_home, 
'maildir:/var/vmail/domain.tld/alex' AS userdb_mail, 150 AS userdb_uid, 
8 AS userdb_gid FROM mailbox WHERE username = 'alex at domain.tld' AND 
active = '1'
2010-05-14 02:24:45 auth(default): Info: client out: OK 1       
user=alex at domain.tld
2010-05-14 02:24:45 auth(default): Info: master in: REQUEST     5       
2188    1
2010-05-14 02:24:45 auth(default): Info: 
prefetch(alex at domain.tld,x.x.x.x): success
2010-05-14 02:24:45 auth(default): Info: master out: USER       5       
alex at domain.tld    home=/var/vmail/domain.tld/alex        
mail=maildir:/var/vmail/domain.tld/alex    uid=150 gid=8
2010-05-14 02:24:45 imap-login: Info: Login: user=<alex at domain.tld>, 
method=PLAIN, rip=x.x.x.x, lip=y.y.y.y, TLS
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Loading modules from 
directory: /usr/lib/dovecot/modules/imap
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib10_quota_plugin.so
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Module loaded: 
/usr/lib/dovecot/modules/imap/lib11_imap_quota_plugin.so
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Effective uid=150, 
gid=8, home=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: Quota root: 
name=storage=102400 backend=maildir args2010-05-14 02:24:45 IMAP(alex at
domain.tld): Info: maildir:
data=/var/vmail/domain.tld/alex
2010-05-14 02:24:45 IMAP(alex at domain.tld): Info: maildir++: 
root=/var/vmail/domain.tld/alex, index=, control=, 
inbox=/var/vmail/domain.tld/alex
2010-05-14 02:24:46 auth(default): Info: new auth connection: pid=2192

--- snip ---

i have a working installation from the stable repository with the same 
settings - but i need the newer dovecot for the nfs feature;
i know there was a kernel bug prior 2.6.27 which also causes such a 
problem, but i have now the 2.6.32 running and still having this problem 
- no client connection could be established....

has anyone a idea or a solution for me?

thx,
alex

Joelly Alexander put forth on 5/14/2010 2:18 PM:
> hi,
> 
> dovecot from the debian lenny backports does not successfully accept
> incomming imap or imaps connections;
> when the client connect i can see the clients ip address in an
> imap-process but the client cannot succesfully connect and retries this
> several times where an new imap-process is bound until the maximum
> connections per client is reached;
> when the client is closed the imap-processes on the server stay opened,
> even when dovecot will be restarted or stopped - the processes needs to
> killed manually;
I'm running the 1.2.11 Lenny backport as well and I've never seen the
problem you describe.  I'm using a custom rolled 2.6.32.9 from kernel.org
source.  I'm not using iptables or selinux.  I've been troubleshooting
some
performance issues likely related to mbox processing/indexing but I've had
nothing like the problem you describe.  I'm using Unix user accounts and PAM
authentication instead of virtual users, so there are substantial
differences between our setups.

However, I don't think Dovecot is the source of your problem.  From your
description, it seems likely that return packets aren't making it to the
clients.  This would explain why they keep reconnecting, and would also
explain why the imap process is never closed, i.e. the client doesn't think
it ever connected successfully, so it never sends a logout command.

Something is preventing your return packets from reaching the clients.
Check/disable your local iptables rules and any firewalls/routers between
you and the clients to see where the outbound traffic is being blocked.

Package: dovecot-imapd
State: installed
Automatically installed: no
Version: 1:1.2.11-1~bpo50+2
Priority: optional
Section: mail
Maintainer: Dovecot Maintainers <jaldhar-dovecot at debian.org>
Uncompressed Size: 1823k
Architecture: i386
Compressed Size: 1119k
Filename: pool/main/d/dovecot/dovecot-imapd_1.2.11-1~bpo50+2_i386.deb
MD5sum: fadfa84d8f07163ab7a2e9b32e39e056
Archive: lenny-backports, now

-- 
Stan

Joelly Alexander put forth on 5/15/2010 4:22 AM:
> the server and the client are on the same layer2 network and there is no
> hard- or software or anything else installed on the server what prevents
> traffic between them;
> i just figured out that it has to do with the nfs portion;
> while incoming mails have no problems and are delivered correct into the
> maildir on the nfs, it does not work when the client want to connect to
> the maildir;
> when i copy content from nfs-storage to the local harddisk it works;
Read these below, and post back if that doesn't help.  Please remember to
reply to the list next time, not to individuals.  I'm not an NFS guru, and
those who are didn't see your reply.

http://wiki.dovecot.org/MailLocation/SharedDisk
http://wiki.dovecot.org/NFS

-- 
Stan



> storage are two debian lenny systems with rhcs, nfs-export configured:
> <nfsexport name="nfs-storage"/>
> <nfsclient name="nfs_fcamx1" allow_recover="1"
> path="/storage/fca-mailstore" target="fcamx1"
> options="rw,no_root_squash,no_all_squash"/>
> <nfsclient name="nfs_fcamx2" allow_recover="1"
> path="/storage/fca-mailstore" target="fcamx2"
> options="rw,no_root_squash,no_all_squash"/>
> 
> mountpoint on fcamx-servers:
> 192.168.100.20:/storage/fca-mailstore on /var/vmail type nfs
> (rw,rsize=8192,wsize=8192,timeo=14,intr,tcp,addr=192.168.100.20)
> 
> dovecot is configured with this parameters:
> fcamx1:/etc/dovecot# dovecot -n
> # 1.2.11: /etc/dovecot/dovecot.conf
> # OS: Linux 2.6.32-bpo.4-686 i686 Debian 5.0.4 nfs
> log_path: /var/log/dovecot/dovecot-errors.log
> info_log_path: /var/log/dovecot/dovecot-info.log
> log_timestamp: %Y-%m-%d %H:%M:%S
> protocols: imap imaps pop3 pop3s
> ssl_cert_file: /etc/ssl/certs/dovecot-cert.pem
> ssl_key_file: /etc/ssl/private/dovecot-key.pem
> verbose_ssl: yes
> login_dir: /var/run/dovecot/login
> login_executable(default): /usr/lib/dovecot/imap-login
> login_executable(imap): /usr/lib/dovecot/imap-login
> login_executable(pop3): /usr/lib/dovecot/pop3-login
> login_greeting: hey dude, do you have an account?
> verbose_proctitle: yes
> first_valid_uid: 150
> last_valid_uid: 150
> mail_privileged_group: mail
> mail_location: maildir:/var/vmail/%d/%u
> mail_debug: yes
> mmap_disable: yes
> mail_nfs_storage: yes
> mail_nfs_index: yes
> lock_method: fnctl
> mbox_write_locks: fcntl dotlock
> mail_executable(default): /usr/lib/dovecot/imap
> mail_executable(imap): /usr/lib/dovecot/imap
> mail_executable(pop3): /usr/lib/dovecot/pop3
> mail_plugins(default): quota imap_quota
> mail_plugins(imap): quota imap_quota
> mail_plugins(pop3): quota
> mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
> mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
> mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
> imap_client_workarounds(default): outlook-idle delay-newmail
> imap_client_workarounds(imap): outlook-idle delay-newmail
> imap_client_workarounds(pop3):
> pop3_client_workarounds(default):
> pop3_client_workarounds(imap):
> pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh
> lda:
>   postmaster_address: postmaster at mydomain.tld
>   mail_plugins: sieve quota
>   global_script_path: /var/vmail/globalsieverc
>   log_path: /var/log/dovecot/dovecot-deliver.log
>   info_log_path: /var/log/dovecot/dovecot-deliver-info.log
> auth default:
>   mechanisms: plain login
>   user: nobody
>   verbose: yes
>   debug: yes
>   debug_passwords: yes
>   passdb:
>     driver: sql
>     args: /etc/dovecot/dovecot-sql.conf
>   userdb:
>     driver: prefetch
>   userdb:
>     driver: passwd
>   userdb:
>     driver: sql
>     args: /etc/dovecot/dovecot-sql.conf
>   socket:
>     type: listen
>     client:
>       path: /var/spool/postfix/private/auth
>       mode: 432
>       user: postfix
>       group: mail
>     master:
>       path: /var/run/dovecot/auth-master
>       mode: 432
>       user: vmail
>       group: mail
> plugin:
>   quota: maildir:storage=102400
>   sieve: ~/.dovecot.sieve
>   sieve_dir: ~/sieve
> fcamx1:/etc/dovecot#