Bug 352574

Summary: When recent documents is on, plasmashell freezes and consumes 100% CPU
Product: [Frameworks and Libraries] frameworks-activities-stats Reporter: Jin Liu <m.liu.jin>
Component: generalAssignee: Ivan Čukić <ivan.cukic>
Status: RESOLVED FIXED    
Severity: grave CC: bhush94, mr.gugs, onestone, plasma-bugs, plusfabi, rdieter
Priority: NOR    
Version: unspecified   
Target Milestone: ---   
Platform: Arch Linux   
OS: Linux   
Latest Commit: Version Fixed In:
Sentry Crash Report:

Description Jin Liu 2015-09-11 15:58:23 UTC
When this happens, kactivitymanagerd consumes ~30% CPU.

dbus-monitor shows plasmashell keeps making the following call very rapidly:

method call time=1441981023.852013 sender=:1.283 -> destination=org.kde.ActivityManager serial=76173 path=/ActivityManager/Resources/Scoring; interface=org.kde.ActivityManager.ResourcesScoring; member=DeleteStatsForResource
   string ":current"
   string ":any"
   string "/home/jin/documents/test.mp4"
signal time=1441981023.852065 sender=:1.285 -> destination=(null destination) serial=152001 path=/ActivityManager/Resources/Scoring; interface=org.kde.ActivityManager.ResourcesScoring; member=ResourceScoreDeleted
   string ":current"
   string ":any"
   string "/home/jin/documents/test.mp4"
method return time=1441981023.852093 sender=:1.285 -> destination=:1.283 serial=152002 reply_serial=76173
method call time=1441981023.856243 sender=:1.283 -> destination=org.kde.ActivityManager serial=76174 path=/ActivityManager/Resources/Scoring; interface=org.kde.ActivityManager.ResourcesScoring; member=DeleteStatsForResource
   string ":current"
   string ":any"
   string "/home/jin/documents/test.mp4"
signal time=1441981023.856791 sender=:1.285 -> destination=(null destination) serial=152003 path=/ActivityManager/Resources/Scoring; interface=org.kde.ActivityManager.ResourcesScoring; member=ResourceScoreDeleted
   string ":current"
   string ":any"
   string "/home/jin/documents/test.mp4"
method return time=1441981023.856828 sender=:1.285 -> destination=:1.283 serial=152004 reply_serial=76174

/home/jin/documents/test.mp4 is a file I recently opened, then deleted.

Turning recent documents off in systemsettings - desktop - activity - privacy immediately fixes this problem.

Reproducible: Sometimes
Comment 1 Ivan Čukić 2015-09-11 16:27:06 UTC
Did you request test.mp4 to be removed from the list before this happened?
Comment 2 Jin Liu 2015-09-11 16:53:12 UTC
(In reply to Ivan Čukić from comment #1)
> Did you request test.mp4 to be removed from the list before this happened?

No. I didn't touch recent documents at all.
Comment 3 Yavor Buyukliev 2015-09-12 00:41:31 UTC
My file in question was also video (.mkv) with few brackets in the filepath.
Disabling the recent documents in systemsettings didn't work for me. To "fix" it I had to kill plasmashell, issue "kactivitymanager stop", deleting 12 rows with that file from ~/.local/share/kactivitymanagerd/resources/database 
By the way, if the "resources" folder not exists, it is not auto-created at startup. 
At some point, i was able to work with the recent documents list (witch was full wit the same very filename) and clears it from the context menu. Now it is empty and not showing any new items. Presume i broke the database ;)
Comment 4 Jin Liu 2015-09-12 08:50:00 UTC
Incidentally my filename also contains brackets, square brackets, and Chinese/Japanese characters, which I deleted for privacy reasons in the original bug report (sorry for that).
In the code, the filename is used in a sqlite GLOB condition. Do square brackets have special meaning in GLOB? Then that may be the problem.
Comment 5 Ivan Čukić 2015-09-12 10:49:16 UTC
> which I deleted for privacy reasons

No problem, glad we are going somewhere with this issue. SQLite Glob is under-documented, but the brackets idea seems very plausible. Now, I'll have to see if and why it triggers the request-response loop.

Thank you all for being perfect bug reporters!
Comment 6 Ivan Čukić 2015-09-12 10:56:53 UTC
p.s. confirmed that sqlite glob is a problem I'll need to fix, definitely, but I'm not sure that it is connected to this issue.
Comment 7 Peter Petrov 2015-09-12 12:06:43 UTC
Just want to confirm experiencing the same bug. My "plasmashell" process was very often consuming an entire CPU core in the last couple of weeks, but it didn't occur to me to monitor DBUS events. Now that I did, I see it was the same issue Jin Liu reported. In my case it was a .jpg file whose filename contained square brackets ([]) and regular brackets. Clearing the recent files immediately fixes the problem.
Comment 8 Jin Liu 2015-09-12 15:03:16 UTC
My speculation regarding the DeleteStatsForResource infinite loop, although I can't reliably reproduce it:

1. resultmodel.cpp:onResultRemoved called. (When?)
2. Which calls fetch(cache.size(), 1).
3. One record fetched from the database, whose name contains square brackets, and the file has been deleted.
4. fetch calls cache.replace(newItems, from), where newItems is the deleted file.
5. cache.replace checks that newItems exist at the end of the function. Since the file was deleted, it calls forgetResource.
6. Due to the glob bug, kactivitymanagerd doesn't really deleted the record from the sqlite db, but still return success to plasmashell.
7. onResultRemoved called again, infinite loop.
Comment 9 Ivan Čukić 2015-09-13 11:29:33 UTC
@Jin

Yes, seems to be source of the issue. The step 1 is probably induced by the file deletion.

Can you try the latest master of kactivities and the ivan/delete-stats-loop branch of plasma-desktop?
Comment 10 Jin Liu 2015-09-13 14:24:08 UTC
(In reply to Ivan Čukić from comment #9)
> @Jin
> 
> Yes, seems to be source of the issue. The step 1 is probably induced by the
> file deletion.
> 
> Can you try the latest master of kactivities and the ivan/delete-stats-loop
> branch of plasma-desktop?

My distro (arch) doesn't ship with a libsqlite3.a. Is it possible to build kactivitymanagerd with share lib?
(Tried to build anyway, but kactivitymanagerd wasn't reading the sqlite database at all.)
Comment 11 Ivan Čukić 2015-09-14 16:52:58 UTC
I took a bit dirty approach now - to skip linking directly to sqlite.

Can you test kactivities:ivan/star-pattern and plasma-desktop:ivan/delete-stats-loop?
Comment 12 Jin Liu 2015-09-15 04:34:50 UTC
(In reply to Ivan Čukić from comment #11)
> I took a bit dirty approach now - to skip linking directly to sqlite.
> 
> Can you test kactivities:ivan/star-pattern and
> plasma-desktop:ivan/delete-stats-loop?

Tested your change. Seems working.

Bug reproduction step:
1. clear recent documents.
2. create 15 files with name [1].txt ... [15].txt
3. open those files with kwrite, so they fill recent documents.
4. open kicker and delete the first item in recent documents.
With KF5.13 and Plasma5.4, this will cause plasmashell to hang.

How I installed your fix:
1. in both repo: cmake . && make install
2. plasmashell not linking with /usr/local/lib/libKF5ActivitiesExperimentalStats.so.0.0.1, so I changed the symlink in /usr/lib to point to there.
3. reboot
4. can't reproduce the bug anymore.

Thanks!
Comment 13 Ivan Čukić 2015-09-15 06:22:52 UTC
Great. Thanks for the help, I'll merge the changes in a few moments.
Comment 14 Ivan Čukić 2015-09-15 06:26:27 UTC
Git commit 5205d51e42fe9123b4c5c1a8b5b231ff63a067aa by Ivan Čukić.
Committed on 15/09/2015 at 06:24.
Pushed by ivan into branch 'master'.

Using a custom matching function instead of sqlite's glob.

We want to support only the asterisk (*) as the universal matcher.
We do not want brackets, question marks nor anything else.

M  +69   -0    src/common/database/Database.h
M  +2    -2    src/lib/stats/resultmodel.cpp
M  +9    -2    src/lib/stats/resultset.cpp
M  +1    -1    src/lib/stats/resultwatcher.cpp
M  +7    -5    src/service/plugins/sqlite/StatsPlugin.cpp

http://commits.kde.org/kactivities/5205d51e42fe9123b4c5c1a8b5b231ff63a067aa
Comment 15 Ivan Čukić 2015-10-13 14:02:05 UTC
*** Bug 353277 has been marked as a duplicate of this bug. ***
Comment 16 Yavor Buyukliev 2015-10-13 14:28:27 UTC
I know this is fixed. But just received mail about https://bugs.kde.org/show_bug.cgi?id=353277, which remembers me, that i have same the issue again last week. I "clear recent history" and turns on "Do not remember" because i don't use neither activities nor recent files for now.
But i just think - in both cases the torrent client are involved. Can it be related? I use qbittorrent.
Comment 17 Ivan Čukić 2015-10-13 14:41:35 UTC
@Yavor There should be no relation between the application that created the file and the issue. The issue was (hopefully in past tense :) ) that plasma and activity manager had different understanding of special characters like [](). Essentially, one component used sqlite understanding of special characters, and the other thought only * is special.

Torrent files might often trigger this because they usually contain brackets and are often deleted :)