Error APPEND -> BAD (invalid argument: unable to parse message) since 6.5.7rc2

[mobamoba]

I've been using Offlineimap for a few years and, since going to from 6.5.6. to 6.5.7rc2, I've started receiving the following error message when syncing one of my folders to Gmail:

Establishing connection to imap.gmail.com:993
ERROR: Saving msg ([unknown message-id]) folder 'SMS', repo 'Remote'failed (error). Server responded: APPEND command error: BAD ['Invalid Arguments: Unable to parse message']. Data: LIGG20 APPEND SMS (\Seen) {1}

Message content was: 4
ERROR: Saving msg ([unknown message-id]) folder 'SMS', repo 'Remote'failed (error). Server responded: APPEND command error: BAD ['Invalid Arguments: Unable to parse message']. Data: OJOA7 APPEND SMS (\Seen) {1}

Message content was: 4

[nicolas33]

No more trace?
Repository type?
Did you test current next branch?
Finally, could you git bisect this issue?

[mobamoba]

I'm using the Master branch which lists itself as 6.5.7rc2. Offlineimap doesn't crash - it just gives the error I listed above and continues then repeats the error the next time it checks (again without crashing). My remote repository is Gmail and my local is Zarafa IMAP.

I'm a noob so can you be more specific about what "git bisect" is and what you need me to do? Thanks.

[nicolas33]

• Found this old imaplib report.
• I think we should provide more context while giving such error.

Please, run a session with -d all and attach the logs. Be care to remove the password. You might also send the full log to me directly by mail if you don't want to not get it public.

[nicolas33]

Also, please check with current next branch:
$ git checkout next
$ ./offlineimap.py <your usual options> -d all

[mobamoba]

I installed the "next" version and still have the issue. When I run
offlineimap -d all, where does the log save to so I can send it to you? I
just get a ton of output in my terminal but can't see where it's saving.

On Sun, Feb 22, 2015 at 6:31 AM, Nicolas Sebrecht notifications@github.com
wrote:

Also, please check with current next branch:
$ git checkout next
$ ./offlineimap.py -d all

—
Reply to this email directly or view it on GitHub
#172 (comment)
.

[nicolas33]

On Sun, Feb 22, 2015 at 11:00:35AM -0800, mobamoba wrote:

I installed the "next" version and still have the issue. When I run
offlineimap -d all, where does the log save to so I can send it to you?

It goes only to stdout unless you use -l LOG_FILE.
See offlineimap --help.

Nicolas Sebrecht

[mobamoba]

Debug log attached as a zip file. I replaced my password with ###### and my
actual email account with "account@gmail.com". I let it run for just over a
minute so hopefully that was enough to log the errors. Let me know if
there's anything else you need at my end. Thanks.

On Sun, Feb 22, 2015 at 5:20 PM, Nicolas Sebrecht notifications@github.com
wrote:

On Sun, Feb 22, 2015 at 11:00:35AM -0800, mobamoba wrote:

I installed the "next" version and still have the issue. When I run
offlineimap -d all, where does the log save to so I can send it to you?

It goes only to stdout unless you use -l LOG_FILE.
See offlineimap --help.

Nicolas Sebrecht

—
Reply to this email directly or view it on GitHub
#172 (comment)
.

[nicolas33]

There is no attachement. Consider https://gist.github.com/.

[mobamoba]

The file was too large for gist. I've put it on my Google Drive:
https://drive.google.com/file/d/0B6XtuCxhp2HCeHhPZFdiWkpMWUtpVm5CeXBnRkMyejBGV1FR/view?usp=sharing

[nicolas33]

There was no error with this session.

[nicolas33]

Try with -d all and redirect outputs: offlineimap.py -d all > debug.log 2>&1

[mobamoba]

Here you go:
https://drive.google.com/file/d/0B6XtuCxhp2HCcVhlNmc1eGxqSVE/view?usp=sharing

[nicolas33]

Relevant logs for further digging:

Copy message from Local:SMS:
 [imap]:   01:28.22 Copy message from Local:SMS LOGOUT:FKFI41.ready.wait
