[Dovecot] mdbox error with 2.0.beta5
Running 2.0.beta5 on Mac OS X with HFS+J, I often see this error in the log:
Fri May 14 12:25:59 gromit dovecot[5466]: imap(pid 8101 user joe): Error: mdbox /var/spool/imap/dovecot/mail/mailboxes/INBOX/Foobar/dbox-Mails: map uidvalidity mismatch (1273852899 vs 1273853949) Fri May 14 12:25:59 gromit dovecot[5466]: imap(pid 8101 user joe): Disconnected: Internal error occurred. Refer to server log for more information. [2010-05-14 12:25:59] bytes=1337/4443 Fri May 14 12:25:59 gromit dovecot[5466]: imap(pid 8101 user joe): Warning: mdbox /var/spool/imap/dovecot/mail/storage: rebuilding indexes
The logs also reveal that this user was logged in twice at the time. There appear to be two issues here: the uidvalidity mismatch, and the path in the "rebuilding indexes" message does not match the path in the "uidvalidity mismatch" error.
On pe, 2010-05-14 at 13:16 -0500, Mike Abbott wrote:
Running 2.0.beta5 on Mac OS X with HFS+J, I often see this error in the log:
Fri May 14 12:25:59 gromit dovecot[5466]: imap(pid 8101 user joe): Error: mdbox /var/spool/imap/dovecot/mail/mailboxes/INBOX/Foobar/dbox-Mails: map uidvalidity mismatch (1273852899 vs 1273853949)
This means that storage/dovecot.map.index's uidvalidity was 1273853949 (created Fri May 14 17:19:09 WEST 2010), but INBOX/Foobar/dbox-Mails/dovecot.index contained messages for map-uidvalidity 1273852899 (created Fri May 14 17:01:39 WEST 2010).
So storage's uidvalidity had changed 17,5 minutes after Foobar's index was created. Was this a real user? Since both dates are May 14th and your mail was also dated May 14h, was the user's first mdbox access also that day? Does it keep happening more than once for the same user?
I heard this happens also after "dsync mirror", but with a quick test I wasn't able to reproduce it..
The logs also reveal that this user was logged in twice at the time. There appear to be two issues here: the uidvalidity mismatch, and the path in the "rebuilding indexes" message does not match the path in the "uidvalidity mismatch" error.
The path mismatch is intended. "Rebuilding indexes" rebuilds all indexes in all mailboxes.
So storage's uidvalidity had changed 17,5 minutes after Foobar's index was created. Was this a real user?
No, this was a test user running a simulation. I can reproduce it at will if you need any more information.
Since both dates are May 14th and your mail was also dated May 14h, was the user's first mdbox access also that day?
Yes.
Does it keep happening more than once for the same user?
Yes.
I heard this happens also after "dsync mirror"
The dsync command was not involved. Just IMAP connections and dovecot-lda delivery.
The path mismatch is intended. "Rebuilding indexes" rebuilds all indexes in all mailboxes.
OK.
On pe, 2010-06-04 at 13:17 -0500, Mike Abbott wrote:
So storage's uidvalidity had changed 17,5 minutes after Foobar's index was created. Was this a real user?
No, this was a test user running a simulation. I can reproduce it at will if you need any more information.
What kind of commands does it run? Could you send me rawlogs of the entire session? I just updated hg version of rawlog so that with -t parameter it prints microsecond resolution timestamps to beginning of each line.
service imap { executable = imap imap-postlogin } service imap-postlogin { executable = script-login rawlog -t unix_listener imap-postlogin { } }
and create ~/dovecot.rawlog/ for the user.
On pe, 2010-06-04 at 20:00 +0100, Timo Sirainen wrote:
On pe, 2010-06-04 at 13:17 -0500, Mike Abbott wrote:
So storage's uidvalidity had changed 17,5 minutes after Foobar's index was created. Was this a real user?
No, this was a test user running a simulation. I can reproduce it at will if you need any more information.
What kind of commands does it run?
Nah, forget it. Looks like the uidvalidity assignment is done in a stupid racy way.
On pe, 2010-06-04 at 20:11 +0100, Timo Sirainen wrote:
Nah, forget it. Looks like the uidvalidity assignment is done in a stupid racy way.
http://hg.dovecot.org/dovecot-2.0/rev/7fc5db26f6eb should help?
Nah, forget it. Looks like the uidvalidity assignment is done in a stupid racy way.
http://hg.dovecot.org/dovecot-2.0/rev/7fc5db26f6eb should help?
Yes, that helps. Thank you.
participants (2)
-
Mike Abbott
-
Timo Sirainen