Bug 1177719 - Intermittent "Empty cache file" errors for IMAP account
Summary: Intermittent "Empty cache file" errors for IMAP account
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: evolution
Version: 21
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
Assignee: Milan Crha
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-12-30 04:48 UTC by Christopher Beland
Modified: 2016-08-02 09:41 UTC (History)
7 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2015-12-02 06:38:24 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Christopher Beland 2014-12-30 04:48:32 UTC
In Evolution, I have my work email set up as an IMAP account on gmail.  After the upgrade from Fedora 20 to 21 via FedUp (which included removing /home/beland/.cache/) I started getting "Empty cache file" errors occasionally when receiving and reading mail.  This has never occurred before.  I just got this:

>>
Unable to retrieve message.

Empty cache file: /home/beland/.cache/evolution/mail/1384799843.1941.4/folders/INBOX/subfolders/git-auto/cur/02/8085
<<

Earlier I got one that said something about a 'Junk check' failure, which caused my incoming mail not to get filtered into subfolders automatically.

A search reveals a previous attempt at fixing a similar problem:
https://mail.gnome.org/archives/evolution-list/2014-August/msg00058.html
https://mail.gnome.org/archives/evolution-list/2014-August/msg00132.html
https://bugzilla.gnome.org/show_bug.cgi?id=731562

I hope this is not losing mail.

evolution-3.12.9-1.fc21.x86_64

Comment 1 Christopher Beland 2014-12-30 22:34:35 UTC
Since it happened again a few times, here's the exact text of that earlier error message:

Error while Filtering new message in 'INBOX'.
Execution of the filter 'Junk check' failed: Error fetching message: Shutting down

Comment 2 Christopher Beland 2015-01-05 16:39:31 UTC
Probably related, I'm also having trouble moving messages between IMAP folders.  Sometimes only the first message moves if I'm dragging and dropping several.  Sometimes it's fixed if I hit Send/Receive.  Sometimes I need to close Evolution and re-open and re-move.  This is nearly unusable for everyday email.

Comment 3 Milan Crha 2015-01-06 11:11:57 UTC
Thanks for a bug report. You are right this is meant to be fixed, especially in 3.12.9 of evolution/evolution-data-server. This is not losing messages, it is just a failure of a download attempt, which will cause the message to be downloaded again when selected (or requested). The 'Shutting down' error looks like some issue with the connection to the GMail server. I think the change between Fedora 20 (evolution 3.10.x) and Fedora 21 (evolution 3.12.x) is that the newer evolution uses concurrent connections. The count of concurrent connections can be limited in the mail account's Properties, at the Receiving Options tab. The default value is 3. Try to limit it to 1, just to see whether it'll help.

I noticed that some users are claiming unreliable connection into the GMail server. Did you ever notice any such thing before? My own connection to the GMail server works well.

Comment 4 Christopher Beland 2015-01-06 21:08:41 UTC
Thanks for the workaround; I set that up and will see how it goes.

With Fedora 20 I had trouble with Evolution not reconnecting with Gmail occasionally when entering a Wifi area after having been off the network, but I don't remember seeing that recently amid all the other problems.  I will keep an eye out for that sort of thing now, though.

Comment 5 Milan Crha 2015-01-07 10:23:44 UTC
The reconnect issue should be much better with 3.12.9 of evolution-data-server and evolution. There is also set a 90 seconds timeout for remote requests, thus they eventually give up after some time, when using an obsolete/dead connection.

Comment 6 Christopher Beland 2015-01-09 18:10:47 UTC
It does seem to be a lot better with a single connection.  I have found at least one piece of mail that didn't get filtered, but most days now I don't have any problems.

Comment 7 Fedora End Of Life 2015-11-04 14:17:58 UTC
This message is a reminder that Fedora 21 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 21. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '21'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 21 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 8 Fedora End Of Life 2015-12-02 06:38:27 UTC
Fedora 21 changed to end-of-life (EOL) status on 2015-12-01. Fedora 21 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 9 Beshoy 2015-12-23 15:08:50 UTC
I am experiencing this on Fedora 23 with the following installed:

evolution.x86_64                      3.18.3-1.fc23             @updates
evolution-data-server.x86_64          3.18.3-1.fc23             @updates
evolution-ews.x86_64                  3.18.3-1.fc23             @updates
evolution-help.noarch                 3.18.3-1.fc23             @updates

Comment 10 Milan Crha 2016-01-19 16:51:00 UTC
With the 3.18.3 release? That's surprising. Could you run evolution from a terminal like this:
  $ evolution &>log.txt