imap.gmail.com reader:
 [imap]:   01:28.25 imap.gmail.com reader poll => [(4, 1)]
 [imap]:   01:28.25 imap.gmail.com reader rcvd 57
 [imap]:   01:28.25 imap.gmail.com reader < * BYE LOGOUT Requested\r\n
 [imap]:   01:28.25 imap.gmail.com reader < FKFI41 OK 73 good day (Success)\r\n
imap.gmail.com handler:
 [imap]:   01:28.25 imap.gmail.com handler untagged_responses[BYE] 0 += ["LOGOUT Requested"]
 [imap]:   01:28.25 imap.gmail.com handler BYE response: LOGOUT Requested
imap.gmail.com reader:
 [imap]:   01:28.25 imap.gmail.com reader poll => []
 [imap]:   01:28.25 imap.gmail.com reader finished
imap.gmail.com handler:
 [imap]:   01:28.26 imap.gmail.com handler terminating: 'connection terminated'
imap.gmail.com writer:
 [imap]:   01:28.26 imap.gmail.com writer finished
Copy message from Local:SMS:
 [imap]:   01:28.26 Copy message from Local:SMS ["<type 'exceptions.TypeError'>: raise: arg 3 must be a traceback or None"]
 [imap]:   01:28.26 Copy message from Local:SMS _close_threads
 [imap]:   01:28.26 Copy message from Local:SMS call shutdown
imap.gmail.com handler:
 [imap]:   01:28.26 imap.gmail.com handler LOGOUT:FKFI41.ready.set
 [imap]:   01:28.26 imap.gmail.com handler state_change_free.set
 [imap]:   01:28.26 imap.gmail.com handler finished
Copy message from Local:SMS:
 [imap]:   01:28.26 Copy message from Local:SMS state_change_pending.release
 [imap]:   01:28.26 Copy message from Local:SMS connection closed
 [imap]:   01:28.26 Copy message from Local:SMS _get_untagged_response(BYE) => ['LOGOUT Requested']
 Establishing connection to imap.gmail.com:993
 [imap]:   01:28.26 Copy message from Local:SMS imaplib2 version 2.37
 [imap]:   01:28.26 Copy message from Local:SMS imaplib2 debug level 5, buffer level 3
 ERROR: Saving msg ([unknown message-id]) folder 'SMS', repo 'Remote'failed (error). Server responded: APPEND command error: BAD ['Invalid Arguments: Unable to parse message']. Data: FKFI39 APPEND SMS (\Seen) {1}

Traceback:
  File "/usr/local/lib/python2.7/dist-packages/offlineimap/folder/Base.py", line 711, in copymessageto
    new_uid = dstfolder.savemessage(uid, message, flags, rtime)
  File "/usr/local/lib/python2.7/dist-packages/offlineimap/folder/Gmail.py", line 195, in savemessage
    return super(GmailFolder, self).savemessage(uid, content, flags, rtime)
  File "/usr/local/lib/python2.7/dist-packages/offlineimap/folder/IMAP.py", line 576, in savemessage
    imaputil.flagsmaildir2imap(flags), date, content)
  File "/usr/local/lib/python2.7/dist-packages/offlineimap/imaplib2.py", line 629, in append
    return self._simple_command(name, mailbox, flags, date_time, **kw)
  File "/usr/local/lib/python2.7/dist-packages/offlineimap/imaplib2.py", line 1620, in _simple_command
    return self._command_complete(self._command(name, *args), kw)
  File "/usr/local/lib/python2.7/dist-packages/offlineimap/imaplib2.py", line 1386, in _command_complete
    raise self.error('%s command error: %s %s. Data: %.100s' % (rqb.name, typ, dat, rqb.data))

This looks like a bug in imaplib2, I'm forwarding to the maintainer.

[nicolas33]

https://sourceforge.net/p/imaplib2/bugs/6/

[johnmolyneux]

The traceback doesn't include the offending APPEND whose arguments are invalid. Any chance of getting a much longer traceback (the part shown is just the logout handshake induced by the error)?

[mobamoba]

I'm still getting the error so if you tell me what you need me to do in order to get a longer traceback for you, I'm happy to do it.

[nicolas33]

@johnmolyneux : did you looked at https://drive.google.com/file/d/0B6XtuCxhp2HCcVhlNmc1eGxqSVE/view?usp=sharing ?

