dovecot - Mar 2004 - imap indexing error when moving multiple mails

Hi,

I've got an 'interesting' problem with a dovecot 0.99.10.4 setup on 
NetBSD/i386 1.6ZK.

dovecot is serving imap only at the moment, using mbox format 
mailboxes. '/etc/dovecot.conf' is pretty vanilla - among the modified 
settings,

mail_read_mmaped = yes
maildir_check_content_changes = yes
mbox_lock = fcntl

could be relevant. Anyway - from time to time when I move a bunch of 
mails ( < 1) from a mailbox to another (or to the trash), the client 
(I've seen it with Eudora 6 on a  Mac, with Mozilla 1.6 and Sylpheed 
on NetBSD) reports an "internal error" and the maillog shows

Mar 25 14:07:33 bounce imap-login: Login: hf [130.83.xxx.yyy]
Mar 25 14:07:44 bounce imap(hf): Error indexing mbox file 
/home/hf/Mail/Leute/Marc Wirth: LF not found where expected
Mar 25 14:09:30 bounce imap(hf): Error indexing mbox file 
/home/hf/Mail/Leute/Marc Wirth: LF not found where expected


which, if I retry the operation to another time, does not persist and 
is not strictly repeatable.

I've set the number of allowed concurrent connections to '1' on the 
client, but that doesn't help.

Is there anything obvious that I overlooked, or have I tripped over a 
genuine bug?

	hauke

-- 
           Hauke Fath                   /~\  The ASCII Ribbon Campaign
Institut f?r Nachrichtentechnik        \ /    No HTML/RTF in email
          TU Darmstadt                   X     No Word docs in email
Ruf +49-6151-16-3281, Fax -3778        / \  Respect for open standards

* Hauke Fath <hf at spg.tu-darmstadt.de> (20040325
15:19):
> could be relevant. Anyway - from time to time when I move a bunch of 
> mails ( < 1) from a mailbox to another (or to the trash), the client 
> (I've seen it with Eudora 6 on a  Mac, with Mozilla 1.6 and Sylpheed 
> on NetBSD) reports an "internal error" and the maillog shows
> 
> Mar 25 14:07:33 bounce imap-login: Login: hf [130.83.xxx.yyy]
> Mar 25 14:07:44 bounce imap(hf): Error indexing mbox file 
> /home/hf/Mail/Leute/Marc Wirth: LF not found where expected
> Mar 25 14:09:30 bounce imap(hf): Error indexing mbox file 
> /home/hf/Mail/Leute/Marc Wirth: LF not found where expected
FWIW, I have the same exact problem. This happens when
`expunging' a mbox or QUIT-ting a POP3 session. The consequence
is the email is not deleted (good), the next fetchmail will get
another, identical message.

A non-informative message is displayed according to the
mail_storage_set_critical() func in lib-storage/mail-storage.c
and the actual error is not logged.

Wouldn't there be a problem with the call to this function in
lib-storage/index/mbox/mbox-storage.c, line 496? The second
argument should be a vprintf() format string.

-- 
olive

* Olivier Tharan <olive at pasteur.fr> (20040330
22:17):
> > Mar 25 14:07:33 bounce imap-login: Login: hf [130.83.xxx.yyy]
> > Mar 25 14:07:44 bounce imap(hf): Error indexing mbox file 
> > /home/hf/Mail/Leute/Marc Wirth: LF not found where expected
> > Mar 25 14:09:30 bounce imap(hf): Error indexing mbox file 
> > /home/hf/Mail/Leute/Marc Wirth: LF not found where expected
> 
> FWIW, I have the same exact problem. This happens when
> `expunging' a mbox or QUIT-ting a POP3 session. The consequence
> is the email is not deleted (good), the next fetchmail will get
> another, identical message.
I keep having the problem. I do my testing with :

- on one terminal :
,----
| while ((1)); do echo "test" | mail -s 'test' zzzzzzz; sleep
10; done
`----

- on one machine, a fetchmail -d 10

The logs:

,----
| Apr 30 17:15:29 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:15:32 munster pop3(zzzzzzz): Error indexing mbox file
/var/mail/zzzzzzz: LF not found where expected
| Apr 30 17:15:42 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:15:55 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:15:58 munster pop3(zzzzzzz): Error indexing mbox file
/var/mail/zzzzzzz: LF not found where expected
| Apr 30 17:16:09 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:16:12 munster pop3(zzzzzzz): Error indexing mbox file
/var/mail/zzzzzzz: LF not found where expected
| Apr 30 17:16:22 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:16:36 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:16:39 munster pop3(zzzzzzz): Error indexing mbox file
/var/mail/zzzzzzz: LF not found where expected
| Apr 30 17:16:49 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:16:52 munster pop3(zzzzzzz): Error indexing mbox file
/var/mail/zzzzzzz: LF not found where expected
| Apr 30 17:17:02 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:17:16 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:17:19 munster pop3(zzzzzzz): Error indexing mbox file
/var/mail/zzzzzzz: LF not found where expected
| Apr 30 17:17:29 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
| Apr 30 17:17:32 munster pop3(zzzzzzz): Error indexing mbox file
/var/mail/zzzzzzz: LF not found where expected
| Apr 30 17:17:42 munster pop3-login: Login: zzzzzzz [157.99.xx.xx]
`----

A precision: /var/mail is a NFS filesystem (from a Netapp). The
indexes are on a local disk.

The same test on a box with a local spool (no NFS) does not
trigger the errors. On both machines, this is dovecot-0.99.10.4
from the FreeBSD ports.

Any ideas?
-- 
olive