and try to reproduce the issue, please? And if you'll be able to do it, then check the log.txt for anything private (though there wouldn't be anything in it, neither passwords nor server, nor email, addresses) and then upload it here, please? I'll check whether evolution didn't claim anything what would explain it.

Comment 11 Beshoy 2016-01-20 08:12:00 UTC
Hello,

Unfortunately, it doesn't look like any useful information is provided:

[000:004] Using Gtk2 toolkit
No bp log location saved, using default.
[000:000] Cpu: 6.63.2, x12, 4000Mhz, 32101MB
[000:000] Computer model: Not available
Created new window in existing browser session.
Created new window in existing browser session.
Created new window in existing browser session.
Created new window in existing browser session.

** (evolution:12912): WARNING **: GDBus.Error:org.freedesktop.DBus.Error.NoReply: Message recipient disconnected from message bus without replying
Created new window in existing browser session.



I have other warnings like:
(evolution:12912): Gtk-WARNING **: Failed to register client: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.SessionManager was not provided by any .service files


but none of them occurred when the empty cache file error was given.

Comment 12 Milan Crha 2016-01-20 10:30:48 UTC
Thanks for the update. You are right, those two runtime warnings are unrelated. Could you try to run the evolution with the camel debugging, which will show the raw communication between the server and the client, please? Such log can contain private information, including your folder listing, content of messages and so on, thus, unless you'd try to sanitize it, you can also send it directly to me. Only name this bug report in the message subject, thus I'd not overlook it in my spam folder. The command for the log is:

   $ CAMEL_DEBUG=imapx:io,imapx:conman evolution &>log.txt

Once you reproduce the empty cache file error you can stop evolution. The log will be interesting only around that error, but I'm not sure whether it'll be shown in the log or not.

Comment 13 Beshoy 2016-01-21 09:16:46 UTC
Hey Milan,

I was able to capture a message where this occurred. The following starts with my clicking on the e-mail:

[imapx:A] Unmark connection 0x7fddf003b330 (server:0x7fdd74002170) busy after failure, error: Empty cache file: /home/beshoy/.cache/evolution/mail/1447278451.2539.36@storm/folders/INBOX/cur/20/8309
[imapx:A] I/O: 'A02317 UID STORE 124765 +FLAGS.SILENT (\DELETED)'
[imapx:A] I/O: '* 222 EXPUNGE
* 221 EXISTS
A02317 OK Success'
[imapx:A] I/O: 'DONE'
[imapx:A] I/O: 'A02319 NOOP'
[imapx:A] I/O: 'A02320 NOOP'
[imapx:A] I/O: 'A02321 NOOP'
[imapx:A] I/O: 'A02312 OK IDLE terminated (Success)'
[imapx:A] I/O: 'A02322 NOOP'
[imapx:A] I/O: 'A02319 OK Success'
[imapx:A] I/O: 'A02323 UID FETCH 48960:* (UID FLAGS)'
[imapx:A] I/O: 'A02321 OK Success'
[imapx:A] I/O: 'A02324 UID FETCH 8310:* (UID FLAGS)'
[imapx:A] I/O: 'A02322 OK Success'
[imapx:A] I/O: 'A02325 UID FETCH 4179:* (UID FLAGS)'
[imapx:A] I/O: 'A02320 OK Success'
[imapx:A] I/O: 'A02326 UID FETCH 124767:* (UID FLAGS)'
[imapx:A] I/O: '* 18 FETCH (UID 48959 MODSEQ (3663737) FLAGS (\Seen))'
[imapx:A] I/O: 'A02323 OK Success'
[imapx:A] I/O: 'A02327 UID FETCH 1:48960 (UID FLAGS)'
[imapx:A] I/O: '* 1 FETCH (UID 8309 MODSEQ (165612) FLAGS ())'
[imapx:A] I/O: 'A02324 OK Success'
[imapx:A] I/O: 'A02328 UID FETCH 1:8310 (UID FLAGS)'
[imapx:A] I/O: '* 4 FETCH (UID 4178 MODSEQ (529128) FLAGS (\Seen))'
[imapx:A] I/O: 'A02325 OK Success'
[imapx:A] I/O: 'A02329 UID FETCH 1:4179 (UID FLAGS)'
[imapx:A] I/O: '* 1 FETCH (UID 8309 MODSEQ (165612) FLAGS ())'
[imapx:A] I/O: 'A02328 OK Success'
[imapx:A] I/O: '* 1 FETCH (UID 28546 MODSEQ (2694879) FLAGS (\Seen))
* 2 FETCH (UID 43520 MODSEQ (3546556) FLAGS (\Flagged \Seen))
* 3 FETCH (UID 44028 MODSEQ (3489429) FLAGS (JUNK \Seen))
* 4 FETCH (UID 44044 MODSEQ (3492564) FLAGS (\Seen))
* 5 FETCH (UID 44493 MODSEQ (3529391) FLAGS (\Seen))
* 6 FETCH (UID 45096 MODSEQ (3522345) FLAGS (\Seen))
* 7 FETCH (UID 45152 MODSEQ (3558880) FLAGS (\Answered \Flagged \Seen))
* 8 FETCH (UID 48911 MODSEQ (3659291) FLAGS ($has_cal \Seen))
* 9 FETCH (UID 48934 MODSEQ (3661655) FL'
[imapx:A] I/O: 'AGS (\Seen))
* 10 FETCH (UID 48941 MODSEQ (3662867) FLAGS (\Seen))
* 11 FETCH (UID 48943 MODSEQ (3662437) FLAGS (\Seen))
* 12 FETCH (UID 48948 MODSEQ (3664032) FLAGS (\Seen))
* 13 FETCH (UID 48950 MODSEQ (3662914) FLAGS (\Seen))
* 14 FETCH (UID 48952 MODSEQ (3664041) FLAGS (\Seen))
* 15 FETCH (UID 48956 MODSEQ (3664035) FLAGS (\Seen))
* 16 FETCH (UID 48957 MODSEQ (3664038) FLAGS (\Seen))
* 17 FETCH (UID 48958 MODSEQ (3664704) FLAGS (\Seen))
* 18 FETCH (UID 48959 MODSEQ (3663737) FLAGS (\Seen))

Comment 14 Milan Crha 2016-01-21 10:55:34 UTC
Nice. I hope you still have the log. I'm more interested what is shown before this error, than after it, because it may explain why it failed.

Comment 15 Beshoy 2016-01-21 19:10:27 UTC
Hey Milan,

Unfortunately, nothing is before it that is relevant.
It looks as though if I try to open an e-mail as soon as it pops up in the list, I get that error.  It's not every time which I know isn't ideal for tracking down a bug).

