KeyError during IMAP to IMAP sync of deleted msgs

Dan Christensen jdc at uwo.ca
Sun Dec 6 22:13:20 GMT 2009


I get a very similar backtrace whenever I try to sync a large number of
new messages in a local IMAP folder to a remote IMAP folder.  (Both
servers running dovecot under Ubuntu.)  It's 100% repeatable, and like
Tony, offlineimap makes progress so if I run it repeatedly it eventually
finishes.  The error typically occurs after several hundred messages
have been successfully copied.  Since I've converting some large folders
from another format to imap, I've having to run offlineimap dozens of
times per folder.

Any information I can provide to help debug this further?

Dan

Tony Bennett <tony.e.bennett at gmail.com> writes:

> Hi
>
> I've just started using offlineimap - hoping it will allow me to
> effectively use gnus again :-)
>
> However offlineimap sync will frequently fail when sync'ing
> "deletions" - actually just moves from 1 folder to a "trash"
> folder.
>
> Setup is IMAP (exchange) -> IMAP (dovecot on my laptop)
> Mail client is Gnus which talks to dovecot using IMAP.
>
> Gnus is setup to move messages into folder Trash when I "delete" them.
>
> I'm using the 'git' version of offlineIMAP with the 'X-OfflineIMAP:'
> header patch.
>
> 2 folders being sync'd:  Test, Trash
>
> If I delete 20 messages in this way, exit Gnus, then initiate
> offlineimap syncup, it will usually (not always) die with a 'KeyError'.
> Typical pattern is:
>
>     I delete 20 msgs from Test folder within Gnus, which moves
>     them into 'Trash' folder.
>
>     Exit from Gnus.
>
>     Initiate offlineIMAP run
>
>       syncs 5 or so msgs.
>       dies with a keyerror on a msgs.
>
>     Initiate a 2nd offlineIMAP run a few minutes later
>       syncs a few msgs.
>       again dies with a keyerror on a different msg.
>
>      ...
>
>     repeat offlineIMAP until all sync'd ok.
>
>
>
> It does make forward progress and will eventually move all the msgs ok.
>
>
> I don't really know python, but from hacking around it seems to be
> dieing on the *** line below from folder/IMAP.py processmessagesflags:
>
>       if not ('UID' in attributehash and 'FLAGS' in attributehash):
>           # Compensate for servers that don't return a UID attribute.
>           continue
>       lflags = attributehash['FLAGS']
>       uid = long(attributehash['UID'])
>  ***  self.messagelist[uid]['flags'] = imaputil.flagsimap2maildir(lflags)
>       try:
>           needupdate.remove(uid)
>       except ValueError:          # Let it slide if it's not in the list
>           pass
>
>
> Is this a "reasonable" failure?
> Or does it indicate some fundamental problem with my setup?
>
>
> Microsoft Exchange Server 2003 IMAP4rev1 server version 6.5.7638.1 
>
>
> Appending a log:
> ----------------
>
>
>  ++ Pass 104
>  Thu Jan  8 09:34:37 2009
>  Running 'offlineimap -c .gen-offit-imaprc -u Noninteractive.Basic'
>
>  OfflineIMAP 6.0.3
>  Copyright (C) 2002 - 2008 John Goerzen <jgoerzen at complete.org>
>  This software comes with ABSOLUTELY NO WARRANTY; see the file
>  COPYING for details.  This is free software, and you are welcome
>  to distribute it under the conditions laid out in COPYING.
>  ++ Processing account tb-nv
>  Copying folder structure from IMAP to MappedIMAP
>  Establishing connection to owa.nvidia.com:993.
>  Establishing connection to localhost:143.
>  Syncing tTest: IMAP -> MappedIMAP
>  Establishing connection to localhost:143.
>  Syncing Trash: IMAP -> MappedIMAP
>  Deleting 18 messages (27, 28, 49, 64, 65, 84, 145, 168, 174, 186, 190,
>      235, 245, 249, 259, 263, 276, 297) in IMAP[tTest], LocalStatus[tTest]
>  Establishing connection to owa.nvidia.com:993.
>  Copy message -11 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -18 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -17 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -16 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Thread 'New msg sync from Trash' terminated with exception:
>  Traceback (most recent call last):
>    File "/Users/tbennett/python/offlineimap/offlineimap/threadutil.py",
>      line 149, in run
>      Thread.run(self)
>    File "2.5/lib/python2.5/threading.py", line 440, in run
>      self.__target(*self.__args, **self.__kwargs)
>    File "offlineimap/folder/Base.py", line 226, in syncmessagesto_neguid_msg
>      self.deletemessage(uid) # It'll be re-downloaded.
>    File "offlineimap/folder/UIDMaps.py", line 210, in deletemessage
>      self._mb.deletemessage(self, self.r2l[uid])
>    File "offlineimap/folder/IMAP.py", line 413, in deletemessage
>      self.deletemessages_noconvert([uid])
>    File "offlineimap/folder/IMAP.py", line 424, in deletemessages_noconvert
>      self.addmessagesflags_noconvert(uidlist, ['T'])
>    File "offlineimap/folder/IMAP.py", line 342, in addmessagesflags_noconvert
>      self.processmessagesflags('+', uidlist, flags)
>    File "offlineimap/folder/IMAP.py", line 395, in processmessagesflags
>      self.messagelist[uid]['flags'] = imaputil.flagsimap2maildir(lflags)
>  KeyError: 3770L
>
>
>  Last 39 debug messages logged for New msg sync from Trash prior to exception:
>  imap: Returned object from fetching 3777:
>      ('OK', [('3305 (UID 3777 BODY[] {2959}',
>      'Received: from hqemfe03.nvidia.com (172.16.227.123) by
>      hqemhub02.nvidia.com\r\nX-OfflineIMAP: x1933549553-044430925898-v6.0.3\r\n
>      (172.17.98.27) with Microsoft SMTP Server id 8.1.311.2; Sat, 3 Jan
>      2009\r\n 21:45:05 -0800\r\n ...
>  imap: savemessage: called
>  imap: savemessage: using date " 3-Jan-2009 21:45:05 -0500"
>  imap: savemessage: initial content is: 'Received: from hqemfe03.nvidia.com
>      (172.16.227.123) by hqemhub02.nvidia.com\r\nX-OfflineIMAP:
>      x1933549553-044430925898-v6.0.3\r\n (172.17.98.27) with Microsoft SMTP
>      Server id 8.1.311.2; Sat, 3 Jan 2009\r\n ...
>  imap: savemessage: new headers are: X-OfflineIMAP:
>      x613059387-043992930615-v6.0.3
>  imap: savemessage_addheader: called to add X-OfflineIMAP:
>      x613059387-043992930615-v6.0.3
>  imap: savemessage_addheader: insertionpoint = 75
>  imap: savemessage_addheader: leader = 'Received: from hqemfe03.nvidia.com
>      (172.16.227.123) by hqemhub02.nvidia.com'
>  imap: savemessage_addheader: newline = '\r\nX-OfflineIMAP:
>      x613059387-043992930615-v6.0.3'
>  imap: savemessage_addheader: trailer = '\r\nX-OfflineIMAP:
>      x1933549553-044430925898-v6.0.3\r\n (172.17.98.27) with Microsoft SMTP
>      Server id 8.1.311.2; Sat, 3 Jan 2009\r\n
>  imap: savemessage: new content is: 'Received: from hqemfe03.nvidia.com
>      (172.16.227.123) by hqemhub02.nvidia.com\r\nX-OfflineIMAP:
>      x613059387-043992930615-v6.0.3\r\nX-OfflineIMAP:
>      x1933549553-044430925898-v6.0.3\r\n (172.17.98.27) with Microsoft SMTP
>      Server id 8.1.311.2; Sat, 3 Jan 2009\r\n 21:45:05 -0800\r\n
>  imap: savemessage: new content length is 3006
>  imap: savemessage: first attempt to get new UID
>  imap: savemessage_searchforheader called for X-OfflineIMAP:
>      x613059387-043992930615-v6.0.3
>  imap: savemessage_searchforheader got initial matchinguids: '146618'
>  imap: savemessage_searchforheader: matchinguids now ['146618']
>  imap: savemessage: returning 146618
>  imap: savemessage: called
>  imap: savemessage: using date " 3-Jan-2009 21:45:05 -0500"
>  imap: savemessage: initial content is: 'Received: from hqemfe03.nvidia.com
>      (172.16.227.123) by hqemhub02.nvidia.com\r\nX-OfflineIMAP:
>      x1933549553-044430925898-v6.0.3\r\n (172.17.98.27) with Microsoft SMTP
>      Server id 8.1.311.2; Sat, 3 Jan 2009\r\n 21:45:05 -0800\r\n
>  imap: savemessage: new headers are: X-OfflineIMAP:
>      x613059387-00918347082237-v6.0.3
>  imap: savemessage_addheader: called to add X-OfflineIMAP:
>      x613059387-00918347082237-v6.0.3
>  imap: savemessage_addheader: insertionpoint = 75
>  imap: savemessage_addheader: leader = 'Received: from hqemfe03.nvidia.com
>      (172.16.227.123) by hqemhub02.nvidia.com'
>  imap: savemessage_addheader: newline = '\r\nX-OfflineIMAP:
>      x613059387-00918347082237-v6.0.3'
>  imap: savemessage_addheader: trailer = '\r\nX-OfflineIMAP:
>      x1933549553-044430925898-v6.0.3\r\n (172.17.98.27) with Microsoft SMTP
>      Server id 8.1.311.2; Sat, 3 Jan 2009\r\n
>  imap: savemessage: new content is: 'Received: from hqemfe03.nvidia.com
>      (172.16.227.123) by hqemhub02.nvidia.com\r\nX-OfflineIMAP:
>      x613059387-00918347082237-v6.0.3\r\nX-OfflineIMAP:
>      x1933549553-044430925898-v6.0.3\r\n (172.17.98.27) with Microsoft SMTP
>      Server id 8.1.311.2; Sat, 3 Jan 2009\r\n
>  imap: savemessage: new content length is 3008
>  imap: savemessage: first attempt to get new UID
>  imap: savemessage: returning 3779
>  imap: imapsplit() called with input: 3298 (UID 3770 FLAGS (\Deleted \Seen))
>  imap: imapsplit() returning: ['3298', '(UID 3770 FLAGS (\\Deleted \\Seen))']
>  imap: imapsplit() called with input: UID 3770 FLAGS (\Deleted \Seen)
>  imap: imapsplit() returning: ['UID', '3770', 'FLAGS', '(\\Deleted \\Seen)']
>  imap: options2hash called with input:
>     ['UID', '3770', 'FLAGS', '(\\Deleted \\Seen)']
>  imap: options2hash returning:
>     {'FLAGS': '(\\Deleted \\Seen)', 'UID': '3770'}
>  imap: processmessagesflags uid 3770, flags:
>     '(\Deleted \Seen)' calls flagimap2maildir
>  imap: flagsimap2maildir() begins
>  imap: flagsimap2maildir() returning: ['S', 'T']
>  Command 'offlineimap -c .gen-offit-imaprc
>     -u Noninteractive.Basic' exited with value 100
>
>  Thu Jan  8 09:35:07 2009
>
>  Retry after error in 2 minutes...
>
>  ++ Pass 105
>  Thu Jan  8 09:37:07 2009
>  Running 'offlineimap -c .gen-offit-imaprc
>     -u Noninteractive.Basic'
>
>  OfflineIMAP 6.0.3
>  Copyright (C) 2002 - 2008 John Goerzen <jgoerzen at complete.org>
>  This software comes with ABSOLUTELY NO WARRANTY; see the file
>  COPYING for details.  This is free software, and you are welcome
>  to distribute it under the conditions laid out in COPYING.
>  ++ Processing account tb-nv
>  Copying folder structure from IMAP to MappedIMAP
>  Establishing connection to owa.nvidia.com:993.
>  Establishing connection to localhost:143.
>  Syncing tTest: IMAP -> MappedIMAP
>  Establishing connection to localhost:143.
>  Syncing Trash: IMAP -> MappedIMAP
>  Copy message -11 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -17 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Establishing connection to owa.nvidia.com:993.
>  Copy message -16 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -15 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -14 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -13 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -12 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -2 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -10 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -9 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -8 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -7 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -6 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -5 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -4 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -3 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Copy message -1 MappedIMAP[Trash] -> IMAP[Trash], LocalStatus[Trash]
>  Deleting 4 messages (146609, 146610, 146611, 146615) in IMAP[Trash],
>     LocalStatus[Trash]
>  Deleting flags S to 2 messages on IMAP[Trash]
>  Deleting flags S to 2 messages on LocalStatus[Trash]
>  Copy message 146620 IMAP[Trash] -> MappedIMAP[Trash], LocalStatus[Trash]
>  Copy message 146621 IMAP[Trash] -> MappedIMAP[Trash], LocalStatus[Trash]
>  ++ Finished processing account tb-nv
>
>  Thu Jan  8 09:37:29 2009
>
>  Delaying 300 seconds...
>
>
>  -- 
>
>  --tony





More information about the OfflineIMAP-project mailing list