dovecot - Nov 2011 - Dot Lock timestmap, users disconnections from roundcube

Hello.

 We are running dovecot 2.0.13 with mdbox+zlib on RHEL 5.7 x64, ext4. We use
NTP. Indexes are in a iSCSI raid 10, mailboxes in raid5. No NFS. We have
detected that sometimes all users get disconnected from roundcube at the same
time. In dovecot logs we hundreds of lines like this:

 Nov 3 09:23:07 buzon dovecot: imap(mcrivero at mydomain): Warning: Created
dotlock file's timestamp is different than current time (1320308587 vs
1320308542): /buzones/mydomain/03/67/mcrivero/subscriptions
 Nov 3 09:23:07 buzon dovecot: imap(mcrivero at mydomain): Connection closed
bytes=0/295
 Nov 3 09:23:07 buzon dovecot: imap(delolmo at mydomain): Warning: Created
dotlock file's timestamp is different than current time (1320308587 vs
1320308542): /buzones/mydomain/15/77/delolmo/subscriptions
 Nov 3 09:23:07 buzon dovecot: imap(delolmo at mydomain): Connection closed
bytes=0/295



 I have been googling but I only see problems with remote NFS, our setup does
not use NFS. I give you doveconf -n output & mount options, if more info es
needed, please ask.

 doveconf -n output


 # 2.0.13: /etc/dovecot/dovecot.conf
 # OS: Linux 2.6.18-274.el5 x86_64 Red Hat Enterprise Linux Server release 5.7
(Tikanga) ext4
 auth_cache_negative_ttl = 10 secs
 auth_cache_size = 10 M
 auth_cache_ttl = 2 mins
 auth_master_user_separator = *
 auth_mechanisms = plain login
 auth_worker_max_count = 3500
 base_dir = /var/run/dovecot/
 default_client_limit = 5000
 default_process_limit = 6500
 disable_plaintext_auth = no
 imap_client_workarounds = tb-extra-mailbox-sep delay-newmail tb-lsub-flags
 lda_mailbox_autocreate = yes
 lda_mailbox_autosubscribe = yes
 mail_fsync = never
 mail_gid = entrega
 mail_home = /buzones/mydomain/%2.26Hn/%2.200Hn/%n/home_usuario/
 mail_location =