It just happened to me again and the following is what's above it:

* 167 FETCH (UID 117196 MODSEQ (16574877) FLAGS (\Seen))
* 168 FETCH (UID 117383 MODSEQ (16630471) FLAGS (\Seen))
* 169 FETCH (UID 117405 MODSEQ'
[imapx:B] I/O: ' (16639011) FLAGS (\Seen))
* 170 FETCH (UID 117450 MODSEQ (16656369) FLAGS (\Seen))
* 171 FETCH (UID 117604 MODSEQ (16682285) FLAGS (\Seen))
* 172 FETCH (UID 117611 MODSEQ (16677118) FLAGS (\Answered \Seen))
* 173 FETCH (UID 117617 MODSEQ (16679223) FLAGS (\Seen))
* 174 FETCH (UID 117898 MODSEQ (16708972) FLAGS (\Seen))
* 175 FETCH (UID 118076 MODSEQ (16701215) FLAGS (\Seen))
* 176 FETCH (UID 118077 MODSEQ (16701179) FLAGS (\Seen))
* 177 FETCH (UID 118078 MODSEQ (16701209) FLAGS (\Seen))
* 178 FETCH (UID 118079 MODSEQ (16701173) FLAGS (\Seen))
* 179 FETCH (UID 118201 MODSEQ (16728391) FLAGS (\Seen))
* 180 FETCH (UID 118599 MODSEQ (17072426) FLAGS (\Answered \Seen))
* 181 FETCH (UID 118683 MODSEQ (16912062) FLAGS (\Seen))
* 182 FETCH (UID 119691 MODSEQ (17003482) FLAGS (\Seen))
* 183 FETCH (UID 120015 MODSEQ (17062853) FLAGS (\Seen))
* 184 FETCH (UID 120119 MODSEQ (17069149) FLAGS (\Seen))
* 185 FETCH (UID 120515 MODSEQ (17102437) FLAGS (\Seen))
* 186 FETCH (UID 120516 MODSEQ (17072587) FLAGS (\Seen))
* 187 FETCH (UID 120517 MODSEQ (17105240) FLAGS (\Seen))
* 188 FETCH (UID 120529 MODSEQ (17965220) FLAGS (\Flagged \Seen))
* 189 FETCH (UID 121306 MODSEQ (17287618) FLAGS (\Seen))
* 190 FETCH (UID 121340 MODSEQ (17311336) FLAGS (\Seen))
* 191 FETCH (UID 121341 MODSEQ (17303315) FLAGS (\Seen))
* 192 FETCH (UID 121353 MODSEQ (17310050) FLAGS (\Seen))'
[imapx:B] I/O: '
* 193 FETCH (UID 121491 MODSEQ (17956403) FLAGS (\Seen))
* 194 FETCH (UID 121562 MODSEQ (17379242) FLAGS (\Seen))
* 195 FETCH (UID 121564 MODSEQ (17376213) FLAGS (\Answered \Seen))
* 196 FETCH (UID 121614 MODSEQ (17390176) FLAGS (\Seen))
* 197 FETCH (UID 121625 MODSEQ (17392988) FLAGS (\Seen))
* 198 FETCH (UID 121868 MODSEQ (17457619) FLAGS (\Seen))
* 199 FETCH (UID 122576 MODSEQ (17956400) FLAGS (\Seen))
* 200 FETCH (UID 122577 MODSEQ (17554664) FLAGS (\Seen))'
[imapx:B] I/O: '* 201 FETCH (UID 122803 MODSEQ (17606231) FLAGS (\Seen))
* 202 FETCH (UID 123015 MODSEQ (17660466) FLAGS (\Seen))
* 203 FETCH (UID 123019 MODSEQ (17659575) FLAGS (\Seen))
* 204 FETCH (UID 123072 MODSEQ (17673760) FLAGS (\Seen))
* 205 FETCH (UID 123081 MODSEQ (17673754) FLAGS (\Seen))
* 206 FETCH (UID 123167 MODSEQ (17627423) FLAGS (\Seen))
* 207 FETCH (UID 123631 MODSEQ (17794408) FLAGS (\Seen))
* 208 FETCH (UID 124024 MODSEQ (17949511) FLAGS (\Seen))
* 209 FETCH (UID 124036 MODSEQ (17862780) FLAGS (\Seen))
* 210 FETCH (UID 124217 MODSEQ (17936803) FLAGS (\Seen))
* 211 FETCH (UID 124264 MODSEQ (17919602) FLAGS (\Seen))
* 212 FETCH (UID 124272 MODSEQ (17920784) FLAGS (\Seen))
* 213 FETCH (UID 124273 MODSEQ (17919593) FLAGS (\Seen))
* 214 FETCH (UID 124472 MODSEQ (17962019) FLAGS (\Seen))
* 215 FETCH (UID 124513 MODSEQ (17969611) FLAGS (\Seen))
* 216 FETCH (UID 124537 MODSEQ (17937966) FLAGS (\Seen))
* 217 FETCH (UID 124759 MODSEQ (17969941) FLAGS (JUNK \Seen))
* 218 FETCH (UID 124769 MODSEQ (17973455) FLAGS (\Seen))'
[imapx:B] I/O: 'B00553 OK Success'
[imapx:B] I/O: 'B00554 IDLE'
[imapx:C] I/O: 'C00555 IDLE'
[imapx:B] I/O: '+ idling'
[imapx:C] I/O: '+ idling'
[imapx:A] I/O: 'A00556 UID FETCH 49060 (BODY.PEEK[])'
[imapx:A] I/O: '* 12 EXISTS
A00556 OK Success'
[imapx:A] Unmark connection 0x7f44500276f0 (server:0x7f43dc0034a0) busy after failure, error: Empty cache file: /home/beshoy/.cache/evolution/mail/1447032579.2655.18@storm/folders/INBOX/cur/3a/49060

** the log sat at that line until I clicked on another e-mail.

Do you need more lines than this? I can send you an e-mail with more lines if you like.

Comment 16 Milan Crha 2016-01-22 10:09:33 UTC
Aha. Everything happens in the [imapx:A] connection. Interestingly everything is shown here:

> [imapx:A] I/O: 'A00556 UID FETCH 49060 (BODY.PEEK[])'
> [imapx:A] I/O: '* 12 EXISTS
> A00556 OK Success'
> [imapx:A] Unmark connection...

That is, the connection asked for the message with UID 49060 in some folder. The comment finished successfully, but didn't return any data. I noticed this behaviour on some servers when there was asked for a message which doesn't exist in that folder.

Please search the log for 49060, above this error. It'll show what was happening with it before the message download. Maybe even after the error (the UID can be folder or even server-side unique, it depends).

Could you try one thing, please? Run evolution with the logging to some file, then just use it as before. Once you get the error again, move to another message and then back. Will it cure it? What if you refresh the folder (right-click the folder name in the left folder tree and pick Refresh). It can take a little while, but after it's done, will the message be viewable or will it disappear?

Comment 17 jeremy9856 2016-08-02 09:41:26 UTC
This kind of problem is still happening

https://bugzilla.gnome.org/show_bug.cgi?id=769412


Note You need to log in before you can comment on or make changes to this bug.