Bug 335442 - Analogue clock causes high cpu load
Summary: Analogue clock causes high cpu load
Status: RESOLVED FIXED
Alias: None
Product: plasmashell
Classification: Plasma
Component: Analog Clock widget (other bugs)
Version First Reported In: master
Platform: Exherbo Linux
: NOR normal
Target Milestone: 1.0
Assignee: Sebastian Kügler
URL:
Keywords:
: 337526 (view as bug list)
Depends on:
Blocks:
 
Reported: 2014-05-27 22:06 UTC by Bernd Steinhauser
Modified: 2014-12-12 12:19 UTC (History)
8 users (show)

See Also:
Latest Commit:
Version Fixed/Implemented In:
Sentry Crash Report:


Attachments
screenshot of sysprof (196.20 KB, image/png)
2014-05-27 22:09 UTC, Bernd Steinhauser
Details
Log Output of sysprof (146.18 KB, application/x-xz)
2014-05-28 19:09 UTC, Bernd Steinhauser
Details
QMLProfiler of analog clock (124.09 KB, image/png)
2014-07-18 15:45 UTC, David Edmundson
Details
radeontop with clock (4.63 KB, text/plain)
2014-07-26 10:44 UTC, João Bóia
Details
radeontop without clock (2.99 KB, text/plain)
2014-07-26 10:44 UTC, João Bóia
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Bernd Steinhauser 2014-05-27 22:06:38 UTC
Since maybe a bit more than one week, plasmashell started to eat up a lot of cpu cycles over here. This starts right after the start of the shell with approx 20% cpu time (for one core) and gets worse until it eventually takes one core completely (after half an hour or so).
Restarting plasmashell will start at the lower cpu load again.
The problem was not present with some previous revision, but I didn't find the time yet to try to bisect.

So the question remains what plasmashell is doing in all those cpu cycles.
On IRC, I was advised to try to profile the issue with sysprof, you can find the resulting profile attached.
It looks like most time is spend with sys_recvmsg. Now I'm not sure about the further interpretation, but to me it looks like, it spents quite some time locking, unlocking files, maybe related to some unix socket.
On IRC, there was at least one person who had the same issue.

I didn't see and symptoms that could be easily related to this (i.e. missing functionality). Also, there aren't any repetitive error messages that could point to the issue.

Advises how to further debug the issue are welcome. ;)

Reproducible: Always

Steps to Reproduce:
1. Start plasmashell
2. Watch cpu usage rise over time (~1/2h)
Comment 1 Bernd Steinhauser 2014-05-27 22:09:29 UTC
Created attachment 86870 [details]
screenshot of sysprof
Comment 2 David Edmundson 2014-05-28 05:57:25 UTC
Make sure kded5 is running.

There's a known bug in which if kded5 isn't running it constantly rebuilds the .desktop file index.

If that's not the reason can you upload your original sysprof log?
Comment 3 Bernd Steinhauser 2014-05-28 19:08:15 UTC
(In reply to comment #2)
> Make sure kded5 is running.
It's running.
> 
> If that's not the reason can you upload your original sysprof log?
Nope, didn't save it.

But I made another one. ;-)
Comment 4 Bernd Steinhauser 2014-05-28 19:09:07 UTC
Created attachment 86884 [details]
Log Output of sysprof
Comment 5 David Edmundson 2014-05-28 19:12:35 UTC
Got info, reopening.
Comment 6 Bernd Steinhauser 2014-05-30 08:25:14 UTC
Ok, good news is, that I found the trigger for this.

I had—for testing purposes (-> Time zone bug)—an analogue clock in my panel and that resulted in a significant load increase.
When I remove the clock, the load drops instantly (approx. 4-5 minutes cpu time in 8 hours). I can observe the same by adding a clock to the desktop (which only works in folder mode). It doesn't matter if the clock shows the seconds or the time zone, the outcome is the same.
The digital clock seems to be ok.

Output when adding the clock:
Arrived mimeData () ("text/x-plasmoidservicename", "text/plain") at 1875 ,  14
adding "org.kde.plasma.analogclock"
DIALOG:  hiding dialog.
file:///usr/share/plasma/shells/org.kde.plasma.desktop/contents/views/Desktop.qml:90: TypeError: Cannot read property 'preventWindowHide' of null

And on removing it:
QObject::disconnect: No such slot QObject::dataUpdated(QString,Plasma::DataEngine::Data)
QObject::disconnect:  (receiver name: 'DataSource')
QObject::disconnect: No such slot QObject::modelChanged(QString,QAbstractItemModel*)
QObject::disconnect:  (sender name:   'Local')
QObject::disconnect:  (receiver name: 'DataSource')
Comment 7 Marco Martin 2014-06-03 09:19:35 UTC
hmm, 4-5 minutes in 8 hours is relevant but not huge..
may be in size with the rotation animation it's doing when the time changes?