mdbox:/buzones/mydomain/%2.26Hn/%2.200Hn/%n:INDEX=/indices_dovecot/indices/%2.26Hn/%2.200Hn/%n
 mail_max_userip_connections = 15000
 mail_plugins = " zlib acl quota autocreate"
 mail_uid = entrega
 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
 mdbox_rotate_interval = 1 days
 mdbox_rotate_size = 60 M
 passdb {
 args = /etc/dovecot/dovecot-ldap.conf
 driver = ldap
 }
 passdb {
 args = /etc/usuario_maestro.txt
 driver = passwd-file
 master = yes
 }
 passdb {
 args = /etc/dovecot/dovecot-ldap.conf
 driver = ldap
 }
 plugin {
 acl = vfile
 autocreate = SPAM
 autocreate2 = Sent
 autocreate3 = Drafts
 autocreate4 = Trash
 autosubscribe = SPAM
 autosubscribe2 = Sent
 autosubscribe3 = Drafts
 autosubscribe4 = Trash
 lda_mailbox_autosubscribe = yes
 quota = dict:Cuota de usuario::file:/buzones/cuotas/%n
 quota_rule2 = Trash:storage=+10%%
 quota_warning = storage=90%% aviso_cuota 90 %u
 sieve = /buzones/mydomain/%2.26Hn/%2.200Hn/%n/home_usuario/dovecot.sieve
 sieve_dir = /buzones/mydomain/%2.26Hn/%2.200Hn/%n/home_usuario/sieve/
 zlib_save = gz
 zlib_save_level = 9
 }
 pop3_no_flag_updates = yes
 protocols = pop3 imap sieve
 service anvil {
 client_limit = 25000
 }
 service auth {
 client_limit = 28000
 unix_listener auth-master {
 user = entrega
 }
 unix_listener auth-userdb {
 user = entrega
 }
 user = root
 }
 service aviso_cuota {
 executable = script /usr/local/bin/quota-warning.sh
 unix_listener aviso_cuota {
 mode = 0666
 }
 user = entrega
 }
 service imap-login {
 executable = /usr/libexec/dovecot/imap-login
 group = dovenull
 service_count = 0
 }
 service imap {
 executable = /usr/libexec/dovecot/imap
 process_limit = 6000
 }
 service managesieve-login {
 executable = /usr/libexec/dovecot/managesieve-login
 inet_listener sieve {
 port = 2000
 }
 process_limit = 2000
 }
 service managesieve {
 executable = /usr/libexec/dovecot/managesieve
 process_limit = 5000
 }
 service pop3-login {
 executable = /usr/libexec/dovecot/pop3-login
 process_limit = 4000
 service_count = 0
 }
 service pop3 {
 executable = /usr/libexec/dovecot/pop3
 process_limit = 4000
 }
 ssl_ca = </etc/pki/generico/cacert.crt.pem
 ssl_cert = </etc/pki/generico/wildcard-us_es.crt
 ssl_key = </etc/pki/generico/wildcard-key.pem
 userdb {
 args = /etc/dovecot/dovecot-ldap.conf
 driver = ldap
 }
 userdb {
 args = /etc/dovecot/dovecot-ldap-userdb.conf
 driver = ldap
 }
 verbose_proctitle = yes
 protocol sieve {
 managesieve_implementation_string = dovecot
 managesieve_logout_format = bytes=%i/%o
 managesieve_max_line_length = 65536
 }
 protocol lda {
 hostname = mydomain
 info_log_path  log_path  mail_fsync = optimized
 mail_plugins = sieve zlib quota
 postmaster_address = evcorreo at mydomain
 syslog_facility = mail
 }
 protocol imap {
 mail_plugins = zlib autocreate quota imap_quota
 }
 protocol pop3 {
 mail_plugins = zlib
 pop3_enable_last = yes
 pop3_uidl_format = %g
 }

 mount points:

 /dev/mapper/Volumen_0-Logico_0 on / type ext3 (rw)
 proc on /proc type proc (rw)
 sysfs on /sys type sysfs (rw)
 devpts on /dev/pts type devpts (rw,gid=5,mode=620)
 /dev/sda1 on /boot type ext3 (rw)
 tmpfs on /dev/shm type tmpfs (rw)
 none on /proc/sys/fs/binfmt_misc type binfmt_misc (rw)
 sunrpc on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw)
 /dev/mapper/Buzon_mydomain-buzones on /buzones type ext4
(rw,noatime,nodiratime,nobarrier,commit=15,data=writeback)

 Indexes are located somewhere in "/" mount point.

Hi
>  We are running dovecot 2.0.13 with mdbox+zlib on RHEL 5.7 x64, ext4. We
use NTP.
Quick check, but by "NTP" you mean the background daemon and you
don't
have some cron job running ntpdate or similar every so often?

No idea, but since it looks like a clock related curiousity, then
knowing if the clock is spot on accurate or drifting would be
interesting to know?  Simple comparison against other machines over a
similar period to you having problems might be accurate enough?

Good luck

Ed W

We use ntpd daemon, all our systems are configured equal. Another thing, this is
VM on vmware vsphere 4.1

 Regards

 Maria

----- Original Message -----
From: Ed W
Sent: 11/03/11 11:25 AM
To: dovecot at dovecot.org
Subject: Re: [Dovecot] Dot Lock timestmap, users disconnections from roundcube

 Hi > We are running dovecot 2.0.13 with mdbox+zlib on RHEL 5.7 x64, ext4. We
use NTP. Quick check, but by "NTP" you mean the background daemon and
you don't have some cron job running ntpdate or similar every so often? No
idea, but since it looks like a clock related curiousity, then knowing if the
clock is spot on accurate or drifting would be interesting to know? Simple
comparison against other machines over a similar period to you having problems
might be accurate enough? Good luck Ed W

All the ESXs hosts and all the VM use the same NTP server.

 Any other idea?

 Regards

 Maria

----- Original Message -----
From: Giulio Casella
Sent: 11/03/11 11:38 AM
To: dovecot at dovecot.org
Subject: Re: [Dovecot] Dot Lock timestmap, users disconnections from roundcube

 This could be the problem. Double check the time also on your host system(s),
