Bug 351814

Summary: Kmail 15.08 will not sync Outlook365 IMAP Folders
Product: [Frameworks and Libraries] Akonadi Reporter: Daniel Shafer <onecoldworld>
Component: IMAP resourceAssignee: Christian Mollekopf <chrigi_1>
Status: RESOLVED FIXED    
Severity: major CC: clearmartin, davide, dvratil, jan_braun, jat255, john.rowley08, kdepim-bugs, lacsilva, markus.hess, orion2000za, vkrause, weigert.stefan, wodenhof
Priority: HI    
Version: unspecified   
Target Milestone: ---   
Platform: Arch Linux   
OS: Linux   
Latest Commit: Version Fixed In: 15.08.2
Sentry Crash Report:
Attachments: IMAP logs generated when trying to download messages

Description Daniel Shafer 2015-08-26 17:24:50 UTC
I added my work's Outlook365 details (which is the standard Outlook365 IMAP settings) into Kmail, it logs in fine as its able to grab the folder structure.  It starts to download email but just sticks at 0%.  

I added my own person IMAP server and it works fine, it seems to be isolated to Office 365.

Let me know if you need further info.


Reproducible: Always

Steps to Reproduce:
1. Open Kmail
2. Add Outlook365 credentials
3. Try to sync email

Actual Results:  
Folder sync hangs at 0% no folders are downloaded, but folder structure gets downloaded

Expected Results:  
Synced all my folders properly.

I did IMAP debug and the best info I got was:

S: A000443 OK SEARCH completed.
C: A000444 UID SEARCH UID 872001:874000
S: * SEARCH
S: A000444 OK SEARCH completed.
C: A000445 UID SEARCH UID 874001:876000
S: * SEARCH
S: A000445 OK SEARCH completed.
C: A000446 UID SEARCH UID 876001:878000
S: * SEARCH
S: A000446 OK SEARCH completed.
C: A000447 UID SEARCH UID 878001:880000
S: * SEARCH
S: A000447 OK SEARCH completed.
C: A000448 UID SEARCH UID 880001:882000
S: * SEARCH
S: A000448 OK SEARCH completed.
C: A000449 UID SEARCH UID 882001:884000

This goes on for an extremely long time, no messages are being downloaded, it literally just scrolls that message over a few million times.
Comment 1 jat255 2015-09-02 22:10:03 UTC
This bug also affects me, using my workplace's IMAP server (which worked fine on previous versions of Kmail). The server responds, as it can auto-detect SSL settings, and the folder tree downloads, but no messages will download. 

No amount of aborting, syncing, or restarting from the akonadi console helps, it just sticks on "Syncing folder 'Inbox' (0%)" forever with no particular output to the terminal. Every now and again, it will stop as though it completed, but still no messages appear. My IMAP logs are also attached and look similar to Daniel's.
Comment 2 jat255 2015-09-02 22:11:40 UTC
Created attachment 94360 [details]
IMAP logs generated when trying to download messages

Used the following commands to generate this output: 

export KIMAP_LOGFILE=/tmp/imap.log
akonadictl restart
Comment 3 Markus Heß 2015-09-07 07:48:57 UTC
I have the issue when I try to sync with a MS Exchange account.
Comment 4 John Rowley 2015-09-09 16:27:55 UTC
I too, am having this problem. Office 365 business account, getting stuck at 0% when syncing folders (folders which themselves are created just fine). I've tried clearing the cache of the account and checking that its status is marked as "Online". Thunderbird works fine.

Nethogs reports a constant 1-5KB/s traffic from process "/usr/bin/akonadi_imap_resource" while it's syncing. tcpdump reports a constant stream of the following two packets:

  19:05:03.232365 IP (tos 0x0, ttl 64, id 56774, offset 0, flags [DF], proto TCP (6), length 157)
    arch.59582 > 132.245.76.210.imaps: Flags [P.], cksum 0x9402 (incorrect -> 0x267f), seq 1873:1990, ack 1989, win 768, length 117
  19:05:03.333080 IP (tos 0x0, ttl 45, id 13447, offset 0, flags [DF], proto TCP (6), length 157)
    132.245.76.210.imaps > arch.59582: Flags [P.], cksum 0x85f0 (correct), seq 1989:2106, ack 1990, win 4016, length 117

