There seems to be a bug in updating uid/uidvalidity when copying mail to an empty or newly created mailbox:
<new connection> . OK Logged in.
. CREATE testfolder4 . OK Create completed.
. SUBSCRIBE testfolder4 . OK Subscribe completed.
. SELECT otherfolder permitted.
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags
- 3 EXISTS
- 0 RECENT
- OK [UNSEEN 1] First unseen.
- OK [UIDVALIDITY 1121171128] UIDs valid
- OK [UIDNEXT 4] Predicted next UID . OK [READ-WRITE] Select completed.
. UID COPY 1 testfolder4 . NO Internal error occured. Refer to server log for more information. [2005-07-12 15:05:45]
. SELECT testfolder4 . NO Internal error occured. Refer to server log for more information. [2005-07-12 15:05:49]
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags
- 1 EXISTS
- 1 RECENT
- OK [UNSEEN 1] First unseen.
- OK [UIDVALIDITY 1121173545] UIDs valid
- OK [UIDNEXT 2] Predicted next UID . OK [READ-WRITE] Select completed.
The errorlog entries for those two errors are: Jul 12 15:05:45 dovecot0 dovecot: IMAP(ynnoz): Corrupted index file /var/run/dovecot-index/ynnoz/.testfolder4/dovecot.index: uid_validity = 0, next_uid = 2 Jul 12 15:05:49 dovecot0 dovecot: IMAP(ynnoz): Corrupted index file /var/run/dovecot-index/ynnoz/.testfolder4/dovecot.index: uid_validity = 0, next_uid = 2
I also managed to trigger an assertion failure this way, by trying another COPY after that first failure:
. UID COPY 1 testfolder6 . NO Internal error occured. Refer to server log for more information. [2005-07-12 15:16:54] . UID COPY 1 testfolder6 Connection closed by foreign host.
The errors for that connection are: Jul 12 15:16:54 dovecot0 dovecot: IMAP(ynnoz): Corrupted index file /var/run/dovecot-index/ynnoz/.testfolder6/dovecot.index: uid_validity = 0, next_uid = 2 Jul 12 15:17:01 dovecot0 dovecot: IMAP(ynnoz): Corrupted index file /var/run/dovecot-index/ynnoz/.testfolder6/dovecot.index: uid_validity = 0, next_uid = 2 Jul 12 15:17:01 dovecot0 dovecot: IMAP(ynnoz): file mail-index-transaction.c: line 128 (mail_index_buffer_convert_to_uids): assertion failed: (*seq != 0) Jul 12 15:17:01 dovecot0 dovecot: child 6666 (imap) killed with signal 6
Another assertion error I triggered was by trying another SELECT right after the failed SELECT (after the failed COPY): Jul 12 15:14:04 dovecot0 dovecot: IMAP(ynnoz): Maildir /var/spool/mail/.4a/S/tmp/ynnoz/.testfolder5 sync: UIDVALIDITY changed (1121174026 -> 1121174044) Jul 12 15:14:09 dovecot0 dovecot: IMAP(ynnoz): Corrupted transaction log file /var/run/dovecot-index/ynnoz/.testfolder5/dovecot.index.log: Append with UID 1, but next_uid = 2 Jul 12 15:14:12 dovecot0 dovecot: IMAP(ynnoz): file mail-index-view.c: line 595 (mail_index_view_open): assertion failed: (index->map != NULL) Jul 12 15:14:12 dovecot0 dovecot: child 6654 (imap) killed with signal 6
I was able to reproduce this on a near-virgin test76 -- it has one patch that should not interfere; we use
default_mail_env = maildir:%Nu:INDEX=/var/run/dovecot-index/%u
where %N is a new var_expand character that looks up the argument in a NIS map (we store actual maildir location there, for scalability.) The INDEX setting we use might matter, though. But it feels like a missing update-uid or invalidate-uid call somewhere, I just don't know where :)
-- Thomas Wouters thomas@xs4all.net
Hi! I'm a .signature virus! copy me into your .signature file to help me spread!