By default, Bugzilla does not search the list of RESOLVED bugs.
You can force it to do so by putting the upper-case word ALL in front of your search query, e.g.: ALL tdelibs
We recommend searching for bugs this way, as you may discover that your bug has already been resolved and fixed in a later release.
Bug 1992 - tdepowersave consuming almost 100% of CPU
Summary: tdepowersave consuming almost 100% of CPU
Status: RESOLVED FIXED
Alias: None
Product: TDE
Classification: Unclassified
Component: non-core programs (show other bugs)
Version: R14.0.0 [Trinity]
Hardware: Other Linux
: P5 blocker
Assignee: Francois Andriot
URL:
Depends on:
Blocks:
 
Reported: 2014-03-06 15:36 CST by David C. Rankin
Modified: 2014-05-19 18:52 CDT (History)
6 users (show)

See Also:
Compiler Version:
TDE Version String:
Application Version:
Application Name:

Attachments
tdelibs : reduce CPU eagerness when using tdepowersave (33.27 KB, patch)
2014-03-09 14:08 CDT, Francois Andriot 		Details | Diff
tdepowersave : use the "battery only" loop of tdehwlib, instead of "all stateless devices" loop (789 bytes, patch)
2014-03-09 14:09 CDT, Francois Andriot 		Details | Diff
tdelibs : reduce CPU eagerness when using tdepowersave (2) (33.24 KB, patch)
2014-03-10 17:02 CDT, Francois Andriot 		Details | Diff
Show Obsolete (3) View All Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description David C. Rankin 2014-03-06 15:36:40 CST 
After Soft-Freeze - tdepowersave consumes 100% CPU.

After login, tdepowersave initially uses 5-7% of CPU, but then steadily grows to consume nearly 100% of the CPU (see screenshot)

http://www.3111skyline.com/dl/dt/trinity/ss/tdeowersave-97percent.jpg

This process creates tens-of-thousands of repeating log errors in the system journal in a 24 hour period, with the messages repeating multiple-times-per-second:

Mar 06 13:31:28 valhalla dbus[176]: [system] Activating service name='org.trinitydesktop.hardwarecontrol' (using servicehelper)
Mar 06 13:31:28 valhalla org.trinitydesktop.hardwarecontrol[176]: [tde_dbus_hardwarecontrol] Listening...
Mar 06 13:31:28 valhalla dbus[176]: [system] Successfully activated service 'org.trinitydesktop.hardwarecontrol'
Mar 06 13:31:28 valhalla dbus[176]: [system] Rejected send message, 2 matched rules; type="method_call", sender=":1.37" (uid=1000 pid=674 comm="tdepowersave [tdeinit]                            ") interface="org.trinitydesktop.hardwarecontrol.InputEvents" member="GetProvidedSwitches" error name="(unset)" requested_reply="0" destination="org.trinitydesktop.hardwarecontrol" (uid=0 pid=12966 comm="/opt/trinity/bin/tde_dbus_hardwarecontrol ")
Mar 06 13:31:28 valhalla org.trinitydesktop.hardwarecontrol[176]: [tde_dbus_hardwarecontrol] Name request failed with error 'Rejected send message, 2 matched rules; type="method_call", sender=":1.37" (uid=1000 pid=674 comm="tdepowersave [tdeinit]                            ") interface="org.trinitydesktop.hardwarecontrol.InputEvents" member="GetProvidedSwitches" error name="(unset)" requested_reply="0" destination="org.trinitydesktop.hardwarecontrol" (uid=0 pid=12966 comm="/opt/trinity/bin/tde_dbus_hardwarecontrol ")'
Mar 06 13:31:28 valhalla org.trinitydesktop.hardwarecontrol[176]: [tde_dbus_hardwarecontrol] Not primary owner (-1), exiting!
Mar 06 13:31:28 valhalla dbus[176]: [system] Activated service 'org.trinitydesktop.hardwarecontrol' failed: Launch helper exited with unknown return code 1
Mar 06 13:31:28 valhalla dbus[176]: [system] Activating service name='org.trinitydesktop.hardwarecontrol' (using servicehelper)
Mar 06 13:31:28 valhalla org.trinitydesktop.hardwarecontrol[176]: [tde_dbus_hardwarecontrol] Listening...
Mar 06 13:31:28 valhalla dbus[176]: [system] Successfully activated service 'org.trinitydesktop.hardwarecontrol'
Mar 06 13:31:28 valhalla dbus[176]: [system] Rejected send message, 2 matched rules; type="method_call", sender=":1.37" (uid=1000 pid=674 comm="tdepowersave [tdeinit]                            ") interface="org.trinitydesktop.hardwarecontrol.InputEvents" member="GetActiveSwitches" error name="(unset)" requested_reply="0" destination="org.trinitydesktop.hardwarecontrol" (uid=0 pid=12968 comm="/opt/trinity/bin/tde_dbus_hardwarecontrol ")
Mar 06 13:31:28 valhalla org.trinitydesktop.hardwarecontrol[176]: [tde_dbus_hardwarecontrol] Name request failed with error 'Rejected send message, 2 matched rules; type="method_call", sender=":1.37" (uid=1000 pid=674 comm="tdepowersave [tdeinit]                            ") interface="org.trinitydesktop.hardwarecontrol.InputEvents" member="GetActiveSwitches" error name="(unset)" requested_reply="0" destination="org.trinitydesktop.hardwarecontrol" (uid=0 pid=12968 comm="/opt/trinity/bin/tde_dbus_hardwarecontrol ")'
Mar 06 13:31:28 valhalla org.trinitydesktop.hardwarecontrol[176]: [tde_dbus_hardwarecontrol] Not primary owner (-1), exiting!
Mar 06 13:31:28 valhalla dbus[176]: [system] Activated service 'org.trinitydesktop.hardwarecontrol' failed: Launch helper exited with unknown return code 1