iirc also scenegraph is documented to be less efficient, more opengl context switches when there is some item rotated at an angle not a multiple of 90 degrees
(that's the case of the clock hands)
Comment 8 Bernd Steinhauser 2014-06-03 15:28:25 UTC
(In reply to comment #7)
> hmm, 4-5 minutes in 8 hours is relevant but not huge..
Just to make sure you understand that correctly:
Without the analogue clock: 4-5 min cpu time/8h
With the analogue clock: ~ 2-3h cpu time/8h
Comment 9 Bhushan Shah 2014-07-17 12:27:10 UTC
*** Bug 337526 has been marked as a duplicate of this bug. ***
Comment 10 David Edmundson 2014-07-18 15:42:08 UTC
I put this through qmlprofiler. There is only one binding changing every second (as you'd expect). 

But the painting is a bit funny; it's practically /always/ painting.
The SpringAnimation inherits a duration 250ms; so it /shouldn't/ be that, but it's possible it ignores that and keeps animating until the object is completely at rest. I'll have a play.

See attached screenshot.
Comment 11 David Edmundson 2014-07-18 15:45:18 UTC
Created attachment 87800 [details]
QMLProfiler of analog clock

Green blocks at top show painting.
2 Purple lines near bottom are ticks from the clock.
Comment 12 David Edmundson 2014-07-19 10:28:53 UTC
Git commit 268910eb4abf974adfd1f9e9bc0fda7fc866c6d7 by David Edmundson.
Committed on 18/07/2014 at 16:02.
Pushed by davidedmundson into branch 'Plasma/5.0'.

Replace SpringAnimation with NumberAnimation with EaseOutIn

SpringAnimation ignores duration property and will keep animating until
the item has stopped springing; this takes a long time >= 1s just with
the movements getting smaller.

This means the analog clock is constantly repainting the entire desktop
causing high load.

This now restricts it to 200ms, so it's 5x less load.

REVIEW: 119357

M  +8    -2    applets/analog-clock/contents/ui/Hand.qml

http://commits.kde.org/plasma-workspace/268910eb4abf974adfd1f9e9bc0fda7fc866c6d7
Comment 13 David Edmundson 2014-07-19 10:30:31 UTC
Bernd can you confirm if this fixes it for you.
Comment 14 Bernd Steinhauser 2014-07-20 05:46:11 UTC
(In reply to David Edmundson from comment #13)
> Bernd can you confirm if this fixes it for you.

Unfortunately, no. I just updated to current head (953d6b), restarted plasmashell (should be enough, right?) and let it run with an analogue clock on the desktop for a couple of hours (approx. 8h).
In that time, it used up 2h of cpu time, in the end the load was at 50%. Removing the clock after that time instantly resulted in a big drop in the cpu load.

Sorry to disappoint you. :(
Comment 15 Bernd Steinhauser 2014-07-25 20:12:42 UTC
Forgot to reopen.

I'm not 100% sure, it might have improved to some degree, but the issue is still there. Having the analogue clock on your panel/desktop will result in a significant increase in cpu load, which gets worse over time.

I.e. with my cpu, the normal plasmashell load is somewhere below 2.5%. Adding the clock results in an increase to 10-20%, after a couple of hours, it's at 50%.
Comment 16 João Bóia 2014-07-26 10:43:18 UTC
In addition to CPU time, it also increases the workload on GPU significantly.
Comment 17 João Bóia 2014-07-26 10:44:01 UTC
Created attachment 87958 [details]
radeontop with clock
Comment 18 João Bóia 2014-07-26 10:44:24 UTC
Created attachment 87959 [details]
radeontop without clock
Comment 19 Marco Martin 2014-10-08 12:41:49 UTC
is this still valid?
Comment 20 Bhushan Shah 2014-10-09 05:17:44 UTC
At least for me this is fixed but for extra performance one could try to port it to RotationAnimator from RotationAnimation
Comment 21 Sebastian Kügler 2014-10-09 13:17:31 UTC
Marked as fixed then, if it persists, still, please reopen yet again.
Comment 22 Bernd Steinhauser 2014-10-09 17:32:03 UTC
I let it run for approx. 10h on Plasma 5.0.95.

Afaics, it didn't increase the cpu load significantly (which was different before), so it indeed seems to be fixed.
Comment 23 David Edmundson 2014-12-12 12:19:57 UTC
Git commit 7033e71812c8d04dc33c629e1e504d7b37a305ad by David Edmundson.
Committed on 11/12/2014 at 20:27.
Pushed by davidedmundson into branch 'master'.

cache QTimeZone for the lifespan of the TimeSource don't recreate every minute

QTimeZone::systemTimeZoneId() will open /etc/localtime every single time it is called.

We are calling this in ::updateTime which happens every single minute, potentially
every second.

REVIEW: 121453

M  +12   -14   dataengines/time/timesource.cpp
M  +2    -0    dataengines/time/timesource.h

http://commits.kde.org/plasma-workspace/7033e71812c8d04dc33c629e1e504d7b37a305ad