Re: sync hangs without any kind of error message

[Daniel Pittman <daniel@xxxxxxxxxxxx>]

Daniel Pittman <daniel@xxxxxxxxxxxx> writes:
> John Goerzen <jgoerzen@xxxxxxxxxxxx> writes:
>> Arian Kuschki wrote:
>>
>>> I am a new user and trying to sync my Gmail account for the first time. At
>>> downloading thousands of emails at some point offlineimap just stops syncing
>>> without any indication why. The screen looks like below and will not change
>>> anymore:
>>
>> What version of OfflineIMAP?
>
> I have what looks like the same problem, on the latest Debian/unstable:

OK.  I spent the time to dig into this some more, and traced the problem down
to what *looks* like a bug in imaplib2 on my platform.  I have this version
information, as part of the 6.1.1 release:

    __version__ = "2.6"   __release__ = "2"    __revision__ = "6"

As a side note, it looks like the docstring for the 'idle' method is odd; it
starts with four double-quote characters on line 632.


Anyway, it looks like imaplib2 is not expecting a continuation response
subsequent to an 'APPEND' command, and hangs because of it, despite the fact
that this is what dovecot normally sends back.

I captured the 'rawlog' details for a successful and unsuccessful append:

OfflineIMAP sends this for a successful case:

JMDP375 SELECT "community/perl/canberra"
JMDP376 APPEND "community/perl/canberra" (\Seen) "18-Jun-2008 19:26:46 +1000" 
{8290}
[... message body elided for sanity ...]

Dovecot responds:

[... the select details elided ...]
JMDP375 OK [READ-WRITE] Select completed.
+ OK
* 4 EXISTS
* 1 RECENT
JMDP376 OK [APPENDUID 1247655345 4] Append completed.


In the unsuccessful case we get this (and these are *all* the commands that
are logged by Dovecot subsequent to the successful append; command 377 is
nowhere visible in the logs...)

JMDP378 CHECK
JMDP379 SELECT "community/perl/canberra"
JMDP380 APPEND "community/perl/canberra" (\Seen) "18-Jun-2008 20:08:00 +1000" 
{6404}

The response:

JMDP378 OK Check completed.
* OK [CLOSED]
* FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
* OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags 
permitted.
* 4 EXISTS
* 0 RECENT
* OK [UIDVALIDITY 1247655345] UIDs valid
* OK [UIDNEXT 5] Predicted next UID
* OK [HIGHESTMODSEQ 1]
JMDP379 OK [READ-WRITE] Select completed.
+ OK


...and the offlineimap debug logs at this stage read:

wrtr: DEBUG[imap]: 55:47.22 wrtr > JMDP380 APPEND "community/perl/canberra" 
(\Seen) "18-Jun-2008 20:08:00 +1000" {6404}\r\n
redr: DEBUG[imap]: 55:47.22 redr poll => [(7, 1)]
redr: DEBUG[imap]: 55:47.22 redr rcvd 6
redr: DEBUG[imap]: 55:47.22 redr < + OK\r\n
hdlr: DEBUG[imap]: 55:47.22 hdlr unexpected continuation response: '+ OK'


Better still, looking into this in the newest release of imaplib2.py, I see
that there has been a change made to '_command', commented:

+        # Must setup continuation expectancy *before* ouq.put

So, my guess is that this is, in fact, a race in imaplib2 that can be
triggered to cause it to hang when the response is received from the IMAP
server before the continuation allowed bit is set.


Finally, testing with the git 220db8a77db69c6153ac1de9ac8f014c911e6829 tells
me that, indeed, the problem is solved by upgrading to the latest imaplib2.

So, as far as I am concerned this is now a resolved issue pending only another
release of offlineimap to make that change public to the world.

Regards,
        Daniel

-- 
✣ Daniel Pittman            ✉ daniel@xxxxxxxxxxxx            ☎ +61 401 155 707
               ♽ made with 100 percent post-consumer electrons