great CPU temperature increase from 5.2 to 5.5 ... and when using intel_pstate
From: Christoph Anton Mitterer
Date: Mon Apr 06 2020 - 20:10:25 EST
Hey.
For several months now, I've been chasing a tremendous heat increase
(CPU/GPU) respectively power usage on my notebook.
It basically started after upgrading from 5.2 to 5.3, at least I
haven't explicitly noted any grave changes from before 5.2 to 5.2.
The issue (actually there might be several) persists until at least 5.4
and 5.5.
Things are so bad, that when just type this mail,... that I can hear
the fan go up considerably (and temps up to 90ÂC) just by typing the
mail in the mail client (while it goes back to - still insane - 65ÂC
idle, when not typing... ok idle here(!) is with firefox running).
Similar things when I scroll through a terminal window, Alt-Tab cycle
between windows, and so on.
Testing is a bit difficult for me, as I couldn't come up with an easy
way to reproducibly generate real world load (like this typing, or
scrolling terminal windows), yet I tried to do an extensive test
series, which I think will illustrate some things.
Not really sure what the normal average or idle temps of that CPU are,
but I guess getting at average >80ÂC by just typing shouldn't be the
case.
1) Previous tests
*****************
When first searching for the reason of the temperature increase, I've
had opened several tickets:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=945055
https://lore.kernel.org/lkml/d05aba2742ae42783788c954e2a380e7fcb10830.camel@xxxxxxxxxxxx/
Finally to find (by coincidence):
https://gitlab.freedesktop.org/drm/intel/issues/614
when reporting:
https://gitlab.freedesktop.org/drm/intel/-/issues/953
myself.
At first I thought #614 would be the bug, but the fix for that went
into 5.5-rc, and in fact, with 5.5.x I do see the GPU entering RC6
sleep states again, yet the temperature of my system is still crazy.
2) Testing Environment
**********************
(for these new tests here)
- Fujitsu Lifebook U757
- most recent BIOS version (1.25) in the tests below (I've had used an
older one in previous tests from the links)
- 32GB memory, some Sandisk SSD
- Intel(R) Core(TM) i7-7600U CPU @ 2.80GHz
- microcode: sig=0x806e9, pf=0x80, revision=0xca
- Debian sid, all packages (unless some totally unrelated stuff at
their newest versions in unstable)
- all used kernels are stock kernels from Debian
- I do use full dm-crypt encryption of the system, but that shouldn't
be a cause for the problems, I guess.
- in my /etc/sysfs.conf I have:
devices/system/cpu/intel_pstate/no_turbo = 1
basically since I have that laptop... with turbo enabled I always
got
these:
Apr 5 18:27:07 heisenberg kernel: [ 9884.510420] mce: CPU3: Package temperature above threshold, cpu clock throttled (total events = 2609)
Apr 5 18:27:07 heisenberg kernel: [ 9884.510422] mce: CPU1: Package temperature above threshold, cpu clock throttled (total events = 2609)
Apr 5 18:27:07 heisenberg kernel: [ 9884.510465] mce: CPU0: Package temperature above threshold, cpu clock throttled (total events = 2609)
Apr 5 18:27:07 heisenberg kernel: [ 9884.510467] mce: CPU2: Package temperature above threshold, cpu clock throttled (total events = 2609)
Apr 5 18:27:07 heisenberg kernel: [ 9884.511427] mce: CPU3: Package temperature/speed normal
Apr 5 18:27:07 heisenberg kernel: [ 9884.511430] mce: CPU0: Package temperature/speed normal
Apr 5 18:27:07 heisenberg kernel: [ 9884.511431] mce: CPU1: Package temperature/speed normal
Apr 5 18:27:07 heisenberg kernel: [ 9884.511436] mce: CPU2: Package temperature/speed normal
=> so for the tests with ipntel_pstate not being disabled, turbo mode
was always disabled
3) How tests were made
**********************
I've tested with the following combinations:
- kernels 5.2.17 and 5.5.13
- with and without intel_pstate=disable
- with Cinnamon and GNOME Shell in classic mode
For all tests the notebook was placed in the same position and ran with
the same commands for tests, no other major processes (like firefox or
so) were running, just the respective bare desktop environment
(cinnamon or gnome shell classic), cron/anacron were stopped.
I always took temperature measurements with the output from sensors and
CSV output from powertop (which contains all the sleep states and high
energy users).
Temperature and powertop measurements were started at basically the
same time. powertop running for n iterations each 20s.
But since powertop takes a while to start the temperature measurements
are effectively shorter.
a) deep-idle
For these tests I've waited very long (like 5 minutes or more) for the
system to cool down.
Measurements with, e.g.:
export NAME="5.2.17/ipstate-disable/thermald-no/gnome-shell-classic/deep-idle" ; timeout 80 sh -c "while true; do sleep 1; sensors; done | grep ÂC > ${NAME}.temp"
and
export NAME="5.2.17/ipstate-disable/thermald-no/cinnamon/deep-idle" ; powertop -i 4 --csv=${NAME}.powertop.csv
b) idle
Basically the same as (a), just not waiting so long to cool down.
Effectively I've always produced some load (with the fan and CPU temp
noticeably going up over 65ÂC), then stopped and waited for a minute.
c) winmove
After waiting a while for the CPU to cool down, starting the
measurement and then moving a terminal window fast and constantly in
circles over the whole screen.
The measurement is split in 3 phases. During warmup and main I've moved
the window like crazy. As soon as the cooldown phase began, I've
stopped that and did nothing more until the measurement finished.
Measurements with, e.g.:
export NAME="5.2.17/ipstate-disable/thermald-no/cinnamon/winmove" ; powertop -i 3 --csv=${NAME}.warmup.powertop.csv ; beep ; powertop -i 4 --csv=${NAME}.main.powertop.csv ; beep ; powertop -i 4 --csv=${NAME}.cooldown.powertop.csv
export NAME="5.2.17/ipstate-disable/thermald-no/gnome-shell-classic/winmove" ; powertop -i 3 --csv=${NAME}.warmup.powertop.csv ; beep ; powertop -i 4 --csv=${NAME}.main.powertop.csv ; beep ; powertop -i 4 --csv=${NAME}.cooldown.powertop.csv
d) verify, verify-data
That measure when running a poorly written shell script of mine, the
shell script would read a list of regular files from find, and tries to
verify the SHA512 sum of that file, potentially stored as XATTR on it.
The script is poorly written, does quite a number of forks, pipes, and
so on, which seemed good for these test.
Difference between verify and verify-data are directories on which I
let find run.
with verify: I did it on /home/, where many files don't have my hash
XATTRs set
with verify-data: I did it on a dir, where basically all files have
them set an such there's more going into actual SHA512 calculation
Measurements with, e.g.:
export NAME="5.2.17/ipstate-disable/thermald-no/gnome-shell-classic/verifyxattr" ; timeout 160 sh -c "while true; do sleep 1; sensors; done | grep ÂC > ${NAME}.warmup+main.temp" ; beep
export NAME="5.2.17/ipstate-disable/thermald-no/cinnamon/verifyxattr" ; powertop -i 8 --csv=${NAME}.warmup+main.powertop.csv ; bee
e) mpv-gpu-vaapi
Playing back a:
Stream #0:0: Video: h264 (High), yuv420p(tv, bt709, progressive), 1920x1080 [SAR 1:1 DAR 16:9], 59.94 fps, 59.94 tbr, 1k tbn, 119.88 tbc (default)
video via:
mpv someVideo.mkv -ao=null
in fullscreen.
.config/mpv/mpv.conf has:
script-opts=osc-deadzonesize=0
hwdec=auto
So the video plays back with:
(+) Video --vid=1 (*) (h264 1920x1080 59.940fps)
(+) Audio --aid=1 --alang=eng (*) (opus 2ch 48000Hz)
Using hardware decoding (vaapi-copy).
AO: [null] 48000Hz stereo 2ch floatp
VO: [gpu] 1920x1080 nv12
AV: 00:00:01 / 00:36:23 (0%) A-V: 0.000
i.e. gpu and vaapi-copy
I've made two phases:
warmup+main: starting the video, going immediately to fullscreen
cooldown: as soon as the beep for it came, stopping mpv
Measurements with, e.g.:
export NAME="5.2.17/ipstate-disable/thermald-no/gnome-shell-classic/mpv-gpu-vaapi" ; timeout 80 sh -c "while true; do sleep 1; sensors; done | grep ÂC > ${NAME}.warmup+main.temp" ; beep ; timeout 80 sh -c "while true; do sleep 1; sensors; done | grep ÂC > ${NAME}.cooldown.temp"
export NAME="5.2.17/ipstate-disable/thermald-no/cinnamon/mpv-gpu-vaapi" ; powertop -i 4 --csv=${NAME}.warmup+main.powertop.csv ; beep ; powertop -i 4 --csv=${NAME}.cooldown.powertop.csv
f) unhide-brute
Running the unhide program in brute mode (using the C version, not the
ruby version).
unhide seems to do a lot of forking, which also seems to CPU to go
crazy in terms of temperature (at least in some cases).
Measurements with, e.g.:
export NAME="5.5.13/ipstate-active-hwp/thermald-no/cinnamon/unhide-brute" ; timeout 240 sh -c "while true; do sleep 1; sensors; done | grep ÂC > ${NAME}.warmup+main.temp" ; beep
export NAME="5.5.13/ipstate-active-hwp/thermald-no/cinnamon/unhide-brute" ; powertop -i 12 --csv=${NAME}.warmup+main.powertop.csv ; beep
4) Results
**********
For ease of use I've placed all my original test files and derived ones
in a git repo:
https://github.com/calestyo/cpu-tests
At first, I'm just looking at the bare temperatures of the Package,
which I've extracted to ./pack-temps for each of the tests.
I use ips = intel_pstate. in the following
a) deep-idle and idle
cinnamon_deep-idle.svg
=> 5.2 with ips=off runs ~2 ÂC cooler than 5.5 with ips=on
~4 ÂC cooler than 5.5 with ips=off
~3 ÂC cooler than 5.2 with ips=on
=> so from hottest to coolest:
5.5/ips=off 5.2/ips=on 5.5/ips=on 5.2/ips=off
cinnamon_idle.svg
=> at least it's quite obvious that 5.2 with ips=off runs coolest
compared to 5.5 with ips=off it's 4-5 ÂC...
compared to 5.5 with
ips=on it's still quite noticeable in the
beginning (could be testing though)
it's also noticeable cooler than
5.2 with ips=on
=> so from hottest to coolest:
5.5/ips=off 5.2/ips=on
5.5/ips=on 5.2/ips=off
(at least in the end)
gnome-shell-classic_deep-idle.svg
=> I'd say the results are too close, as one could deduce anything
valuable here,... but 5.5 looks better here (and ips=on looks even
better than having it disabled)
gnome-shell-classic_idle.svg
=> similarly here, the numbers are rather close, but 5.5 with ips=on
looks better... could however depend on the testing and the difference
is only ~2ÂC
=> One also sees, cinnamon runs considerably hotter than gnome-shell-
classic, none of them have any special applets or so running (just task
bar, workspace switcher, clock).
b) winmove.*
cinnamon_winmove.warmup.svg
cinnamon_winmove.main.svg
cinnamon_winmove.cooldown.svg
=> 5.2/ips=off runs considerably cooler than everything else, something
around 10-15ÂC?
=> 5.5/ips=on is clearly the worst
=> 5.2/ips=on and 5.5/ips=off are similar, but 5.2 seems still a bit
better during warmup and main
In this test it seems:
=> ips=off is considerably cooler/better for each kernel
=> 5.2 is considerably better or at least equal than the best of 5.5
gnome-shell-classic_winmove.warmup.svg
gnome-shell-classic_winmove.main.svg
gnome-shell-classic_winmove.cooldown.svg
=> again, g-s-c seems to do much better than cinnamon, but
=> 5.5/ips=off seems worst
5.5/ips=on seems slightly best
5.2/* in the mid-range
=> but again, the numbers are pretty close so this could be just from
testing
c) mpv-gpu-vaapi
mpv-gpu-vaapi.warmup+main.svg
=> most likely the blue line (5.2/ips=off/cinnamon) is just bogus,
could redo it if someone needs
difficult to say something,...
=> all end up at 95-100ÂC, the ones from cinnamon much faster
=> the only thing I'd personally deduce from these is, that hardware
acceleration has some severe problem in my setup. I'd have expected
that playing back a video in fullscreen should be not problem at all
for the GPU
mpv-gpu-vaapi.cooldown.svg
=> the only clear thing, I guess, is that 5.5/ips=off is worst with
cinnamon
d) verifyxattr and verifyxattr-data
cinnamon_verifyxattr.warmup+main.svg
cinnamon_verifyxattr-data.warmup+main.svg
=> the ones with ips=on are considerably worse...
=> interestingly, for verifyxattr 5.2/ips=off is better with
5.5/ips=off being the 2nd
=> but for verifyxattr-data (which is ought to be more actual SHA512
computation intensive and less just-forking), it's vice-versa
and 5.5/ips=off is better than 5.2/ips=off
=> seems like a hint that forking and/or process switches or similar
things could cause the temperature issues
gnome-shell-classic_verifyxattr.warmup+main.svg
gnome-shell-classic_verifyxattr-data.warmup+main.svg
similarly:
=> the ones with ips=on are considerably worse...
=> interestingly for verifyxattr 5.2 and 5.5 with ips=off
are more or less the same
=> but for verifyxattr-data 5.5 is noticeably better
=> these differences cannot be directly explained by some GPU issues,
at least not to my knowledge, since not much graphical output was
produced
e) unhide-brute
cinnamon_unhide-brute.warmup+main.svg
gnome-shell-classic_unhide-brute.warmup+main.svg
=> both are nearly the same, except that under g-s-c, 5.5/ips=on
is noticeable worse than under 5.2/ips=on
=> again, ips=off is *much* better than ips=on
=> 5.2 is considerably better than 5.5
=> these differences cannot be directly explained by some GPU issues,
at least not to my knowledge, since not much graphical output was
produced
I think overall conclusions are mostly:
Especially when the temperatures vary greatly, then
- 5.2 is much better than 5.5
- ips=off is much better or at least similar to ips=on
5) the powertop files
*********************
So far I've only taken a glance on them in trying to deduce anything
meaningful.
My hope would have been that some experts here have more experience on
reading them. ;-)
Looking for example at the files from my unhide-brute tests, comparing
5.2/ips=on/cinnamon with 5.5/ips=on/cinnamon, it seemed sometimes that:
Timer;tick_sched_timer
kWork;intel_atomic_commit_work
kWork;free_work
might be offenders... but that's all not so obvious (at least to me).
6) Observations / Other
***********************
a) One thing I've noted sometimes, but not always:
When the system was under "some" load that caused extreme
temperatures... even when I stopped that load, temperatures didn't
always go back.
I mean it's clear that cooling takes a while, but sometimes things went
on for 5 mins or more.
b) Sometimes it might have seemed, that putting the system to suspend
cured the symptoms for a while,... but not always and I haven't tested
this in both kernels and ips=* variations.
c) While writing this email I'm in 5.5/ips=off/g-s-c ...
(not sure whether ips=on would have been much better)
The short time idle-temperature is already pretty bad (~65ÂC)
(firefox, which seems to be a bad temperature offender, runs
though).
Closing FF and the idle temp goes to around ~58-59 (would probably
go lower if I wait for longer)
But when I now start moving around the mouse pointer, everything
stays the roughly same... but I had also situations, where just by
moving the pointer, temperatures when to 80ÂC or higher,... stopped
moving the pointer, and the fell again.
When I know press&hold a key in a gnome-terminal window, say
constantly writing "n" to it... nothing changes.
When I do the same in Evolution's mail compose window...
temperatures go up to 74ÂC.
Correspondingly I see
/usr/lib/x86_64-linux-gnu/webkit2gtk-4.0/WebKitWebProcess
going through the roof in powertop.
Now one could argue there's just something fishy in
Evolution/WebKit, but from what I remember it's by far not that bad
(if at all) under 5.2.
d) Similarly, if I just move around the pointer via the touchpad:
1.71 W 13,2 ms/s 436,3 Interrupt PS/2 Touchpad / Keyboard / Mouse
becomes the top power consumer with quite a lot it seems?
e) At least until 5.5 (which fixed the i915 GPU doesn't go to RC6
issue), I quite often saw the temperatures go crazy, while top
didn't show that much CPU utilisation.
Well it's quite clear if the issue was only in the GPU, but even
with that fixed it still seemed at least sometimes during my tests,
that I saw extreme temperatures while top didn't show even close to
100% CPU utilisation.
f) right now, eventstat shows something like this:
Event/s PID %CPU PR NI Task Init Function
81.92 10050 2.1 0 0 WebKitWebProces hrtimer_wakeup
51.95 1600 0.1 0 0 Xorg it_real_fn
49.95 1600 0.1 0 0 Xorg hrtimer_wakeup
46.95 10050 2.1 0 0 WebKitWebProces tick_sched_timer
32.97 3184 0.7 0 0 gnome-terminal- hrtimer_wakeup
28.97 63710 0.0 0 0 [kworker/0:2-event intel_uncore_fw_release_timer
11.99 2831 0.1 0 0 gnome-shell hrtimer_wakeup
8.99 3417 0.1 0 0 evolution hrtimer_wakeup
5.00 1600 0.1 0 0 Xorg tick_sched_timer
5.00 71575 0.3 0 0 top it_real_fn
4.00 3184 0.7 0 0 gnome-terminal- tick_sched_timer
4.00 59885 0.1 0 0 diodon hrtimer_wakeup
3.00 71575 0.3 0 0 top tick_sched_timer
2.00 72584 0.0 0 0 <unknown> tick_sched_timer
2.00 2831 0.1 0 0 gnome-shell timerfd_tmrproc
1.00 72585 0.0 0 0 sleep hrtimer_wakeup
1.00 66991 0.0 0 -20 [kworker/u9:2-i915 tick_sched_timer
1.00 750 0.0 0 0 haveged hrtimer_wakeup
that hrtimer_wapeup and tick_sched_timer appear quite often in the top list.
Anything that changed there after 5.2?
Attaching with strace to that WebKitWebProcess:
$ strace -p 10050
strace: Process 10050 attached
restart_syscall(<... resuming interrupted read ...>) = 0
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 0 (Timeout)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 0 (Timeout)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 0 (Timeout)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 0 (Timeout)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 14) = 0 (Timeout)
in a very fast "loop"...
Interestingly, printing that out, which is really! fast... doesn't seem
to increase the temperature much.
When I press&hold a key in evolution strace output shows a lot of
these:
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\2\0\0\0\0\0\0\0", 16) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
madvise(0x7f74af5ea000, 4096, MADV_NORMAL) = 0
madvise(0x7f74af5ea000, 4096, MADV_DODUMP) = 0
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\2\0\0\0\0\0\0\0", 16) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
memfd_create("WebKitSharedMemory", MFD_CLOEXEC) = 23
ftruncate(23, 18585600) = 0
mmap(NULL, 18585600, PROT_READ|PROT_WRITE, MAP_SHARED, 23, 0) = 0x7f74ae346000
fcntl(23, F_DUPFD_CLOEXEC, 0) = 18
munmap(0x7f74ae346000, 18585600) = 0
close(23) = 0
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
madvise(0x7f74af5e9000, 4096, MADV_NORMAL) = 0
madvise(0x7f74af5e9000, 4096, MADV_DODUMP) = 0
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670f5d690, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\2\0\0\0\0\0\0\0", 16) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
memfd_create("WebKitSharedMemory", MFD_CLOEXEC) = 24
ftruncate(24, 18585600) = 0
mmap(NULL, 18585600, PROT_READ|PROT_WRITE, MAP_SHARED, 24, 0) = 0x7f74ae346000
fcntl(24, F_DUPFD_CLOEXEC, 0) = 18
munmap(0x7f74ae346000, 18585600) = 0
close(24) = 0
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\2\0\0\0\0\0\0\0", 16) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(10, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55c670f5d690, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f74c0005ab0, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55c670eff418, FUTEX_WAKE_PRIVATE, 1) = 1
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 3, 0) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\5\0\0\0\0\0\0\0", 16) = 8
write(4, "\1\0\0\0\0\0\0\0", 8) = 8
write(15, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x7f74d8000b60, FUTEX_WAKE_PRIVATE, 1) = 1
memfd_create("WebKitSharedMemory", MFD_CLOEXEC) = 24
ftruncate(24, 18585600) = 0
mmap(NULL, 18585600, PROT_READ|PROT_WRITE, MAP_SHARED, 24, 0) = 0x7f74ae346000
fcntl(24, F_DUPFD_CLOEXEC, 0) = 18
Not sure if that's normal...
Anyway, back to my needle-in-the-haystack-search:
diodon, which is a small little clipboard helper also shows up in
powertop since a while, not it that much mW, but still much more I'd
have expected from a little tool that does basically nothing.
Attaching to it with strace again reveals a lot of polling:
writev(7, [{iov_base="\203(\3\0\336\5\0\0\2\0\0\0", iov_len=12}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 12
poll([{fd=7, events=POLLIN}], 1, -1) = 1 ([{fd=7, revents=POLLIN}])
recvmsg(7, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1(!T\7\0\0\0\336\5\0\0[\201S\2\0\0]\0\0\0!\1\0\0]\0\0\0!\1"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 60
poll([{fd=3, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 3, 0) = 1 ([{fd=3, revents=POLLIN}])
read(3, "\1\0\0\0\0\0\0\0", 16) = 8
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 3, 494) = 0 (Timeout)
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 3, 3) = 0 (Timeout)
poll([{fd=7, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=7, revents=POLLOUT}])
writev(7, [{iov_base="\22\0\7\0\2\0\300\4L\2\0\0L\2\0\0\10\0\0\0\1\0\0\0a\1\0\0", iov_len=28}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 28
poll([{fd=7, events=POLLIN}], 1, -1) = 1 ([{fd=7, revents=POLLIN}])
recvmsg(7, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\34\0\"T\2\0\300\4L\2\0\0\207f\24\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=7, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=7, revents=POLLOUT}])
writev(7, [{iov_base="\27\0\2\0\1\0\0\0", iov_len=8}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 8
poll([{fd=7, events=POLLIN}], 1, -1) = 1 ([{fd=7, revents=POLLIN}])
recvmsg(7, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\0#T\0\0\0\0\2\0@\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32
poll([{fd=7, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=7, revents=POLLOUT}])
writev(7, [{iov_base="\30\0\6\0\2\0\300\4\1\0\0\0M\2\0\0\230\1\0\0\207f\24\2", iov_len=24}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 24
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 3, 494) = 1 ([{fd=7, revents=POLLIN}])
recvmsg(7, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\34\0$T\2\0\300\4\230\1\0\0\214f\24\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 64
recvmsg(7, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable)
All this again with 5.5/ips=off/g-c-s.
g) Looking at powertop:
1.56 W 9,8 ms/s 397,8 Interrupt PS/2 Touchpad / Keyboard / Mouse
836 mW 1,6 ms/s 213,9 kWork dbs_work_handler
804 mW 2,7 ms/s 205,5 Timer tick_sched_timer
594 mW 30,2 ms/s 144,6 Process [PID 2831] /usr/bin/gnome-shell
585 mW 35,6 ms/s 140,9 Process [PID 1600] /usr/lib/xorg/Xorg :0 -seat seat0 -auth /var/run/lightdm/root/:0 -nolisten
(this is during and effectively idly system)
tick_sched_timer and dbs_work_handler appear there quite often at the top.
And they keyboard/mouse/touchpad, too.
7) Conclusions
**************
Well not that many except:
- video acceleration seems not really working
- cinnamon generally worse than gnome-shell-classic (which of course
doesn't have to be a kernel issue, but it still seems to have gotten
worse with >5.2 ... and it might be a pointer to what's wrong in the
kernel
- when the temperature differs more greatly in the measurements, than
5.2 seems typically much better than 5.5
and ips=off, too.
My tests are obviously somehow limited. None of them simulates the
"normal" usage, like just switching between windows (well the winmove
tests does to some extent), scrolling up and down in a window and so
on.... and these use cases also greatly increase temperature... not
rarely over 80ÂC.
Any ideas what could cause all this? Context switches? Spectre&friends
protections that were added after 5.2? Interrupts? Something related to
polling?
Or any ideas what to do in terms of further tests? Other kernel
options? Or other tools (things like eventstat and so on)?
Any help would be appreciated, cause right now my laptop is more of an
oven and it starts to literally burn my legs when I work with it.
Thanks,
Chris.