crash on sync of large maildir

Sun May 1 17:38:34 BST 2011

On Sat, 30 Apr 2011 23:14:24 -0400, mah at everybody.org wrote:
> My INBOX maildir hold mail for the last 10 years — no Inbox Zero for me!
:)

> I've used offlineimap very successfully for a long time, but recently
> something started happening to screw it up.

Mmh, once the UID map between 2 IMAP servers gets screwed, things are
not going to be nice with offlineimap. The whole IMAP<->IMAP syncing
really feels somewhat tacked on in a rather hackish way. IMAP<->Maildir
is much more robust, personally I would advice to use that.

>     Syncing INBOX: IMAP -> MappedIMAP
>     Copy message -2 MappedIMAP[INBOX] -> IMAP[INBOX]
>     Copy message -6 MappedIMAP[INBOX] -> IMAP[INBOX]
>     Copy message -5 MappedIMAP[INBOX] -> IMAP[INBOX]
>     Copy message -4 MappedIMAP[INBOX] -> IMAP[INBOX]
>     Thread 'New msg sync from INBOX' terminated with exception:
>     Traceback (most recent call last):
>     File "/usr/lib/pymodules/python2.7/offlineimap/threadutil.py", line 159, in run
>     Thread.run(self)
>     File "/usr/lib/python2.7/threading.py", line 505, in run
>     self.__target(*self.__args, **self.__kwargs)
>     File "/usr/lib/pymodules/python2.7/offlineimap/folder/Base.py", line 264, in syncmessagesto_neguid_msg
>     self.deletemessage(uid)
>     File "/usr/lib/pymodules/python2.7/offlineimap/folder/UIDMaps.py", line 238, in deletemessage
>     self._mb.deletemessage(self, self.r2l[uid])
>     File "/usr/lib/pymodules/python2.7/offlineimap/folder/IMAP.py", line 567, in deletemessage
>     self.deletemessages_noconvert([uid])
>     File "/usr/lib/pymodules/python2.7/offlineimap/folder/IMAP.py", line 578, in deletemessages_noconvert
>     self.addmessagesflags_noconvert(uidlist, ['T'])
>     File "/usr/lib/pymodules/python2.7/offlineimap/folder/IMAP.py", line 499, in addmessagesflags_noconvert
>     self.processmessagesflags('+', uidlist, flags)
>     File "/usr/lib/pymodules/python2.7/offlineimap/folder/IMAP.py", line 531, in processmessagesflags
>     assert r[0] == 'OK', 'Error with store: ' + '. '.join(r[1])
>     AssertionError: Error with store: UID STORE failed

OK, this is what's happening:
- you try to upload a new message from your "local" IMAP server to the
remote IMAP server. The remote IMAP server assigns a new UID, and the
local IMAP server gets the messages then saved with the new UID and
deleted the old UID (which makes sense on a IMAP<->Maildir set up but is
clumsy on IMAP<->IMAP). However, when we "delete" the old local mail by
setting the flag "T", the local IMAP responds with "UID STORE" failed.

>     Last 9 debug messages logged for New msg sync from INBOX prior to exception:
>     imap: Returned object from fetching 780665: ('OK', ['72967 (UID 780665 BODY[] "")'])
>     imap: savemessage: called
>     imap: savemessage: using date None
>     imap: savemessage: content is: '2'
>     imap: savemessage: returning new UID 406
>     imap: savemessage: called
>     imap: savemessage: using date None
>     imap: savemessage: content is: '2'
>     imap: savemessage: returning new UID 786370
>     imap(mah): Info: Connection closed bytes=14751/16239

When we fetch the message with UID 780665 from your local IMAP it
responds with an empty message. This line is supposed to contain the
full email message:
> imap: Returned object from fetching 780665: ('OK', ['72967 (UID 780665 BODY[] "")'])

Your mail server is serving something bogus here, it seems. Where the
"content is: '2'" comes from, I don't know.

> Three things:
> 
> 1) It copies about the same number of emails each time and then bails.
> 2) It creates a bogus email in my inbox consisting of a single
>    character: “2”.  No From headers or To headers… just the number 2.
> 
> I delete the bogus email from my maildir locally and (probably because
> I've confused my local IMAP by deleting the non-mail file), it crashes again:

This is ok in the IMAP<->Maildir case, but a bit more tricky in the IMAP<->IMAP
case. We maintain a UIDmap file containing the mapping between remote
and local UIDs. If the local UID just disappears, we prune this mapping, so we
will just redownload the mail file from the remote IMAP, I guess.

>     Establishing connection to tunnel:nice env MAILDIR=/home/mah/maildir/everybody.org /usr/lib/dovecot/imap.

There have been changes to the tunneled authentication recently. I am
not sure if that is resonsible for anything...

>     Establishing connection to mail.nichework.com:993.
>     Syncing INBOX: IMAP -> MappedIMAP
>     Deleting 6 messages (407, 408, 409, 410, 411, 412) in MappedIMAP[INBOX]
>     WARNING: ERROR attempting to sync flags for account nichework.com:Traceback (most recent call last):
>       File "/usr/lib/pymodules/python2.7/offlineimap/folder/Base.py", line 486, in syncmessagesto
>         action(dstfolder, statusfolder)
>       File "/usr/lib/pymodules/python2.7/offlineimap/folder/Base.py", line 397, in syncmessagesto_delete
>         folder.deletemessages(deletelist)
>       File "/usr/lib/pymodules/python2.7/offlineimap/folder/UIDMaps.py", line 242, in deletemessages
>         self._mb.deletemessages(self, self._uidlist(self.r2l, uidlist))
>       File "/usr/lib/pymodules/python2.7/offlineimap/folder/UIDMaps.py", line 77, in _uidlist
>     return [mapping[x] for x in items]
>     KeyError: 408L

These messages have been deleted on the REMOTE IMAP server: 407, 408,
409, 410, 411, 412 and it tries to delete them on the LOCAL
one. However, you have manually deleted the corresponding one on the
local IMAP server, and therefore pruned the mapping between REMOTE UID
405 and whatever the local one is. LocalStatus (our cache) still shows
that we have this already synced, so it fails hard trying to look up the
UID of the local one now. You can fix this by removing the line in the
corresponding LocalStatus file (the one with 408 in it). We definitely
should not fail hard here. I'd consider that a bug. Our only excuse is
that this behavior has existed forever and we did not have time to fix
it since the maintainer change.

Sebastian
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 197 bytes
Desc: not available
URL: <http://alioth-lists.debian.net/pipermail/offlineimap-project/attachments/20110501/227a0ba8/attachment-0001.sig>