bbidulock / icewm

A window manager designed for speed, usability, and consistency
Other
570 stars 97 forks source link

Higher background CPU load due to some amok running timer #763

Open Code7R opened 5 months ago

Code7R commented 5 months ago

I started wondering over x-mas time why one of my systems (which is typically idling overnight with an active X session) started consuming more power. And not just a little bit, the wattage almost doubled. And powertop reported icewm as the culprit, causing over 100 wakeups per second while supposedly doing nothing. But the behavior did not always appear, and I was not sure how to reproduce it.

But this time I could catch it, and see it happening even over multiple restarts of icewm. So I did a git-bisect and could identify the following commit as the culprit:

13d384d352a10ebdface07c1b821b0c8c971f209 is the first bad commit
commit 13d384d352a10ebdface07c1b821b0c8c971f209
Author: Bert Gijsbers <gijsbers@science.uva.nl>
Date:   Wed Nov 9 22:05:27 2022 +0100

    Freeze the task pane layout while Alt is pressed for #549.

 src/atasks.cc    | 12 ++++++------
 src/wmtaskbar.cc |  2 +-
 2 files changed, 7 insertions(+), 7 deletions(-)

And regarding the type of events, that could be anything. Looks like some endlessly repeated X11 communication attempt:


poll([{fd=5, events=POLLIN}], 1, -1)    = 1 ([{fd=5, revents=POLLIN}])
recvmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\1\320\231\0\0\0\0a\5\0\0\0\0\0\0_\r,\4\307\1\5\376\20\0\0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=383841538}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=383880230}) = 0
rt_sigprocmask(SIG_UNBLOCK, [HUP INT QUIT USR2 PIPE TERM CHLD], NULL, 8) = 0
pselect6(1024, [3 5], [], NULL, {tv_sec=0, tv_nsec=15961000}, NULL) = 0 (Timeout)
rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT USR2 PIPE TERM CHLD], NULL, 8) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=400309429}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=400456237}) = 0
poll([{fd=5, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=5, revents=POLLOUT}])
writev(5, [{iov_base="&\0\2\09\2@\0", iov_len=8}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 8
poll([{fd=5, events=POLLIN}], 1, -1)    = 1 ([{fd=5, revents=POLLIN}])
recvmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\1\321\231\0\0\0\0a\5\0\0\0\0\0\0_\r,\4\307\1\5\376\20\0\0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=400893864}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=400923687}) = 0
rt_sigprocmask(SIG_UNBLOCK, [HUP INT QUIT USR2 PIPE TERM CHLD], NULL, 8) = 0
pselect6(1024, [3 5], [], NULL, {tv_sec=0, tv_nsec=15970000}, NULL) = 0 (Timeout)
rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT USR2 PIPE TERM CHLD], NULL, 8) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=417219908}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=417357496}) = 0
poll([{fd=5, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=5, revents=POLLOUT}])
writev(5, [{iov_base="&\0\2\09\2@\0", iov_len=8}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 8
poll([{fd=5, events=POLLIN}], 1, -1)    = 1 ([{fd=5, revents=POLLIN}])
recvmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\1\322\231\0\0\0\0a\5\0\0\0\0\0\0_\r,\4\307\1\5\376\20\0\0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=417842686}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=417876978}) = 0
rt_sigprocmask(SIG_UNBLOCK, [HUP INT QUIT USR2 PIPE TERM CHLD], NULL, 8) = 0
pselect6(1024, [3 5], [], NULL, {tv_sec=0, tv_nsec=15966000}, NULL) = 1 (in [5], left {tv_sec=0, tv_nsec=2087068})
rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT USR2 PIPE TERM CHLD], NULL, 8) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=432054343}) = 0
recvmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\34\0\322\231n<\340\1\177\1\0\0\347\303?\7\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(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=5, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=5, revents=POLLOUT}])
writev(5, [{iov_base="\24\0\6\0m<\340\1\177\1\0\0\6\0\0\0\0\0\0\0\1\0\0\0", iov_len=24}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 24
poll([{fd=5, events=POLLIN}], 1, -1)    = 1 ([{fd=5, revents=POLLIN}])
recvmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\0\323\231\0\0\0\0\0\0\0\0\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
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(5, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {tv_sec=121619, tv_nsec=432798506}) = 0
gijsbers commented 5 months ago

Maybe can you try undoing this part, so that it uses Now:

index 0e3e814d..36e99a81 100644
--- a/src/wmtaskbar.cc
+++ b/src/wmtaskbar.cc
@@ -643,7 +643,7 @@ void TaskBar::relayoutNow() {
         updateLocation();
     }
     if (taskPane())
-        taskPane()->relayoutNow();
+        taskPane()->relayout();
     if (fButtonUpdate) {
         fButtonUpdate = false;
         buttonUpdate();
Code7R commented 4 months ago

This does not really make a difference. OTOH I am observing more strange issues with CPU activity on that system, seems to be caused by recent updates which trigger strange kernel behaviors. I need to observe this further, the current issue can be probably put on hold.