Bug 331486 - creation of 1000s of 1byte files in inbox/new/ for "ghost" mails on start
Summary: creation of 1000s of 1byte files in inbox/new/ for "ghost" mails on start
Status: RESOLVED WORKSFORME
Alias: None
Product: Akonadi
Classification: Frameworks and Libraries
Component: Maildir Resource (show other bugs)
Version: GIT (master)
Platform: unspecified Linux
: NOR grave
Target Milestone: ---
Assignee: kdepim bugs
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-02-25 10:56 UTC by Aaron J. Seigo
Modified: 2015-09-11 12:37 UTC (History)
3 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Aaron J. Seigo 2014-02-25 10:56:22 UTC
If I forget to quit kontact and akonadi before logging out, it happens from time to time that akonadi apparently does not quit cleanly. Upon starting kontact after logging in for the first time after reboot, akonadi then reports anywhere from 5k-300k mails in the inbox that are unread.

Looking in .local/share/.local-mail.directory/inbox/new/ reveals that there are that many empty files (1 byte in size, which at least makes deleting them easy with `find`). Additionally, all unread emails that *actually* exist will be duplicated anywhere from 3-5 times to as many as a several hundred times.

The only way I have found to get the system back into order is to:

* stop akonadi
* manually delete all the 1 byte files in the inbox
* start akonadi
* open akonadiconsole (kontact will not do here, for whatever reason) and request a re-sync of the inbox folder

Sometimes I need to repeat the above a couple times, but eventually it notices that there are, indeed, missing items. What I see as debug output, both on startup and during re-sync:

Maildir::readEntry unable to find:  "1393320241.R898.freedom" 

There is one line generated for each email missing. I noticed that in kdepim-runtime/resources/maildir/maildirresource.cpp readEntry is called in two places without the return value being checked. It returns an empty QByteArray on failure. Putting in suitable return statements at those two places does not fix the issue, but then I start seeing this in addition to the above line:

ItemRetrieverException :  Unable to retrieve item from resource: <html>Invalid item retrieved</html>

This seams to be repeated twice for each "unable to find" line.

Eventually, this stops and then a few of these lines will appear:

Error during executing query "UPDATE PimItemTable SET atime = :0 WHERE ( ( PimItemTable.id = :1 ) )" :  "Lock wait timeout exceeded; try restarting transaction QMYSQL3: Unable to execute statement"
Unable to update item access time 
Error during executing query "UPDATE PimItemTable SET atime = :0 WHERE ( ( PimItemTable.id = :1 ) )" :  "Lock wait timeout exceeded; try restarting transaction QMYSQL3: Unable to execute statement"
Unable to update item access time 
Error during executing query "UPDATE PimItemTable SET atime = :0 WHERE ( ( PimItemTable.id = :1 ) )" :  "Lock wait timeout exceeded; try restarting transaction QMYSQL3: Unable to execute statement"
Unable to update item access time 

Eventually, akonadi continues and the mailfilter starts:

akonadi_mailfilter_agent(9522)/libkdepim Akonadi::PluginLoader::scan: registering Desktop file "/opt/kde4/share/apps/akonadi/plugins/serializer/akonadi_serializer_bookmark.desktop" for ("application/x-xbel") @ ("legacy", "default", "KBookmark")

(several more similar lines appear ..)

And then we're back to not finding items, only this time we are told:

AkonadiAgentServer(9520)/libakonadi Akonadi::ResourceBase::itemRetrieved: Item does not provide part "RFC822" 

Again, this appears to repeat once for every "ghost" email, and every so often one these lines will appear:

akonadiconsole(9666)/libakonadi Akonadi::EntityTreeModelPrivate::monitoredItemChanged: Got a stale notification for an item which was already removed. 1047667 "1393320340.R525.freedom"

After some minutes of churning, local mail filters are applied at an extremely slow pace and a huge amount of disk read/write activity between akonadi and the mysql database ensues. Slowly but surely each of the valid, but now massively duplicated, emails is filtered into their target folders as expected.

Depending on the amount of duplication, this can take anywhere from 10 minutes to half an hour to complete, during which time I have no access to my mail. This has been a persistent problem for the last 3-4 months of akonadi, updated from the git master branch (akonadi, kdepimlibs, kdepim-runtime and kdepim) every few weeks.

It is hard to put into words how disruptive this is to my daily workflow, and has become a deal-breaker in terms of being able to use kontact.

Reproducible: Always
Comment 1 Aaron J. Seigo 2014-02-25 11:47:07 UTC
"this can take anywhere from 10 minutes to half an hour to complete"

I should be a bit clearer on this point: this only covers the filtering once everything is sorted out. It easily takes an hour for the entire process from "broken" to "working" with disk churning for a significant portion of that.
Comment 2 Daniel Vrátil 2014-03-01 11:21:51 UTC
Hi,

can you please update to latest master (or 4.13) of kdepim, run Akonadi Console and enable "Notification Monitor" and "Job Tracker"? When this happens again, get dump from both tabs (there are new "Save to file..." buttons) and upload it here?
Comment 3 Kevin Krammer 2014-03-02 20:55:52 UTC
Since I just read "1-byte sized files" in another bug report update, might this be related?
https://bugs.kde.org/show_bug.cgi?id=319226
Comment 4 Martin Steigerwald 2014-03-02 22:51:52 UTC
Yeah, Kevin, might be related. Please note however that in my case Akonadi was actually loosing data. These mails were missing. On the POP3 server I found those mails intact. Aaron, do you miss any mails that should be there?
Comment 5 Martin Steigerwald 2014-04-06 11:33:41 UTC
Bug 330895 - copy mail folder to other folder on other ressource results in empty mails

might be related.
Comment 6 Martin Steigerwald 2015-04-12 10:19:02 UTC
Aaron, do you have anything new on this? Since András wrote in my report (bug #319226):

András Manţia 2013-11-17 11:18:04 UTC
This is tentatively fixed in master, after a little more testing I will backport to 4.12.

This issue may be gone if our two issues are related. I think I will summon up the courage to try it some time in the future. But if you have any new feedback, please share.

Thanks, Martin
Comment 7 Martin Steigerwald 2015-09-11 12:37:39 UTC
As I have not seen any new 1-byte sized files in local maildir since May 2013 and Aaron, you didn´t answer, I am closing this. Feel free to reopen it, if it still happens for you.