dovecot - Apr 2007 - Lock file issues

First off, just want to say Dovecot is great! We have been using it for
several months now in a fairly large installation with only a few
problems. 
We are running 1.0.rc28 on three servers with 3 Horde/IMP boxes talking
to Dovecot.  The user's home dirs are located on an NFS server
and the indexes are stored in their Maildirs. I have mmap_disable=yes
and lock_method=dotlock in dovecot.conf. We have not implemented 
anything to direct users to the same server as is recommended per the
Wiki. I have been trying to avoid this, as the best way I could see to
do 
it would be to put in an IMAP proxy (Perdition?) and I just wanted to
keep it as simple as possible if I could.

The problems we have been having are due to dovecot.*.lock files not
being cleaned up. This issue presents itself as a user not being able to
login via the webmail interface. The logfile will contain something
similar to the following:


Apr  3 08:37:51 app02 dovecot: IMAP(user): Corrupted transaction log
file /mail_home3/j/ji/user/Maildir/dovecot.index.log: end_offset
(23440)
> current sync_offset (23368)
Apr  3 08:37:51 app02 dovecot: IMAP(user): file
mail-index-sync-update.c: line 40 (mail_index_sync_update_log_offset):
assertion failed: (prev_offset >= map->hdr.log_file_int_offset ||
prev_seq > map->hdr.log_file_seq)
Apr  3 08:37:51 app02 dovecot: IMAP(user): Raw backtrace: imap
[0x80a8c1a] -> imap [0x80a873f] -> imap [0x8091fcf] ->
imap(mail_index_sync_update_index+0x2a1) [0x80935c5] ->
imap(mail_index_sync_commit+0xbf) [0x8091c9f] ->
imap(maildir_sync_index_finish+0xc4) [0x8065fbc] -> imap [0x8066851] ->
imap(maildir_storage_sync_init+0x4a) [0x80669b2] ->
imap(mailbox_sync_init+0x15) [0x809c9ed] -> imap(imap_sync_nonselected
+0x17) [0x8060ac3] -> imap(_cmd_select_full+0xc3) [0x8059893] ->
imap(cmd_select+0x13) [0x80599fb] -> imap
[0x805b12e] -> imap [0x805b251] -> imap(_client_input+0xc3) [0x805b323]
-> imap(io_loop_handler_run+0x184) [0x80ae1c0] -> imap(io_loop_run+0x1d)
[0x80ad73d] -> imap(main+0xa5) [0x80626b1]
-> /lib/libc.so.6(__libc_start_main+0xbb) [0x4003414f] -> imap(chroot
+0x31) [0x80568d1]
Apr  3 08:38:01 app02 dovecot: IMAP(user): Transaction log
file /mail_home3/j/ji/user/Maildir/dovecot.index.log: marked corrupted
Apr  3 08:38:01 app02 dovecot: IMAP(user): Transaction log
file /mail_home3/j/ji/user/Maildir/dovecot.index.log.2: marked corrupted


A directory listing of the Maildir shows the dovecot lock files:

-rw-------    1 user users           0 Apr  3  2007 dovecot-uidlist.lock
-rw-------    1 user users         360 Apr  3  2007 dovecot.index
-rw-------    1 user users       32768 Apr  3  2007 dovecot.index.cache
-rw-------    1 user users          24 Apr  3  2007 dovecot.index.log
-rw-------    1 user users          11 Apr  3  2007
dovecot.index.log.lock
-rw-------    1 user users         360 Apr  3  2007 dovecot.index.tmp


While I can't login via the IMP web interface as that user, I am able to
initiate an IMAP session via telnet. 
I can login, but as soon as I try a " select INBOX" it just appears to
hang. I have attached the output of 'strace -p pid' of this 
IMAP session, which shows that it appears to be in a loop (statting the
lock file?) for 244 seconds (seems to be consistent, 
tried it three different times) before it continues and gives me the
INBOX. This happens for every subsequent command as 
well (Fetch, etc.) Once I log out, the lock files are not removed. I
have to remove the lock files for the user to be able to log in
via the web interface. 

Please let me know if I need to provide more information.