The .xsession-error warning related to tdepowersave is:

tdepowersave: WARNING: The session is not registered with systemd 

(does it need it's own .service file?)

Attempting to attach the gdb debugger to tdepowersave gave the following information:

sudo gdb attach 674
...
0xb7795424 in __kernel_vsyscall ()
(gdb) continue

Interrupting tdepowesave in gdb output the following:

^C
Program received signal SIGINT, Interrupt.
0xb5ac1b1f in ?? () from /usr/lib/libdbus-1.so.3

I'm not sure where the problem is, but the CPU use will push a laptop close to its thermal limits with the CPU pegged at 100% continually.
Comment 1 David C. Rankin 2014-03-06 16:30:48 CST 
Here is where the tdepowersave generates all the error (TQEventLoop::activateTimers) :

TQTimerEvent (timerId=122, this=0xbf894650) at kernel/ntqevent.h:169
169     kernel/ntqevent.h: No such file or directory.
TQEventLoop::activateTimers (this=this@entry=0x98a9d38) at kernel/qeventloop_unix.cpp:564
564     kernel/qeventloop_unix.cpp: No such file or directory.
TQApplication::sendEvent (receiver=0x9977db0, event=event@entry=0xbf894650) at kernel/qapplication.cpp:2456
2456    kernel/qapplication.cpp: No such file or directory.
2457    in kernel/qapplication.cpp
TQEventLoop::activateTimers (this=this@entry=0x98a9d38) at kernel/qeventloop_unix.cpp:565
565     kernel/qeventloop_unix.cpp: No such file or directory.
Comment 2 Alex Couture 2014-03-07 14:44:06 CST 
Hi,

On my PCLinuxOS non-official TDE remaster, I used to set TDE Powersave to maximum CPU performance to avoid this problem, so I can confirm that the problem was present in 3.5.13.1 and in 3.5.13.2 too.

On an underpowered lappy such as my first-gen Asus EEE, the computer was almost unusable with the default setting.

-Alexandre
Comment 3 Francois Andriot 2014-03-09 14:08:28 CDT 
Created attachment 1999 [details]
tdelibs : reduce CPU eagerness when using tdepowersave

Hello, I've investigated the "tdepowersave constantly uses 5% CPU" issue.

I've found out that it is due to having 2 hardware polling loops running inside the TDE HW library:
- A loop running every 500ms for polling CPU informations
- A loop running every 1000ms for polling other "stateless" devices information

I've found out that, by default, each loops are equally wasting ressources (e.g. each loops causes ~2.5% constant cpu usage). So, both of them have to be fixed.

The general problem is that the code contains several loops (e.g. loop through each CPU core) which in turn contain several CPU or I/O consuming functions.
Example: I have 6 core hyperthread CPU (so 12 logical cores). For each core, we need to read about 10 files in SYSFS. As a result, the CPU polling loop opens, reads, and closes 12*10 = 120 files on my computer every 500ms !!!


The attached patches changes the following:

About CPU polling loop:
- Replaces the "readLine()" methods with "read()" methods, which are much faster (especially for parsing /proc/cpuinfo which was really slow).
- Add missing "else" statements, to avoid having useless string comparison in loops.
- Add a "cpu device cache" dictionnary, which avoids the slow parsing of all devices at every loop iteration (avoid calling "findBySystemPath()" which is slow)
- Consider that most power related features (cpu available governors, min/max frequency ...) are the same on all CPUs, to avoid scanning these values on each CPU; now we only scan the first CPU and apply the features to all others.

Now the CPU loop is about 10 (ten !) times faster than it originally was !


About the StateLess device loop:
The problem is that it causes rescan of almost ALL devices in the computer; we are only interested in batteries here, so this is a lot of useless stuff ...
I've implemented a 3rd loop, which is dedicated to polling batteries only, every 5 seconds.
In order to use this, we need to patch tdepowersave as well. 

I've also left (but disabled) the small profiling code I've used to find where the CPU time was wasted.
Comment 4 Francois Andriot 2014-03-09 14:09:27 CDT 
Created attachment 2000 [details]
tdepowersave : use the "battery only" loop of tdehwlib, instead of "all stateless devices" loop
Comment 5 Francois Andriot 2014-03-10 17:02:36 CDT 
Created attachment 2003 [details]
tdelibs : reduce CPU eagerness when using tdepowersave (2)

Small bugfix on tdelibs patch.
Comment 6 Timothy Pearson 2014-05-07 01:18:30 CDT 
Comment on attachment 1999 [details]
tdelibs : reduce CPU eagerness when using tdepowersave

Attachment 1999 [details] pushed to GIT in hash 3c9d481.
Comment 7 Timothy Pearson 2014-05-07 01:22:38 CDT 
Comment on attachment 2003 [details]
tdelibs : reduce CPU eagerness when using tdepowersave (2)

Sorry, I didn't realize that Attachment 2003 [details] superseded Attachment 1999 [details].  Fixed in GIT hash 1afbea2.
Comment 8 Timothy Pearson 2014-05-07 01:48:35 CDT 
Comment on attachment 2000 [details]
tdepowersave : use the "battery only" loop of tdehwlib, instead of "all stateless devices" loop

Attachment 2000 [details] Pushed to GIT in hash f43aac0.
Comment 9 Timothy Pearson 2014-05-07 01:50:30 CDT 
All patches have been pushed to GIT.  Please test and mark RESOLVED FIXED if the problem has been fixed.

Thanks for reporting, and thanks to Francois for the patches and the tdehwlib performance improvements!
Comment 10 Timothy Pearson 2014-05-10 01:22:56 CDT 
I'm still seeing tdepowersave eating 100% CPU after many hours of running on Ubuntu Maverick; changing status back to NEW.
Comment 11 Slávek Banko 2014-05-10 19:36:00 CDT 
(In reply to Timothy Pearson from comment #10)
> I'm still seeing tdepowersave eating 100% CPU after many hours of running on
> Ubuntu Maverick; changing status back to NEW.

This test was carried out with or without a commit f43aac0e? Patches from bug 2052 in any case reduce the number and frequency of dbus calls. I'm waiting for comments and testing :)
Comment 12 Timothy Pearson 2014-05-19 18:52:44 CDT 
It looks like the fix for Bug 2052 also fixed the high CPU usage on my laptop.  Marking as RESOLVED FIXED since I seem to have been the only one with a residual problem.

Thanks all for the patches!