not only on guest. Bye, gc Il 03/11/2011 11.30, Maria Arrea ha scritto: > We
use ntpd daemon, all our systems are configured equal. Another thing, this is VM
on vmware vsphere 4.1 > > Regards > > Maria > > ----- Original
Message ----- > From: Ed W > Sent: 11/03/11 11:25 AM > To: dovecot at
dovecot.org > Subject: Re: [Dovecot] Dot Lock timestmap, users disconnections
from roundcube > > Hi> We are running dovecot 2.0.13 with mdbox+zlib on
RHEL 5.7 x64, ext4. We use NTP. Quick check, but by "NTP" you mean the
background daemon and you don't have some cron job running ntpdate or
similar every so often? No idea, but since it looks like a clock related
curiousity, then knowing if the clock is spot on accurate or drifting would be
interesting to know? Simple comparison against other machines over a similar
period to you having problems might be accurate enough? Good luck Ed W > --
Giulio Casella giulio at dsi.unimi.it System and network manager Computer
Science Dept. - University of Milano

We follow the guidelines about timekeeping RHEL in vmware vsphere located here

 http://kb.vmware.com/selfservice/microsites/search.do?language=en_US&cmd=displayKC&externalId=1006427

 These problems happens in peak hours. Any dovecot config parameter I could set
to mitigate this problem?

 Regards

 Maria

----- Original Message -----
From: Ed W
Sent: 11/03/11 11:57 AM
To: Maria Arrea, Dovecot Mailing List
Subject: Re: [Dovecot] Dot Lock timestmap, users disconnections from roundcube

 On 03/11/2011 10:49, Maria Arrea wrote: > All the ESXs hosts and all the VM
use the same NTP server. > > Any other idea? > Doesn't ESX have
issues with the time drifting when certain kernel options are set? Something to
do with it rescheduling machines and them not counting idle ticks or
something..? Does this problem happen during idle hours or peak hours? I should
home in on clock problems... Probably vmware related issues to the kernel you
are using? Good luck Ed W

On Thu, 2011-11-03 at 10:54 +0100, Maria Arrea wrote:
> Hello.
> 
>  We are running dovecot 2.0.13 with mdbox+zlib on RHEL 5.7 x64, ext4. We
use NTP. Indexes are in a iSCSI raid 10, mailboxes in raid5. No NFS. We have
detected that sometimes all users get disconnected from roundcube at the same
time. In dovecot logs we hundreds of lines like this:
> 
>  Nov 3 09:23:07 buzon dovecot: imap(mcrivero at mydomain): Warning: Created
dotlock file's timestamp is different than current time (1320308587 vs
1320308542): /buzones/mydomain/03/67/mcrivero/subscriptions
I did several fixes related to this, but they were already in v2.0.10.
Note the time difference of 45 seconds.
>  Nov 3 09:23:07 buzon dovecot: imap(mcrivero at mydomain): Connection
closed bytes=0/295
The dotlock warning isn't related to this.

My guess: NFS was being extremely slow here, some operation took 45
seconds and Roundcube decided to abort before that. The "timestamp is
different" check doesn't work 100% correctly if the filesystem
operations take more than a second.

Timo, we are not using NFS, we use remote iSCSI volumes with ext4.

 Regards

 Maria

----- Original Message -----
From: Timo Sirainen
Sent: 11/04/11 09:59 PM
To: Maria Arrea
Subject: Re: [Dovecot] Dot Lock timestmap, users disconnections from roundcube

 On Thu, 2011-11-03 at 10:54 +0100, Maria Arrea wrote: > Hello. > > We
are running dovecot 2.0.13 with mdbox+zlib on RHEL 5.7 x64, ext4. We use NTP.
Indexes are in a iSCSI raid 10, mailboxes in raid5. No NFS. We have detected
that sometimes all users get disconnected from roundcube at the same time. In
dovecot logs we hundreds of lines like this: > > Nov 3 09:23:07 buzon
dovecot: imap(mcrivero at mydomain): Warning: Created dotlock file's
timestamp is different than current time (1320308587 vs 1320308542):
/buzones/mydomain/03/67/mcrivero/subscriptions I did several fixes related to
this, but they were already in v2.0.10. Note the time difference of 45 seconds.
> Nov 3 09:23:07 buzon dovecot: imap(mcrivero at mydomain): Connection closed
bytes=0/295 The dotlock warning isn't related to this. My guess: NFS was
being extremely slow here, some operation took 45 seconds and Roundcube decided
to abort before that. The "timestamp is different" check doesn't
work 100% correctly if the filesystem operations take more than a second.