dovecot - Sep 2004 - Dovecot 1.0-test45 indexing issues

We're currently on dovecot 0.99.10 with a few modifications (including one
very nasty hack for the blank line at the beginning of the mailbox bug).

We're using mbox all around.

Everything works smoothly but we still ocasionally get corrupt mailboxes
and indexes that need to be wiped out.

I setup 1.0-test45 on one of our mailservers to start testing it and ran
into a few issues.  The first one is if I try to use mail_read_mmaped=yes
I get this error:

Error: POP3(sobo1): file istream-raw-mbox.c: line 410
(istream_raw_mbox_get_body_size):
assertion failed: (rstream->mail_size != (uoff_t)-1)

for every mailbox.

If I switch to mail_read_mmaped=no everything works, but performance is
extremely bad.  I have a few test mailboxes with about 20k messages and if
I toggle a message flag from unread to read, dovecot seems to re-read the
entire mailbox up to that message (I saw this with strace).

Is this how supposed to work??  I don't see behavior like this on 0.99.10,
and on a mailbox with any substantial number of messages it really slows
things down.

Thanks for any input.

- Mike

On 22.9.2004, at 00:36, dovecot at spam.turbolink.net wrote:
> If I switch to mail_read_mmaped=no everything works, but performance is
> extremely bad.
There shouldn't be hardly any performance difference with mmaped=no vs. 
yes, but I'll look into that problem..
>  I have a few test mailboxes with about 20k messages and if
> I toggle a message flag from unread to read, dovecot seems to re-read 
> the
> entire mailbox up to that message (I saw this with strace).
You set the flag with Dovecot? It shouldn't do that (and doesn't with 
me). Did anything else modify the mbox at the same time, for example if 
new mail was just written to the mbox? What OS is this? What 
filesystem? Can I see the strace log?
-------------- 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/20040922/07101a8a/attachment-0001.bin>

On Wed, 22 Sep 2004, Timo Sirainen wrote:
> On 22.9.2004, at 00:36, dovecot at spam.turbolink.net wrote:
>
> > If I switch to mail_read_mmaped=no everything works, but performance
is
> > extremely bad.
>
> There shouldn't be hardly any performance difference with mmaped=no vs.
> yes, but I'll look into that problem..
That was meant to be all together, the performance issue is the one of
re-reading the mailbox from the beginning.
> >  I have a few test mailboxes with about 20k messages and if
> > I toggle a message flag from unread to read, dovecot seems to re-read
> > the
> > entire mailbox up to that message (I saw this with strace).
>
> You set the flag with Dovecot? It shouldn't do that (and doesn't
with
> me). Did anything else modify the mbox at the same time, for example if
> new mail was just written to the mbox? What OS is this? What
> filesystem? Can I see the strace log?
Well, I clicked 'Mark as Unread' in Thunderbird.

This is on Linux 2.4.21, INBOX is on NFS.  No new messages are delivered.
Nothing else has the mailbox open or is even trying.

Here is the snippet of an ngrep log I captured as I hit 'Mark as
Unread':

#
T 192.168.196.53:143 -> 192.168.199.48:57262 [AP]
  26 OK Idle completed...
##
T 192.168.199.48:57262 -> 192.168.196.53:143 [AP]
  27 uid store 5957 -Flags (\Seen)..

very large delay here, 60-90 seconds

##
T 192.168.196.53:143 -> 192.168.199.48:57262 [AP]
  * 5957 FETCH (FLAGS ())..27 OK Store completed...
#
T 192.168.199.48:57262 -> 192.168.196.53:143 [AP]
  28 check..
##
T 192.168.196.53:143 -> 192.168.199.48:57262 [AP]
  28 OK Check completed...
#
T 192.168.199.48:57262 -> 192.168.196.53:143 [AP]
  29 IDLE..
##
T 192.168.196.53:143 -> 192.168.199.48:57262 [AP]
  + idling..


I didn't save the strace but I can generate a new one.  I did do a gdb
backtrace, while it was re-reading:

#0  0x0808ab02 in i_strdup_until ()
#1  0x0806a833 in mbox_from_parse ()
#2  0x0806a07b in i_stream_create_raw_mbox ()
#3  0x0806a1d5 in istream_raw_mbox_get_body_size ()
#4  0x08067b37 in mbox_sync_seek ()
#5  0x080687a4 in mbox_sync_seek ()
#6  0x08069003 in mbox_sync_seek ()
#7  0x080694ca in mbox_sync ()
#8  0x0806439f in mbox_transaction_commit ()
#9  0x0807e3ea in mailbox_transaction_commit ()
#10 0x080562fb in cmd_store ()
#11 0x080565df in cmd_uid ()
#12 0x08056d5a in _client_reset_command ()
#13 0x08056e69 in _client_input ()
#14 0x0808c768 in io_loop_handler_run ()
#15 0x0808bead in io_loop_run ()
#16 0x0805d107 in main ()
#17 0x40037bb4 in __libc_start_main () from /lib/libc.so.6


- Mike

I'm not sure exactly what it means, but it repeats over and over again for
2 different boxes on my system:

Error: IMAP(trisha): Corrupted transaction log file
/var/spool/mailindex/trisha/SPAM/dovecot.index.log: Append with UID 58332, but
next_uid = 59582
Error: IMAP(trisha): Transaction log file
/var/spool/mailindex/trisha/SPAM/dovecot.index.log: marked corrupted

It seems to repeatedly mark it corrupted but then never does anything
about it?

Client is outlook express, and only dovecot 0.99.10 and 1.0-test45 have
ever been used to access this mbox.

- Mike