KeyError during IMAP to IMAP sync of deleted msgs

[Tony Bennett <tony.e.bennett@xxxxxxxxx>]

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@xxxxxxxxxxxx>
 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@xxxxxxxxxxxx>
 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