After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 786636 - Certain emails not shown in message list (downloaded but not indexed in folders.db)
Certain emails not shown in message list (downloaded but not indexed in folde...
Status: RESOLVED DUPLICATE of bug 786208
Product: evolution-ews
Classification: Other
Component: Mail
3.24.x
Other Linux
: Normal normal
: ---
Assigned To: Evolution EWS maintainer(s)
Evolution EWS maintainer(s)
: 790417 (view as bug list)
Depends on:
Blocks:
 
 
Reported: 2017-08-22 18:04 UTC by Maciej Mrozowski
Modified: 2017-11-24 08:16 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
evolution &> evo-log.txt, file was sent and missing in "Sent To" somewhere near the end (6.75 KB, application/gzip)
2017-08-28 20:22 UTC, Maciej Mrozowski
Details
evolution &> evo-log2.txt, start of Evo after reproducing the problem (just in case) (306 bytes, application/gzip)
2017-08-28 20:25 UTC, Maciej Mrozowski
Details

Description Maciej Mrozowski 2017-08-22 18:04:44 UTC
This is Evolution configured with EWS account (outlook.office365.com in my case)

Certain, just recently sent emails (at least only those I spotted) are not shown in "Sent items" folder. It just happened twice to me I believe, so not reliably reproducible. Happend when writing 1st reply to existing thread as well as nth reply (so this is not a factor here).

All those emails were actually successfully sent, emails are sent properly (verified with Oulook web client).

Those emails can be found in Evolution cache (somewhere in ~/.cache/evolution/mail/<accountid/folders/Sent Items/cur/) in case it mattered.

(my cache is over 13GiB, I wouldn't like to purge it for test purpose)

I don't know/think those emails are any special wrt formatting or in other means that would make them somehow discarded by message list UI. But yes, this surely is some "corpo-style" html top-posting, though I have hundreds of emails like this going through my inbox daily, many going out daily and I just noticed two cases in overall (and relatively recently, with evo-3.24.5 only I think) where just immediately sent emails never appeared in "Sent Items" in Evo.

This is:
evolution-ews-3.24.5-1.fc26.x86_64
evolution-3.24.5-1.fc26.x86_64

This bugs does not seem related to bug 597770. I found no workaround to get those emails shown.
Comment 1 Milan Crha 2017-08-24 07:34:05 UTC
Thanks for a bug report. Does the Web interface (owa) of the exchange server show those messages in the Sent Items, please? That might be one clue, to know whether it's stored on the server but not shown in evolution UI for some reason (like search filters in there?).

The Sent Items folder doesn't update immediately, but if you see the message in the local cache, then it is known, or at least had been known, there.

Could you run the below command from a terminal, please?

   $ ~/.cache/evolution/mail/<accountid>/folders.db \
     "select subject,flags,deleted,junk,uid from 'sent items' where subject like '%test%'"

It might be one long line and you replace the <accountid> with the account name and the "test" (quotes for clarity only) at the end with part of the subject to search for. The search is not case sensitive, at least here. The command will show all messages with certain subject in the folders.db file for the Sent Items folder with some additional information.
Comment 2 Maciej Mrozowski 2017-08-24 18:27:36 UTC
> Does the Web interface (owa) of the exchange server show those messages in the Sent Items, please?

Yes, they're there, properly threaded etc. In Inbox, message I replied to has "<-" icon indicating that message was replied to, as well, but I guess it's irrelevant to presence of message in "Sent Items".

I did make sure of course that no search filter is applied, selected "All Messages", tried toggling "Group by thread".

Your SQL query explains why it didn't help.
"Luckily" issue happened again just a while ago so it's fresh matter to check for me. I sent four messages with certain subject over a few days, three of them are visible in Evo, the most recently one, sent today is not. SQL query should return four rows but returns three.

[mrozowsk@cnu420dqzs 1459523689.7646.3@cnu420dqzs.intra.nokia.com]$ pwd
/home/mrozowsk/.cache/evolution/mail/1459523689.7646.3@cnu420dqzs.intra.nokia.com
[mrozowsk@cnu420dqzs 1459523689.7646.3@cnu420dqzs.intra.nokia.com]$ sqlite3 folders.db 
SQLite version 3.20.0 2017-08-01 13:24:15
Enter ".help" for usage hints.
sqlite> select subject,flags,deleted,junk,uid from 'sent items' where subject like '%mysubject%';
myfullsubject|16|0|0|AAMkADBiZjU5Nzk2LTg4MTUtNGUwZC05MjI3LWExOTk0MzMxOWQyNABGAAAAAABVX3r/l7DbR6jmpVWmB5X2BwBX0XQ11cwYQ79gX0DVfdJ4AAAAR4O/AADzg1PdX+n7QpP/KpyKUrMnAABm0UtjAAA=
myfullsubject|16|0|0|AAMkADBiZjU5Nzk2LTg4MTUtNGUwZC05MjI3LWExOTk0MzMxOWQyNABGAAAAAABVX3r/l7DbR6jmpVWmB5X2BwBX0XQ11cwYQ79gX0DVfdJ4AAAAR4O/AADzg1PdX+n7QpP/KpyKUrMnAABnLNNPAAA=
myfullsubject|16|0|0|AAMkADBiZjU5Nzk2LTg4MTUtNGUwZC05MjI3LWExOTk0MzMxOWQyNABGAAAAAABVX3r/l7DbR6jmpVWmB5X2BwBX0XQ11cwYQ79gX0DVfdJ4AAAAR4O/AADzg1PdX+n7QpP/KpyKUrMnAABnLNNQAAA=

Do I happen to get some collision on that uid perhaps? It did happen for first reply in thread before though (in case subject was used to generate this string somehow).
Comment 3 Milan Crha 2017-08-25 07:53:11 UTC
(In reply to Maciej Mrozowski from comment #2)
> Do I happen to get some collision on that uid perhaps?

I do not think so. Those IDs are fully generated by the server, thus the collision is unlikely. I suspect there happened some other kind of issue.

The evolution-ews refreshes folder content by asking the server for changes which happened since the last check. The server returns newly added, modified and removed IDs, which evolution-ews propagates to the summary. The message didn't make it in your case, still it seems like the internal state of the last check had been updated, even the complete refresh failed (it could be even cancelled by some action in UI of Evolution).

I would check the debugging logs of EWS, but I'm afraid this thing won't be shown there. I'll create a test build for you, which will print some interesting information when updating folder content, which will, hopefully, shed a light on it.
Comment 4 Milan Crha 2017-08-25 08:28:09 UTC
Here [1] is a test build (it'll be deleted within a week or so). Just download the main package and install it like this:

   $ sudo dnf update ./evolution-ews-3.24.5-1.1.fc26.x86_64.rpm

Then start evolution from a terminal, for example like this:

   $ evolution &>log.txt

The log.txt file will be populated with lines describing what changes had been received from the server and what evolution-ews did with them, eventually whether anything broke (ended with error). Watch for the 'Sent Items' folder there, especially after you'll notice that anything is missing. Thanks in advance.

[1] https://koji.fedoraproject.org/koji/taskinfo?taskID=21458407
Comment 5 Maciej Mrozowski 2017-08-25 15:19:42 UTC
Thanks. I'll give it a go and update the bug with log when I reproduce the problem.
Any env var (like on https://wiki.gnome.org/Apps/Evolution/Debugging) needs to be set? Also, if you know some suspicious file and line, I can perhaps set some trap in gdb and perhaps dump some local context or sth.
Comment 6 Milan Crha 2017-08-28 08:45:05 UTC
Nothing from the environment variables for now. You can enable EWS_DEBUG=2, if you want to, which would interleave with the debugging output from the test build, but the added debug output from the test build is currently the main thing I would like to start with.
Comment 7 Maciej Mrozowski 2017-08-28 20:22:20 UTC
Created attachment 358631 [details]
evolution &> evo-log.txt, file was sent and missing in "Sent To" somewhere near the end
Comment 8 Maciej Mrozowski 2017-08-28 20:25:35 UTC
Created attachment 358632 [details]
evolution &> evo-log2.txt, start of Evo after reproducing the problem (just in case)

I wonder what are those akonadi or chrome logs doing in 1st log file.. Some dbus leaking stuff across sessions? Strange. But perhaps unrelated and harmless.
Comment 9 Milan Crha 2017-08-29 08:26:03 UTC
Thanks for the update. I see that the first log has many refreshes of the Sent Items folder where the server didn't report any new or changed messages, but upper in the log there are logged recognized changes. If I understand it correctly, then it was not enough to stop evolution and run it again, when you entered the Sent Items folder it did not show the missing sent messages, right? I ask, because the second log also shows no new messages recognized in the Sent Items folder. From that it looks like the server didn't provide the messages. It's weird, but it's possible there's some "corner case" bug on the server, maybe with the old synchronization state being saved for the Sent Items folder.

Let's try to start the Sent Items folder from scratch, with a fresh synchronization token. I would like to backup the old synchronization state too, thus we have something to return to, if needed. Please do these steps:

a) move to the mail cache folder for the EWS account:
   $ cd ~/.cache/evolution/mail/<EWS-account-UID>/
b) backup current folder-tree file, that's with command:
   $ cp folder-tree folder-tree.bak
c) backup current sync state for the Sent Items folder:
   $ sqlite3 ./folders.db "select bdata from folders where \
     folder_name='Sent Items';" >backup-sent-items-sync-state
d) reset the sync state for the Sent Items folder:
   $ sqlite3 ./folders.db "update folders set bdata=null where \
     folder_name='Sent Items';"

You can do all the sqlite3 commands when the Evolution is running. After it enter the Sent Items folder, which will do a full update, thus you should see the missing messages now, without a need to drop everything in all folders. You can even compare the synchronization states before and after fresh update, with something like this:
   $ sqlite3 ./folders.db "select bdata from folders where \
     folder_name='Sent Items';" >new-sent-items-sync-state
   $ ls -l *sent-items-sync-state
   $ diff -u backup-sent-items-sync-state new-sent-items-sync-state

where the 'ls' command will show whether the size changed (it did for me, the new sync state is longer) and the diff is more for case when the size is the same, to see whether it truly changed.

Please see whether anything improved when using the fresh token.

Another thing I do not understand is that why only Sent Items folder is affected. I would expect to see similar issues elsewhere too, but it's not the case here. I know the Sent Items is a special folder, evolution-ews tells the Exchange server to copy the message there for it (which is, maybe, the reason to trigger the server bug), but otherwise I'd expect it behave the same as any other folder.

There is also bug #786208 which seems related, but it's for IMAP and evolution restart fixes the issue, thus it can be completely different thing (I think it is).
Comment 10 Maciej Mrozowski 2017-08-29 11:59:52 UTC
My Exchange mailbox size is over 13GiB, I wouldn't like to purge it for test purpose, I can set up separate user account and configure evolution there however and let you know the differences.

Also, just in case you missed it, I wrote earlier that those missing emails can be found in Evolution cache (somewhere in ~/.cache/evolution/mail/<accountid/folders/Sent Items/cur/). I grepped for some particular email contents and it's clearly there.
They are just not found in cache index (folders.db) and not shown in UI.
Are they put to cache the moment they are sent by Evo - or the moment they are received back from server (in Sent Items)?
Comment 11 Milan Crha 2017-08-29 14:01:20 UTC
(In reply to Maciej Mrozowski from comment #10)
> I wouldn't like to purge it for test purpose

Yes, that's why I suggested to change only the Sent Items. The steps from comment #9 do not change anything but the Sent Items folder.

> Also, just in case you missed it, I wrote earlier that those missing emails
> can be found in Evolution cache (somewhere in
> ~/.cache/evolution/mail/<accountid/folders/Sent Items/cur/). I grepped for
> some particular email contents and it's clearly there.
> They are just not found in cache index (folders.db) and not shown in UI.

Right, I noticed it, but I didn't pay much attention to it. It's weird to see it in the cache, but not in the folders.db summary file. The summary file dictates what the message list in the UI shows.

> Are they put to cache the moment they are sent by Evo - or the moment they
> are received back from server (in Sent Items)?

That's tricky. For EWS accounts configured to use Sent Items folder as its Sent folder (Defaults tab in account Properties) the message is just passed to the server and server takes care of the correct save of the message copy to that selected folder. Otherwise (Sent folder configured as not the one on the same EWS server) Evolution makes the copy on its own. You might have the first option, thus the message cannot get to the cache on the disk other than by being received from the server.

Could you try to run evolution with EWS debugging on, as you wanted initially, thus it'll show what had been loaded and what not, please? The thing is that such log will contain plenty of private information (with compare of the debug prints from the test build), the raw communication between evolution-ews and the server, thus it's not suitable to be attached here in public. Feel free to send me the log to my bugzilla email, only reference this bug report in the subject, thus I'd not overlook it in my spam folder. The command with logging is:

   $ EWS_DEBUG=2 evolution &>log.txt

Ideally also mention in the message body subject of the missing message, some clue what to look for in the log. Having filename of the corresponding mesage file on the disk would be also nice to have. Thanks in advance.
Comment 12 Milan Crha 2017-09-07 08:30:14 UTC
(In reply to Milan Crha from comment #9)
> There is also bug #786208 which seems related, but it's for IMAP and
> evolution restart fixes the issue, thus it can be completely different thing
> (I think it is).

Further updates in that bug #786208 showed that EWS can be also affected, which can mean they are the same issues. If you want, feel free to join the other bug. I may eventually close this as a duplicate of it, once we get to a state of some patch (the debug patch attached there is mainly for IMAP (the reason why it is for evolution-data-server), but it also touches a common part for any other provider, which can eventually help with EWS environment debugging too. You can also skip the EWS_DEBUG=2 run of evolution, though the debugging patch there still prints information on the console, thus running evolution from terminal is required to see the debugging information.
Comment 13 Maciej Mrozowski 2017-09-20 15:40:02 UTC
Thanks for the info.
Meanwhile. I noticed my Evo Inbox sync state is also slightly off with what OWA shows so it seems to be some universal syncing issue indeed.
I returned from holidays, went straight to OWA today, read/deleted some emails in Inbox from OWA, then started Evo (after clearing sync state for "Sent Items" using your SQL statement, unrelated here) - Evo shows different number of unread messages in Inbox than OWA. So just I case I purged whole email cache altogether. I'll monitor that other bug and see whether I can get anything useful from Evo debug log on my side when issue happens in "Send items" (though I don't think I'll be rebuilding Evo with path from that other bug).
Comment 14 Milan Crha 2017-09-21 07:46:00 UTC
Here's a test build with that semi-debug patch included:
https://koji.fedoraproject.org/koji/taskinfo?taskID=21998432

You download all the packages you've installed (rpm -qa | grep evolution-data), then run as root int he folder you've saved them:
    # dnf update ./evolution-data-server*.rpm
If anything goes wrong you can downgrade the packages back to the previous version, with something like:
    # dnf downgrade evolution-data-server*
Please note that the patch prints everything on stdout, thus on the console, which means you might run evolution from a terminal.
Comment 15 Maciej Mrozowski 2017-09-26 15:29:59 UTC
Thanks.
I renamed the subject. Rationale:
- issue is not specific to "Sent items" it seems
- emails are in fact downloaded as they are found in .cache/evolution/mail/<accountid>/folders/.../<someuuidorhash>

But.. they are missing in cache index (folders.db as I imagine), which I confirmed by running:
select * from "<folder>" where subject = '<subject>'.

Is there some env var to enable printing SQLite query errors? Perhaps some INSERTs fail due to unmet constraint checks or sth.
Comment 16 Maciej Mrozowski 2017-09-26 16:09:36 UTC
Notable difference from bug #786208 is that workaround mentioned there doesn't work here.

- restarting Evo (killing all its service processes just in case) does not solve the problem
- triggering cache "re-sync" for this folder by replying there (to missing email) also does not cause missing email to be re-downloaded and added to cache properly
- removing blob file (.cache/evolution/mail/<accountid>/folders/.../<someuuidorhash>) does not help either (in case it prevented index entry from being re-added)

What only helps is clearing sync state for the folder (setting bdata to null).
Blobs are only redownloaded when needed or they overwrite existing ones?
Comment 17 Milan Crha 2017-09-27 06:12:05 UTC
(In reply to Maciej Mrozowski from comment #16)
> Notable difference from bug #786208 is that workaround mentioned there
> doesn't work here.

Yes, it makes sense, because synchronization in EWS is different from IMAP. While IMAP checks local folder content against remote folder content, EWS uses the sync states to ask the server "what changed since my last check" and the server returns what had been added/changed/removed in the folder, and also a new sync state. When you issue Refresh, then EWS uses the new sync state, thus the server doesn't reclaim the changes related to the previous sync state.
Comment 18 Joakim Tjernlund 2017-09-27 07:22:09 UTC
This looks similar to what I see:

For quite some time now I have experienced loss of email in evolution-ews every 2-3 days.
This loss is per folder. It starts with E having problems marking mails as read or deleting
mail(they don't go away/sometimes just overstrucken). Then some new/all new mails to that folder
don't appear in E, I notice I have unread mail via other mail clients(Android/webmail).

Sometimes I can get back those mail by choosing Refresh on folder level but mostly
I need to restart E, then do a Refresh en each problematic folder to get my mail back.

It seems like E loses sync with the mail server and then cannot recover. The mail sever is
on the other side of the Atlantic with ping times 170-180 ms and quite busy.
Comment 19 Joakim Tjernlund 2017-09-27 07:23:48 UTC
Version 3.24.5
Comment 20 Milan Crha 2017-09-27 12:18:57 UTC
Please see bug #786208 comment #24, it contains a probable fix and also a link for a test build for Fedora 26. There is more information included there. Thanks in advance.
Comment 21 Joakim Tjernlund 2017-09-27 14:44:31 UTC
I applied the patch in (In reply to Milan Crha from comment #20)
> Please see bug #786208 comment #24, it contains a probable fix and also a
> link for a test build for Fedora 26. There is more information included
> there. Thanks in advance.

I applied this patch as is, my Inbox had completely jammed so I had to
resolve this to work at all.

BTW, why do I see this in evo:
pm_process() returned Yes
lp_servicenumber: couldn't find homes
could not obtain winbind domain name!
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Got 'YR' from squid (length: 2).
GENSEC backend 'gssapi_spnego' registered
GENSEC backend 'gssapi_krb5' registered
GENSEC backend 'gssapi_krb5_sasl' register

we don't use winbind, we use sssd. Why does E look for winbind?
Comment 22 David Woodhouse 2017-09-27 14:54:59 UTC
We use /usr/bin/ntlm_auth to attempt NTLM single-sign-on. Winbind supports that, but SSSD does not (there have been RFE bugs filed for a while).
Comment 23 Joakim Tjernlund 2017-09-27 15:00:05 UTC
(In reply to David Woodhouse from comment #22)
> We use /usr/bin/ntlm_auth to attempt NTLM single-sign-on. Winbind supports
> that, but SSSD does not (there have been RFE bugs filed for a while).

I see, is the 
 lp_servicenumber: couldn't find homes
also from missing winbind?
Comment 24 Milan Crha 2017-09-27 15:05:08 UTC
(In reply to Joakim Tjernlund from comment #21)
> I applied this patch as is, my Inbox had completely jammed so I had to
> resolve this to work at all.

Ehm, to avoid ambiguity, did your Inbox break before or after you applied the patch? If before, then fine, if after, then it's unexpected. What is expected is that EWS accounts won't recover on their own, as described in comment #17.
Comment 25 Joakim Tjernlund 2017-09-27 15:12:26 UTC
(In reply to Milan Crha from comment #24)
> (In reply to Joakim Tjernlund from comment #21)
> > I applied this patch as is, my Inbox had completely jammed so I had to
> > resolve this to work at all.
> 
> Ehm, to avoid ambiguity, did your Inbox break before or after you applied
> the patch? If before, then fine, if after, then it's unexpected. What is
> expected is that EWS accounts won't recover on their own, as described in
> comment #17.

It broke BEFORE, sorry for not being clear about that. I tried to
sync(refresh)/restart E several times to get my missing email back but that
didn't work(it has worked before).
After patch, evolution --force-shutdown, and a refresh I got the missing mails :)
Comment 26 Milan Crha 2017-09-27 15:20:55 UTC
(In reply to Joakim Tjernlund from comment #25)
> It broke BEFORE

Good, thanks. You might have evolution consistent now.
Comment 27 Joakim Tjernlund 2017-09-27 15:25:33 UTC
Yes, so far so good :)

Is there any chance E will recover lost mails just by rebooting 
Evo/machine with a this fix applied?
Comment 28 Milan Crha 2017-09-27 15:35:46 UTC
(In reply to Joakim Tjernlund from comment #27)
> Is there any chance E will recover lost mails just by rebooting 
> Evo/machine with a this fix applied?

In case of EWS? No, see comment #17. I may release evolution-ews with some fix (to be done) which will do it on its own. Something to invalidate stored sync state and update local summary with missing mails.
Comment 29 Milan Crha 2017-10-02 11:52:16 UTC
I made evolution-ews related changes to bug #786208 as part of that bug report, thus I'm closing this as a duplicate of it.

Just a note, those changes in evolution-ews are trying to be smart, which means they download newly discovered messages into the summary only, not whole folder content.

*** This bug has been marked as a duplicate of bug 786208 ***
Comment 30 Milan Crha 2017-11-24 08:16:10 UTC
*** Bug 790417 has been marked as a duplicate of this bug. ***