IMAP_TRACE=1 output: http://pastebin.com/Wtifd4c5 - ("akonadictl restart && kmail" in a terminal).
Comment 5 Davide Gianforte 2015-09-16 09:08:53 UTC
I have the same issue. I have latest Applications 15.08.1.

At work I use KDE 4.14.3 and IMAP works fine.
Comment 6 Orion 2015-09-17 13:53:40 UTC
seeing the same on Kubuntu 15.10 Beta
KMail 4.81 Beta

office365.com - can create IMAP account and subscribe to folders. Fetching starts, Akonadi even reports correct numbers of items in a folder but nothing happens apart 0%

On my production system Kubuntu 14.10, Kmail 4.14.2 this works just fine
Comment 7 Jan-Matthias Braun 2015-09-17 19:26:47 UTC
Hi!

I am using kde-apps 15.08.1 version of kmail and I am having problems with an Exchange 2010 system, afaik. Nonetheless the symptoms are similar. Sometimes I am getting my INBOX updated, but most of the day not. I cannot even reproduce the update reliably. Stopping akonadi and restarting kmail won't work.

I too am seeing this endless sequence in my imap-log:
...
S: * SEARCH
S: A032761 OK SEARCH completed.
C: A032762 UID SEARCH UID 65508001:65510000
S: * SEARCH
S: A032762 OK SEARCH completed.
C: A032763 UID SEARCH UID 65510001:65512000
... and so on and on.

In my .xsession-errors I got the impression, that it actually gets the new mails and feeds them to the indexer:
Wrote 19189 bytes to  ".../.local/share/akonadi/file_db_data/992243_r0"
log_akonadi_indexer_agent: indexed  126
akonadiagentbase_log: 2837
log_akonadi_indexer_agent: Processing collection:  126
log_akonadi_indexer_agent:
log_akonadi_indexer_agent: Indexing Valid new e-Mail 1
log_akonadi_indexer_agent: Indexing Valid new e-Mail 2
log_akonadi_indexer_agent: Indexing Valid new e-Mail 3
log_akonadi_indexer_agent: Indexing Valid new e-Mail 4
log_akonadi_indexer_agent: Indexing Valid new e-Mail 5
log_akonadi_indexer_agent: Indexed  5  items in (ms):  23
log_akonadi_indexer_agent: Indexing complete. Total time:  25
log_akonadi_indexer_agent: indexed  127
log_akonadi_indexer_agent: Processing collection:  127
log_akonadi_indexer_agent:
log_akonadi_indexer_agent: Indexing Valid new e-Mail 1
log_akonadi_indexer_agent: Indexing Valid new e-Mail 2
log_akonadi_indexer_agent: Indexing Valid new e-Mail 3
log_akonadi_indexer_agent: Indexed  3  items in (ms):  13
log_akonadi_indexer_agent: Indexing complete. Total time:  15
log_akonadi_indexer_agent: Processing done

All those e-Mail-Subjects are new and not in my inbox. For at least half a dozen akonadi restarts I was only seeing them once.

So, different exchange server version, similar output and it looks like the new mails are indexed. But I am getting only around one INBOX update a day. All other accounts are working flawlessly.

What can I do to help?

All the best,

