Unexpected tags interrupt sync when talking to outlook.com's IMAP servers
mailbox synchronizer
Brought to you by:
ossi
Hi,
I'm using the latest git master (46e792c3dfc5b81a0bf54d95a0b43429013a224d) to sync an outlook.com IMAP account with a local Maildir. Here's my configuration:
Expunge None Create Both MaildirStore local Path ~/Mail/ Trash Trash IMAPStore my-username@live.com Host imap-mail.outlook.com User my-username@live.com Pass my-password CertificateFile /etc/ssl/certs/ca-certificates.crt Port 993 SSLType IMAPS Channel my-username@live.com Master :my-username@live.com: Slave :local:my-username@live.com
The first run of mbsync -a
timed out after a few messages. Subsequent runs all had issues with tags:
$ mbsync -a C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +0/0 *0/0 #0/0 Maildir notice: no UIDVALIDITY, creating new. C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +18/294 *0/0 #0/0 Socket error on imap-mail.outlook.com (207.46.11.202:993): timeout. C: 1/1 B: 1/1 M: +0/0 *0/0 #0/0 S: +18/294 *0/0 #0/0 $ mbsync -a C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +0/0 *0/0 #0/0 Warning: lost track of 276 pulled message(s) C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +29/276 *0/0 #0/0 IMAP error: unexpected tag 100070 C: 1/1 B: 1/1 M: +0/0 *0/0 #0/0 S: +29/276 *0/0 #0/0 $ mbsync -a C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +0/0 *0/0 #0/0 Warning: lost track of 247 pulled message(s) C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +29/247 *0/0 #0/0 IMAP error: unexpected tag 100100 C: 1/1 B: 1/1 M: +0/0 *0/0 #0/0 S: +29/247 *0/0 #0/0 $ mbsync -a C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +0/0 *0/0 #0/0 Warning: lost track of 218 pulled message(s) C: 0/1 B: 0/1 M: +0/0 *0/0 #0/0 S: +29/218 *0/0 #0/0 IMAP error: unexpected tag 100129 C: 1/1 B: 1/1 M: +0/0 *0/0 #0/0 S: +29/218 *0/0 #0/0
Running with the -D
option shows a normal-looking trace, until the final few messages:
32 OK FETCH Completed -> new UID 132 on slave * 133 FETCH (UID 100133 BODY[] {4680} ) 33 OK FETCH Completed -> new UID 133 on slave * 134 FETCH (UID 100134 BODY[] {5072} ) 34 OK FETCH Completed -> new UID 134 on slave 100135 BAD Bad command. IMAP error: unexpected tag 100135
How can I help debug this issue further?
I noticed one thing: the number of messages downloaded before crashing is always 29:
Exept in the first case where the
S:
counter reports 29, but thelost track of
message reports a difference of 28 (154 to 126).Does this make sense?
Hi,
I am seeing this as well when trying to sync FROM a local MailDir store TO an on-premise Exchange 2013 server. Running mbsync 1.2.1 on Debian 8.
Anything I can contribute to the solution? Logs, Exchange settings, whatever?
Thanks
Evgenij
exchange is the only server this is happening with, and it's happening pretty consistently, for no apparent reason whatsoever. that's pretty good evidence that the server is simply broken.
it seems to have botched input buffering, either skipping or duplicating part of the data sent to it. if you find a way to dump raw data as seen by the server at different layers (socket, decrypted ssl, command tokenizer) and can correlate it with the corresponding logs from mbsync/your client machine, you may be able to deduce where to look for knobs to work around the issue. i'd be interested in the results as well.
For us the problem has been 'solved' by adding
PipelineDepth 1
to theIMAPAccount
section of our configuration file, in order to disable concurrent IMAP commands.The trick with PipelineDepth helped to me as well.
Yes can confirm this tricks work for me. Despite that have no reason why before my mbsync worksed completely fine with (PipelineDepth = 50) and all of a sudden it does not work until I set it to 1
fwiw, the wip/exchange-workarounds-1.* branches contain prospective solutions to the issue(s).
thanks, I rebased
wip/exchange-workarounds-1.4
ontomaster
and it solves this for menot sure if that's the most recent version of exchange workarounds. the code in -1.4 looks similar, but distinct from what's in -1.5
I'm still experiencing this on 1.4.4, on NixOS with Microsoft 365, Exchange Online.
However, the tag errors actually look more like XML or HTML elements in debugging.
Anyone else experiencing this - or should I open a new bug?