[PATCH 0/3] timer hang: fix periodic powertop hangs

[Sergey Senozhatsky]

Hello Arjan,

I've merged my branch with fenrus75/powertop.git and my powertop build
began to periodically hang with high CPU usage.

The consuming function turned out to be timer::is_deferred().

15078 root 20 0 198m 152m 12m R 94 (%CPU) 4.0 1:11.25 powertop
...
0x00007fa12b5e9600 in __read_nocancel () from /lib/libc.so.6
(gdb) bt
#0 0x00007fa12b5e9600 in __read_nocancel () from /lib/libc.so.6
#1 0x00007fa12b5869c8 in _IO_new_file_underflow () from /lib/libc.so.6
#2 0x00007fa12b587a1e in _IO_default_uflow_internal () from /lib/libc.so.6
#3 0x00007fa12b57c42a in _IO_getline_info_internal () from /lib/libc.so.6
#4 0x00007fa12b57b27b in fgets () from /lib/libc.so.6
#5 0x0000000000423a74 in fgets (__stream=0xc29da20, __n=4096, __s=0x7fff8847eb30 "196609D, 11372 kworker/3:1 schedule_delayed_work_on
+(delayed_work_timer_fn)\n") at /usr/include/bits/stdio2.h:255
#6 timer::is_deferred (this=0xc296b70) at process/timer.cpp:155
#7 0x000000000041fc5c in perf_process_bundle::handle_trace_point (this=<optimized out>, type=<optimized out>, trace=0xbe38ff8, cpu=1,
+time=22986802201894, flags=20 '\024') at process/do_process.cpp:379
#8 0x000000000041c60e in perf_bundle::process (this=0x83c4a70) at perf/perf_bundle.cpp:245
#9 0x0000000000420016 in process_process_data () at process/do_process.cpp:997
#10 0x000000000040a4aa in one_measurement (seconds=<optimized out>) at main.cpp:205
#11 0x0000000000405cab in main (argc=1, argv=0x7fff88481dd8) at main.cpp:422


Below are 3 patches to make powertop much more responsive just as it's used to be.
Of course, is_deferred() affects performance, however, its impact is minimized.


-ss

[Sergey Senozhatsky]

Code cleanup in is_deferred().

- No need to check for !handler, since it's allocated member array
- "total events" substrig search is redundant -- EOF should do the same
- replace strchr() with "D," substring search.

Alos I really don't like fopen()/fclose() syscall storm, fix it later.

Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky-***@public.gmane.org>

---

process/timer.cpp | 35 +++++++++++++----------------------
1 files changed, 13 insertions(+), 22 deletions(-)

diff --git a/process/timer.cpp b/process/timer.cpp
index 5c1da31..221d6d0 100644
--- a/process/timer.cpp
+++ b/process/timer.cpp
@@ -139,36 +139,27 @@ bool get_timerstats(void)

bool timer::is_deferred(void)
{
- FILE *file;
- char line[4096];
+ FILE *file;
+ bool ret = false;
+ char line[4096];

if (!get_timerstats()){
return false;
}
- file = fopen("/proc/timer_stats", "r");
+ file = fopen("/proc/timer_stats", "r");
if (!file) {
- return false;
+ return ret;
}

- while (file && !feof(file)) {
- char *c;
- if (fgets(line, 4096,file)== NULL)
- break;
- if (strstr(line, "total events"))
+ while (!feof(file)) {
+ if (fgets(line, 4096, file) == NULL)
break;
- if (!handler)
- break;
- if (strstr(line, handler)){
- c = strchr(line, ',');
- if (!c)
- continue;
- c--;
- if (*c == 'D') {
- fclose(file);
- return true;
- }
+ if (strstr(line, handler)) {
+ ret = (strstr(line, "D,") != NULL);
+ if (ret == true)
+ break;
}
}
fclose(file);
- return false;
-}
\ No newline at end of file
+ return ret;
+}

[Sergey Senozhatsky]

Factor out timer::is_deferred() to timer_is_deferred() function.
timer_is_deferred() gets called from timer() constructor and
fills deferred bool member variable. So timer::is_deferred() now
can simply return deferred, w/o any need of file lookup -- which is
performed only once during timer creation, not on every
timer:timer_expire_entry event.


Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky-***@public.gmane.org>

---

process/timer.cpp | 45 +++++++++++++++++++++++++--------------------
process/timer.h | 1 +
2 files changed, 26 insertions(+), 20 deletions(-)

diff --git a/process/timer.cpp b/process/timer.cpp
index 9674645..5711b8c 100644
--- a/process/timer.cpp
+++ b/process/timer.cpp
@@ -35,11 +35,35 @@

using namespace std;

+static bool timer_is_deferred(const char *handler)
+{
+ FILE *file;
+ bool ret = false;
+ char line[4096];
+
+ file = fopen("/proc/timer_stats", "r");
+ if (!file) {
+ return ret;
+ }
+
+ while (!feof(file)) {
+ if (fgets(line, 4096, file) == NULL)
+ break;
+ if (strstr(line, handler)) {
+ ret = (strstr(line, "D,") != NULL);
+ if (ret == true)
+ break;
+ }
+ }
+ fclose(file);
+ return ret;
+}

timer::timer(unsigned long address) : power_consumer()
{
strncpy(handler, kernel_function(address), 31);
raw_count = 0;
+ deferred = timer_is_deferred(handler);
}


@@ -127,24 +151,5 @@ void clear_timers(void)

bool timer::is_deferred(void)
{
- FILE *file;
- bool ret = false;
- char line[4096];
-
- file = fopen("/proc/timer_stats", "r");
- if (!file) {
- return ret;
- }
-
- while (!feof(file)) {
- if (fgets(line, 4096, file) == NULL)
- break;
- if (strstr(line, handler)) {
- ret = (strstr(line, "D,") != NULL);
- if (ret == true)
- break;
- }
- }
- fclose(file);
- return ret;
+ return deferred;
}
diff --git a/process/timer.h b/process/timer.h
index 19aa0a7..8e07e69 100644
--- a/process/timer.h
+++ b/process/timer.h
@@ -34,6 +34,7 @@ class timer : public power_consumer {
public:
char handler[32];
int raw_count;
+ bool deferred;

timer(unsigned long timer_func);