Jan
Comment 8 Jan-Matthias Braun 2015-09-17 19:27:10 UTC
*** This bug has been confirmed by popular vote. ***
Comment 9 Martin Kostolný 2015-09-23 14:20:31 UTC
I just commented another bug (https://bugs.kde.org/show_bug.cgi?id=351993) which seems to be a duplicate of this one.
Comment 10 Martin Kostolný 2015-09-23 14:26:07 UTC
Maybe another duplicate here: https://bugs.kde.org/show_bug.cgi?id=352701
But there is also a word about Kolab account (apart from Office365).
Comment 11 Jan-Matthias Braun 2015-09-23 15:45:35 UTC
Another observation is, that the corresponding akondi_imap_resource is quite CPU-demanding; most of the time with around 15 % on my system. The Outlook resource is at 50 minutes compute time right now, in comparison to below 10 seconds for my three other resources.

Nonetheless, I won't see new mails for days. Today (Wednesday) I saw the first update since Friday. The outlook resource has always been a bit slower with updates than the others, but only with the current version I am seeing no updates at all.

Is there any specific diagnostic I can run? For example to better understand the imap logs?
Comment 12 Jan-Matthias Braun 2015-09-27 12:09:49 UTC
Hi, I cannot tell for bug #351993, as I am only experiencing this problem with our corporate exchange server. All other accounts are working flawlessly and respond fast. The same goes for bug #352701 -- this is a very localised one resource-only problem for me.

For this exchange server imap idle never really seemed to have worked and now fetching mails seems to be stuck with some demanding operation which never seems to end. So I guess there is a general problem with the exchange server.
Comment 13 Jan-Matthias Braun 2015-09-27 12:11:34 UTC
The funny thing is, that smaller folders, like the Junk-Mail-Folder, updates occur.

The inbox folder is quite huge, so I tried to move two years worth of e-Mails, but this action never got synced and probably made things only worse.
Comment 14 Orion 2015-10-02 12:21:12 UTC
I can add that, at least for me still on Kubuntu 15.10 Beta2 with all upgrades this also affects pop3 access to office365.com. Just to test I deleted the IMAP and created a POP3 account instead. 

Same outcome - no fetching takes place

this is a "showstopper" to me - I have to have access to office365.com and I need the mail offline, not only via webmail or similar. 

This works just fine on "pre Plasma5 KMail"
Comment 15 jat255 2015-10-02 12:43:04 UTC
(In reply to Jan-Matthias Braun from comment #7)
> Hi!
> 
> I am using kde-apps 15.08.1 version of kmail and I am having problems with
> an Exchange 2010 system, afaik. Nonetheless the symptoms are similar.
> Sometimes I am getting my INBOX updated, but most of the day not. I cannot
> even reproduce the update reliably. Stopping akonadi and restarting kmail
> won't work.
> 
> I too am seeing this endless sequence in my imap-log:
> ...
> S: * SEARCH
> S: A032761 OK SEARCH completed.
> C: A032762 UID SEARCH UID 65508001:65510000
> S: * SEARCH
> S: A032762 OK SEARCH completed.
> C: A032763 UID SEARCH UID 65510001:65512000
> ... and so on and on.
> 
> In my .xsession-errors I got the impression, that it actually gets the new
> mails and feeds them to the indexer:
> Wrote 19189 bytes to  ".../.local/share/akonadi/file_db_data/992243_r0"
> log_akonadi_indexer_agent: indexed  126
> akonadiagentbase_log: 2837
> log_akonadi_indexer_agent: Processing collection:  126
> log_akonadi_indexer_agent:
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 1
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 2
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 3
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 4
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 5
> log_akonadi_indexer_agent: Indexed  5  items in (ms):  23
> log_akonadi_indexer_agent: Indexing complete. Total time:  25
> log_akonadi_indexer_agent: indexed  127
> log_akonadi_indexer_agent: Processing collection:  127
> log_akonadi_indexer_agent:
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 1
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 2
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 3
> log_akonadi_indexer_agent: Indexed  3  items in (ms):  13
> log_akonadi_indexer_agent: Indexing complete. Total time:  15
> log_akonadi_indexer_agent: Processing done
> 
> All those e-Mail-Subjects are new and not in my inbox. For at least half a
> dozen akonadi restarts I was only seeing them once.
> 
> So, different exchange server version, similar output and it looks like the
> new mails are indexed. But I am getting only around one INBOX update a day.
> All other accounts are working flawlessly.
> 
> What can I do to help?
> 
> All the best,
> 
> Jan

Jan, 

This sounds like you may want to open another bug report. To keep this one clean, it would probably be best to keep it to people whose IMAP folders are not getting updated at all. 

On another note, has anyone from the kmail team seen/commented on this bug? There seem to be a lot people willing to help diagnose the problem, but very few suggestions at this point. As Orion noted, this is a showstopper and I have completely stopped using kmail because it is useless to me under plasma. I wonder if there's a better way to get the devs' attention?
Comment 16 jat255 2015-10-02 12:43:40 UTC
(In reply to Jan-Matthias Braun from comment #7)
> Hi!
> 
> I am using kde-apps 15.08.1 version of kmail and I am having problems with
> an Exchange 2010 system, afaik. Nonetheless the symptoms are similar.
> Sometimes I am getting my INBOX updated, but most of the day not. I cannot
> even reproduce the update reliably. Stopping akonadi and restarting kmail
> won't work.
> 
> I too am seeing this endless sequence in my imap-log:
> ...
> S: * SEARCH
> S: A032761 OK SEARCH completed.
> C: A032762 UID SEARCH UID 65508001:65510000
> S: * SEARCH
> S: A032762 OK SEARCH completed.
> C: A032763 UID SEARCH UID 65510001:65512000
> ... and so on and on.
> 
> In my .xsession-errors I got the impression, that it actually gets the new
> mails and feeds them to the indexer:
> Wrote 19189 bytes to  ".../.local/share/akonadi/file_db_data/992243_r0"
> log_akonadi_indexer_agent: indexed  126
> akonadiagentbase_log: 2837
> log_akonadi_indexer_agent: Processing collection:  126
> log_akonadi_indexer_agent:
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 1
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 2
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 3
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 4
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 5
> log_akonadi_indexer_agent: Indexed  5  items in (ms):  23
> log_akonadi_indexer_agent: Indexing complete. Total time:  25
> log_akonadi_indexer_agent: indexed  127
> log_akonadi_indexer_agent: Processing collection:  127
> log_akonadi_indexer_agent:
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 1
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 2
> log_akonadi_indexer_agent: Indexing Valid new e-Mail 3
> log_akonadi_indexer_agent: Indexed  3  items in (ms):  13
> log_akonadi_indexer_agent: Indexing complete. Total time:  15
> log_akonadi_indexer_agent: Processing done
> 
> All those e-Mail-Subjects are new and not in my inbox. For at least half a
> dozen akonadi restarts I was only seeing them once.
> 
> So, different exchange server version, similar output and it looks like the
> new mails are indexed. But I am getting only around one INBOX update a day.
> All other accounts are working flawlessly.
> 
> What can I do to help?
> 
> All the best,
> 
> Jan

Jan, 

This sounds like you may want to open another bug report. To keep this one clean, it would probably be best to keep it to people whose IMAP folders are not getting updated at all. 

On another note, has anyone from the kmail team seen/commented on this bug? There seem to be a lot people willing to help diagnose the problem, but very few suggestions at this point. As Orion noted, this is a showstopper and I have completely stopped using kmail because it is useless to me under plasma. I wonder if there's a better way to get the devs' attention?
Comment 17 Jan-Matthias Braun 2015-10-03 09:31:50 UTC
Hi!

(In reply to jat255 from comment #16)
> (In reply to Jan-Matthias Braun from comment #7)
[...]
> This sounds like you may want to open another bug report. To keep this one
> clean, it would probably be best to keep it to people whose IMAP folders are
> not getting updated at all. 

Actually, I am not convinced that these are two distinct behaviours. For the first, the imap-logs seem to be the same as in the original report, i.e., I would suspect a higher load of the corresponding resource for all these cases, at least it seems to be logging activity all the time. For the second---as an update, my INBOX right now hasn't been updated since 23rd of September, the resource being online and working all the while. This makes every update a stochastic event at best and the time lag has jumped from almost daily over after three days to not in all since 23rd of September. In other words, there is no reliable working component, but the symptoms seem similar, which makes it seem that I sometimes get lucky for small folders with 1-3 (!) e-Mails in them.

> On another note, has anyone from the kmail team seen/commented on this bug?
> There seem to be a lot people willing to help diagnose the problem, but very
> few suggestions at this point. As Orion noted, this is a showstopper and I
> have completely stopped using kmail because it is useless to me under
> plasma. I wonder if there's a better way to get the devs' attention?

Probably irc? I don't know and won't have time to check for a little longer.

All the best and good luck,

Jan
Comment 18 Luis Silva 2015-10-03 09:46:33 UTC
I can confirm the problem. However, to me it all started when my email provider upgraded to Outlook365. Outlook has never been standard imap so that might be the root cause of the problem.
Comment 19 Daniel Vrátil 2015-10-03 12:12:56 UTC
Hi,

from the IMAP log it appears that Outlook365 has broken IMAP support (no surprise there), and the SEARCH query returns no results, thus the resource thinks there's nothing to sync.

I should still have access to Outlook365 from my old highschool account, so I'll see if I can remember the password and reproduce it.
Comment 20 Daniel Vrátil 2015-10-03 12:46:04 UTC
commit 813e4dfdcf30bed34397fa578d0d1ae0e61ea625
Author: Dan Vrátil <dvratil@redhat.com>
Date:   Sat Oct 3 14:37:34 2015 +0200

    IMAP: use UIDNEXT instead of "*" as interval end when doing full mailbox resync
    
    The opened interval is represented as -1, so when syncing with Microsoft
    Exchange the qMin() comparision in the search-in-chunks workaround for
    Exchange evaluates as qMin(X, 2^32-1), causing the BatcherFetcher to get
    to a loop trying to SEARCH all chunks between 1 and 2^32-1. In practice
    Exchange will drop connection at some point, so the folder sync is aborted
    and no emails are ever synced.
    
    With this patch we limit the interval end to reported UIDNEXT, so that the
    SEARCH loop is finished when we reach the interval with UIDNEXT.
Comment 21 Daniel Vrátil 2015-10-03 12:48:07 UTC
Turned out their SEARCH actually returns valid results but the bug was in our workaround code for MS Exchange SEARCH limitations, which caused an endless loop :)
Comment 22 Jan-Matthias Braun 2015-10-03 14:06:51 UTC
Whatever---it works!

Thank you very much Daniel!

All the best,

Jan
Comment 23 Orion 2015-10-03 14:20:27 UTC
(In reply to Daniel Vrátil from comment #20)
> commit 813e4dfdcf30bed34397fa578d0d1ae0e61ea625
> Author: Dan Vrátil <dvratil@redhat.com>
> Date:   Sat Oct 3 14:37:34 2015 +0200
> 
>     IMAP: use UIDNEXT instead of "*" as interval end when doing full mailbox
> resync
>     
>     The opened interval is represented as -1, so when syncing with Microsoft
>     Exchange the qMin() comparision in the search-in-chunks workaround for
>     Exchange evaluates as qMin(X, 2^32-1), causing the BatcherFetcher to get
>     to a loop trying to SEARCH all chunks between 1 and 2^32-1. In practice
>     Exchange will drop connection at some point, so the folder sync is
> aborted
>     and no emails are ever synced.
>     
>     With this patch we limit the interval end to reported UIDNEXT, so that
> the
>     SEARCH loop is finished when we reach the interval with UIDNEXT.

Great you found the problem! What still baffles me is how it occurred from the "kde4" version of KMail to the 4.81 beta "plasma 5" version. When do we see the patch being distributed?
Comment 24 Daniel Vrátil 2015-10-03 14:48:36 UTC
The Exchange workaround code was introduced in http://commits.kde.org/kdepim-runtime/94b64eebb6a88846b221aad810045fecb4173f79, which was in KDE 4.14.3 release a year ago. PIM is part of KDE Applications release cycle, nothing to do with Plasma.

The patch will be included in KDE Applications 15.08.2 release, which is due on October 13, so depending on your distribution it should get to you in around 2 weeks .
Comment 25 Luca Beltrame 2015-10-08 18:53:50 UTC
*** Bug 353691 has been marked as a duplicate of this bug. ***
Comment 26 wodenhof 2015-11-29 17:56:35 UTC
I use 15.08.3 on openSUSE Leap 42.1. The bug is still there.
Comment 27 Jan-Matthias Braun 2016-02-21 19:12:37 UTC
Hi! I do have the impression that this issue came back with 15.12.: My outlook imap is not syncing anymore. 

Does somebody else see the same behaviour? Can the fix somehow have evaded going into 15.12 or should I open a new bug report?

All the best,

Jan
Comment 28 Jan-Matthias Braun 2016-02-22 08:23:27 UTC
Okay, I think I have answered my own question: It is there and therefore I should better open a new but.

Please excuse the noise... :-/