[johnmolyneux]

Apologies - didn't notice the full debug file. I've now looked at it and I'm no wiser. There are several APPEND commands, all substantially identical that worked fine before the last one failed. They all take the form "XXXXX APPEND SMS (\Seen) {1}\r\n" where XXXXX is the IMAP4 command tag. So, I'd guess that this is not an imaplib2 bug, but something else. One thing struck me and that is that for any particular IMAP4 instance the first 4 letters of the tag are always the same, so for instance this log shows a session starting with the tag FKFI, but the errant APPEND has quite a different tag. Hope that helps.

[johnmolyneux]

Should have looked harder. There are multiple sessions in that log, each ending with an APPEND error, so that explains the different tags. Each APPEND command is well formed as per the IMAP4 spec, as is the data written, so I'm not sure why the error is 'Invalid Arguments', unless it is that the RFC specifies that the literal argument "SHOULD be in the format of an [RFC-2822] message" - which isn't the case here.

[nicolas33]

Yes, I should have told you it's a multi-sessions logs. What stuck me most is that everything goes fine for the same IMAP server on the other sessions and this same error is raised (at some random time) and is reproducible.

@mobamoba : could you please run offlineimap --info? Do you know what is the IMAP server?

[mobamoba]

The remote type Gmail and is imap.gmail.com:993 and the Local is localhost:143 (I used Zarafa for my local IMAP). Do you need more info than that?

[nicolas33]

@mobamoba Could you try to bisect this issue? (http://offlineimap.github.io/doc/git-bisect.html)

[mobamoba]

I got this:
e8db121 is the first bad commit
commit e8db121
Author: Eygene Ryabinkin rea@codelabs.ru
Date: Sun Jun 1 22:09:44 2014 +0400

Fix improper header separator for X-OfflineIMAP header

For servers without UIDPLUS we are inserting additional header
just after transformation '\n' -> CRLF was done.  addmessageheaders()
was written to work with just '\n' as the separator, so X-OfflineIMAP
header wasn't preceeded by the CRLF, but just by '\n'.

Signed-off-by: Eygene Ryabinkin <rea@codelabs.ru>

:100644 100644 a05dec2c0406ed95a5c7a75cd8af723523e088a5 4a4db93996f20f6c667c69b4ba7b4ccc1ae47655 M Changelog.rst
:040000 040000 311b825bd1569f71c585f2eee3f5820a6b83675c cbe9d8ef9ed66b6a5004ab90cd1c84c21362d5bd M offlineimap

[nicolas33]

@konvpalto : could you please look at this?

[nicolas33]

So, the message gets refused by the server because it couldn't parse the headers correctly.
@mobamoba, please:

• share your configuration file (remove passwords)
• try to find our the offfending messages with improper headers and share them

[mobamoba]

Okay. But how do I know which messages are the offending ones, i.e. how do I find them in my email?

[nicolas33]

From the logs. One current mail in the SMS folder is to blam. I don't know more because the logs saying the headers are modified was done on another sync.

• You might want to compare what is on remote and what is not.
• If nothing obvious, you could try to move last half mails in SMS out of the folder (or out of the Maildir) and re-sync to check if the issues is still there. Then you know what half has the offending mail. More iterations will let you know what's the offending mail.

[mobamoba]

Here's the unsatisfying resolution to this (unsatisfying because it doesn't tell you anything about the source of the bug): I did what you said and moved emails from one folder to another in chunks. Unfortunately (from the POV of bug-hunting), moving the email solved the problem. In other words, somehow the act of copying emails from one folder to another then copying them back to the original folder eliminated the error.

I'm not really sure how moving an email somehow fixes a header issue, but it did. So the bottom line is I now really have no idea which emails were causing the original problem because the effort to figure that out (moving to another folder then back) fixed the problem.

Would moving an email fix a malformed header?

[nicolas33]

Would moving an email fix a malformed header?

Indirectly, yes it looks like it did. Moving a mail of a folder means you re-upload the mail to the remote in the "other" folder. We add headers (what you bisected) at upload time of a "new" message.

Though, I was expecting the same issue to be fully reproductible and raise again.