Paul Hamby
-------------- next part --------------
A non-text attachment was scrubbed...
Name: lockfile.strace.txt.zip
Type: application/zip
Size: 22016 bytes
Desc: not available
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20070403/bdfb44c7/attachment-0002.zip>

On 3.4.2007, at 21.05, Paul Hamby wrote:
> We are running 1.0.rc28 on three servers with 3 Horde/IMP boxes  
> talking
> to Dovecot.  The user's home dirs are located on an NFS server
> and the indexes are stored in their Maildirs. I have mmap_disable=yes
> and lock_method=dotlock in dovecot.conf. We have not implemented
> anything to direct users to the same server as is recommended per the
> Wiki. I have been trying to avoid this, as the best way I could see to
> do
> it would be to put in an IMAP proxy (Perdition?) and I just wanted to
> keep it as simple as possible if I could.
And I guess you didn't disable attribute cache either?
> The problems we have been having are due to dovecot.*.lock files not
> being cleaned up. This issue presents itself as a user not being  
> able to
> login via the webmail interface. The logfile will contain something
> similar to the following:
..
> Apr  3 08:37:51 app02 dovecot: IMAP(user): Corrupted transaction log
> file /mail_home3/j/ji/user/Maildir/dovecot.index.log: end_offset  
> (23440)
>> current sync_offset (23368)
> Apr  3 08:37:51 app02 dovecot: IMAP(user): file
> mail-index-sync-update.c: line 40 (mail_index_sync_update_log_offset):
> assertion failed: (prev_offset >= map->hdr.log_file_int_offset ||
> prev_seq > map->hdr.log_file_seq)
Hmm. I guess I should change this assert to instead just log an error  
and return failure, because it's what leaves the lock files lying  
around.

But anyway I don't think it's a good idea to keep using this kind of  
a configuration where things break all the time..
-------------- next part --------------
A non-text attachment was scrubbed...
Name: PGP.sig
Type: application/pgp-signature
Size: 186 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20070408/01700495/attachment.bin>

On Sun, 2007-04-08 at 12:06 +0300, Timo Sirainen wrote:
> On 3.4.2007, at 21.05, Paul Hamby wrote:
> 
> > We are running 1.0.rc28 on three servers with 3 Horde/IMP boxes  
> > talking
> > to Dovecot.  The user's home dirs are located on an NFS server
> > and the indexes are stored in their Maildirs. I have mmap_disable=yes
> > and lock_method=dotlock in dovecot.conf. We have not implemented
> > anything to direct users to the same server as is recommended per the
> > Wiki. I have been trying to avoid this, as the best way I could see to
> > do
> > it would be to put in an IMAP proxy (Perdition?) and I just wanted to
> > keep it as simple as possible if I could.
> 
> And I guess you didn't disable attribute cache either?
I was concerned about the performance hit it would take doing this. I
will set actimeo=0 on the nfs mounts and monitor the logs for errors to
see if this helps while not killing performance.
> 
> > The problems we have been having are due to dovecot.*.lock files not
> > being cleaned up. This issue presents itself as a user not being  
> > able to
> > login via the webmail interface. The logfile will contain something
> > similar to the following:
> ..
> > Apr  3 08:37:51 app02 dovecot: IMAP(user): Corrupted transaction log
> > file /mail_home3/j/ji/user/Maildir/dovecot.index.log: end_offset  
> > (23440)
> >> current sync_offset (23368)
> > Apr  3 08:37:51 app02 dovecot: IMAP(user): file
> > mail-index-sync-update.c: line 40 (mail_index_sync_update_log_offset):
> > assertion failed: (prev_offset >= map->hdr.log_file_int_offset
||
> > prev_seq > map->hdr.log_file_seq)
> 
> Hmm. I guess I should change this assert to instead just log an error  
> and return failure, because it's what leaves the lock files lying  
> around.
> 
Will this change be in an upcoming RC?
> But anyway I don't think it's a good idea to keep using this kind
of
> a configuration where things break all the time..
Understood, there are just some added complexities to consider in the
IMAP proxy scenario, such as the changes needed for adding, editing and
deleting user accounts and the necessary changes to our LDAP config. It
is something I will have to give more thought/time to.

Thanks for your reply.

Paul