Now, I must understand WHY the issue did not reproduce where it should have. IOW, you have the same message on disk (filename changed), same methods applied on it, same content changes expected on it, same remote server, different results... Weird!

[mobamoba]

Totally weird. However, I'm guessing I'll have this error again, so it may be worth leaving this thread open because maybe I'll be able to get a narrower date range next time and just look at the headers and see if I see anything missing or off.

The reason I think it'll happen again is because I reported this issue on 2/21; I first started by moving all emails from that folder prior to 2/21 into a different folder; this reduced the error count from 4 to 2, which means that I got this error twice more after initially reporting it.

Here's one thought though: the error is in my SMS folder, which is the folder I use to backup text messages from my phone. The program I use is SMS Backup+ (https://play.google.com/store/apps/details?id=com.zegoggles.smssync&hl=en), which sends my SMSes to my local (Zarafa) IMAP. Perhaps this program is occasionally creating an incorrect header or conflicting with Offlineimap in some way. Of course, this doesn't explain why moving the email would fix the header, but maybe the source is somewhere between these two programs?

[nicolas33]

Will know more with the headers. I keep this open. Thanks.

[mobamoba]

Okay so this error happened again and I managed to track it in time to figure out which message was causing it. It's on my local but won't sync to Gmail because of that APPEND error. Here are the headers from the offending message (with personally identifiable stuff x'ed out). Does this help at all?

Subject: SMS with xxxxxxxx
MIME-Version: 1.0
Content-Type: text/plain;
charset=utf-8
From: xxxxxxx xxxxxxx@gmail.com
To: xxxxxx
References: 7l767a1i0sc3omr1pwqjywuv.2681@sms-backup-plus.local
Message-ID: a1e0b545f6845476518ebf826e2929f6@sms-backup-plus.local
X-smssync-address: +1xxxxxxxxx
X-smssync-datatype: SMS
X-smssync-backup-time: 29 Apr 2015 20:37:56 GMT
X-smssync-version: 1550
Date: Wed, 29 Apr 2015 16:34:53 -0400
X-smssync-id: 6563
X-smssync-type: 1
X-smssync-date: 1430339693292
X-smssync-thread: 49
X-smssync-read: 0
X-smssync-status: -1
X-smssync-protocol: 0
X-smssync-service_center: +1xxxxxxxxx
Content-Transfer-Encoding: quoted-printable

[nicolas33]

I don't see any problem in these headers. You could try by removing one header line at a time to track down the offender.

[mobamoba]

How do I remove headers from an email I've already received in order to do that? Also, I checked other emails of the same kind and they all the have the same headers and sync perfectly, so perhaps it's not a header issue. But it's definitely something with that particular email as that's the one that generates that APPEND error. Is there some other tool that could better debug the problem with that email?

[nicolas33]

Could you send this offending mail to me privately?

[mobamoba]

Sure there's really nothing all that private in it. Where should I forward it to?

[nicolas33]

By mail, or a gist if it doesn't hurt.

[mobamoba]

I'm not actually sure how to attach an email to a gist. The text of the email was nothing - "Check out this video on Youtube" along with a Youtube link. I mentioned above that I use a program on my phone that backs up my SMS messages via IMAP and this was one of those messages. In fact all of the messages that generated this error are from that same SMS backup folder.

[mobamoba]

A little update to this: I get the exact same error when trying to sync an email with a very large attachment, one that's larger than the send or receive limit on one of the IMAP servers. I don't know if that helps as the original error pointed to an email that was very tiny and with no attachments, just a link, but I thought I'd let you know I'd seen it again in a different context.

[nicolas33]

On Sat, May 09, 2015 at 08:56:09AM -0700, mobamoba wrote:

A little update to this: I get the exact same error when trying to sync
an email with a very large attachment, one that's larger than the send
or receive limit on one of the IMAP servers. I don't know if that helps
as the original error pointed to an email that was very tiny and with
no attachments, just a link, but I thought I'd let you know I'd seen it
again in a different context.

Always good to have more info.

Nicolas Sebrecht

[nicolas33]

Any news on this?

[mobamoba]

I haven't seen this error in a while and knock wood it's gone for good.

[nicolas33]

Ok, thanks for the feedback.