measuring system wide CPU usage ignoring idle process

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs utilized          
       4004.526474      task-clock (msec)         #    4.000 CPUs utilized          
       945,906,029      cycles                    #    0.236 GHz                    
       461,861,241      instructions              #    0.49  insn per cycle         

       1.001247082 seconds time elapsed

This shows that cpu-clock and task-clock are incremented also for the idle processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

Quoted 16 lines · Milian Wolff

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs utilized
       4004.526474      task-clock (msec)         #    4.000 CPUs utilized
       945,906,029      cycles                    #    0.236 GHz
       461,861,241      instructions              #    0.49  insn per
       cycle
       
       1.001247082 seconds time elapsed

Quoted 3 lines

This shows that cpu-clock and task-clock are incremented also for the idle processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

I dont think it's the idle process you see, I think it's the managing overhead before the 'sleep 1' task goes actualy to sleep

there's some user space code before it gets into the sleep syscall, and there's some possible kernel scheduling/syscall/irq code with events already enabled and counting

in following 3 sessions you can see the counts are pretty much the same regardless the sleeping time:

	[jolsa@krava perf]$ sudo ./perf stat -e cycles:u,cycles:k sleep 1

	 Performance counter stats for 'sleep 1':

		   316,478      cycles:u
		   594,468      cycles:k

	       1.000813330 seconds time elapsed

	[jolsa@krava perf]$ sudo ./perf stat -e cycles:u,cycles:k sleep 5

	 Performance counter stats for 'sleep 5':

		   339,287      cycles:u
		   665,888      cycles:k

	       5.001004575 seconds time elapsed

	[jolsa@krava perf]$ sudo ./perf stat -e cycles:u,cycles:k sleep 10

	 Performance counter stats for 'sleep 10':

		   314,507      cycles:u
		   658,764      cycles:k

	      10.001117596 seconds time elapsed

Quoted 21 lines · On Montag, 20. November 2017 15:29:08 CET Jiri Olsa wrote:

Quoted 16 lines · Milian Wolff

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs utilized
       4004.526474      task-clock (msec)         #    4.000 CPUs utilized
       945,906,029      cycles                    #    0.236 GHz
       461,861,241      instructions              #    0.49  insn per
       cycle
       
       1.001247082 seconds time elapsed

Quoted 3 lines

This shows that cpu-clock and task-clock are incremented also for the idle processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

Quoted 6 lines

I dont think it's the idle process you see, I think it's the managing overhead before the 'sleep 1' task goes actualy to sleep

there's some user space code before it gets into the sleep syscall, and there's some possible kernel scheduling/syscall/irq code with events already enabled and counting

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

Quoted 33 lines · Milian Wolff

Quoted 25 lines · On Montag, 20. November 2017 15:29:08 CET Jiri Olsa wrote:

Quoted 19 lines · Milian Wolff

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my
attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs
       utilized
       4004.526474      task-clock (msec)         #    4.000 CPUs
       utilized
       945,906,029      cycles                    #    0.236 GHz
       461,861,241      instructions              #    0.49  insn per
       cycle
       
       1.001247082 seconds time elapsed

Quoted 4 lines

This shows that cpu-clock and task-clock are incremented also for the idle
processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

Quoted 6 lines

I dont think it's the idle process you see, I think it's the managing overhead before the 'sleep 1' task goes actualy to sleep

there's some user space code before it gets into the sleep syscall, and there's some possible kernel scheduling/syscall/irq code with events already enabled and counting

Quoted 6 lines

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

ugh my bad.. anyway by using -a you create cpu counters which never unschedule, so those times will be same as the 'sleep 1' run length

but not sure now how to get the real utilization.. will check

Quoted 40 lines · CET Jiri Olsa

Quoted 33 lines · Milian Wolff

Quoted 25 lines · On Montag, 20. November 2017 15:29:08 CET Jiri Olsa wrote:

Quoted 19 lines · Milian Wolff

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my
attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs
       utilized
       4004.526474      task-clock (msec)         #    4.000 CPUs
       utilized
       945,906,029      cycles                    #    0.236 GHz
       461,861,241      instructions              #    0.49  insn per
       cycle
       
       1.001247082 seconds time elapsed

Quoted 4 lines

This shows that cpu-clock and task-clock are incremented also for the idle
processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

Quoted 6 lines

I dont think it's the idle process you see, I think it's the managing overhead before the 'sleep 1' task goes actualy to sleep

there's some user space code before it gets into the sleep syscall, and there's some possible kernel scheduling/syscall/irq code with events already enabled and counting

Quoted 6 lines

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

Quoted 5 lines

ugh my bad.. anyway by using -a you create cpu counters which never unschedule, so those times will be same as the 'sleep 1' run length

but not sure now how to get the real utilization.. will check

Hey jirka,

did you have a chance to check the above? I'd be really interested in knowing whether there is an existing workaround. If not, would it be feasible to patch perf to get the desired behavior? I'd be willing to look into this. This would probably require changes on the kernel side though, or how could this be fixed?

Quoted 47 lines · Milian Wolff

Quoted 40 lines · CET Jiri Olsa

Quoted 33 lines · Milian Wolff

Quoted 25 lines · On Montag, 20. November 2017 15:29:08 CET Jiri Olsa wrote:

Quoted 19 lines · Milian Wolff

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my
attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs
       utilized
       4004.526474      task-clock (msec)         #    4.000 CPUs
       utilized
       945,906,029      cycles                    #    0.236 GHz
       461,861,241      instructions              #    0.49  insn per
       cycle
       
       1.001247082 seconds time elapsed

Quoted 4 lines

This shows that cpu-clock and task-clock are incremented also for the idle
processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

Quoted 6 lines

I dont think it's the idle process you see, I think it's the managing overhead before the 'sleep 1' task goes actualy to sleep

there's some user space code before it gets into the sleep syscall, and there's some possible kernel scheduling/syscall/irq code with events already enabled and counting

Quoted 6 lines

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

Quoted 5 lines

ugh my bad.. anyway by using -a you create cpu counters which never unschedule, so those times will be same as the 'sleep 1' run length

but not sure now how to get the real utilization.. will check

Quoted 7 lines

Hey jirka,

did you have a chance to check the above? I'd be really interested in knowing whether there is an existing workaround. If not, would it be feasible to patch perf to get the desired behavior? I'd be willing to look into this. This would probably require changes on the kernel side though, or how could this be fixed?

hi,
I haven't found any good way yet.. I ended up with following patch to allow attach counters to idle process, which got me the count/behaviour you need (with few tools changes in my perf/idle branch)

but I'm not sure it's the best idea ;-) there might be better way.. CC-ing Ingo, Peter and Alexander

Quoted 42 lines · Milian Wolff

Quoted 41 lines · CET Jiri Olsa

Quoted 40 lines · Milian Wolff

Quoted 39 lines · On Montag, 20. November 2017 15:29:08 CET Jiri Olsa wrote:

Quoted 25 lines · Milian Wolff

Quoted 19 lines

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my
attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs
       utilized
       4004.526474      task-clock (msec)         #    4.000 CPUs
       utilized
       945,906,029      cycles                    #    0.236 GHz
       461,861,241      instructions              #    0.49  insn per
       cycle
       
       1.001247082 seconds time elapsed

Quoted 4 lines

This shows that cpu-clock and task-clock are incremented also for the idle
processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

Quoted 6 lines

I dont think it's the idle process you see, I think it's the managing overhead before the 'sleep 1' task goes actualy to sleep

there's some user space code before it gets into the sleep syscall, and there's some possible kernel scheduling/syscall/irq code with events already enabled and counting

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

Quoted 3 lines

Quoted 3 lines

Quoted 3 lines

ugh my bad.. anyway by using -a you create cpu counters which never unschedule, so those times will be same as the 'sleep 1' run length

Quoted 15 lines

Quoted 8 lines

Quoted 2 lines

but not sure now how to get the real utilization.. will check

did you have a chance to check the above? I'd be really interested in knowing whether there is an existing workaround. If not, would it be feasible to patch perf to get the desired behavior? I'd be willing to look into this. This would probably require changes on the kernel side though, or how could this be fixed?

hi,
I haven't found any good way yet.. I ended up with following patch to allow attach counters to idle process, which got me the count/behaviour you need (with few tools changes in my perf/idle branch)

Quoted 2 lines

but I'm not sure it's the best idea ;-) there might be better way.. CC-ing Ingo, Peter and Alexander

also I was thinking we might add 'idle' line into perf top ;-) shouldn't be that hard once we have the counter

Em Thu, Nov 23, 2017 at 03:21:00PM +0100, Jiri Olsa escreveu:

Quoted 43 lines · Jiri Olsa

Quoted 42 lines · Milian Wolff

Quoted 41 lines · CET Jiri Olsa

Quoted 40 lines · Milian Wolff

Quoted 39 lines · On Montag, 20. November 2017 15:29:08 CET Jiri Olsa wrote:

Quoted 25 lines · Milian Wolff

Quoted 19 lines

Hey all,

colleagues of mine just brought this inconvenient perf stat behavior to my
attention:

$ perf stat -a -e cpu-clock,task-clock,cycles,instructions sleep 1

Performance counter stats for 'system wide':

       4004.501439      cpu-clock (msec)          #    4.000 CPUs
       utilized
       4004.526474      task-clock (msec)         #    4.000 CPUs
       utilized
       945,906,029      cycles                    #    0.236 GHz
       461,861,241      instructions              #    0.49  insn per
       cycle
       
       1.001247082 seconds time elapsed

Quoted 4 lines

This shows that cpu-clock and task-clock are incremented also for the idle
processes. Is there some trick to exclude that time, such that the CPU utilization drops below 100% when doing perf stat -a?

Quoted 6 lines

I dont think it's the idle process you see, I think it's the managing overhead before the 'sleep 1' task goes actualy to sleep

there's some user space code before it gets into the sleep syscall, and there's some possible kernel scheduling/syscall/irq code with events already enabled and counting

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

Quoted 3 lines

Quoted 3 lines

Quoted 3 lines

Quoted 3 lines

ugh my bad.. anyway by using -a you create cpu counters which never unschedule, so those times will be same as the 'sleep 1' run length

Humm, what role perf_event_attr.exclude_idle has here?

Quoted 9 lines

Em Thu, Nov 23, 2017 at 03:21:00PM +0100, Jiri Olsa escreveu:

Quoted 8 lines · Jiri Olsa

Quoted 7 lines · Milian Wolff

Quoted 6 lines

Quoted 6 lines

Quoted 6 lines

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

Quoted 5 lines

Quoted 3 lines

Quoted 3 lines

Quoted 3 lines

Quoted 3 lines

ugh my bad.. anyway by using -a you create cpu counters which never unschedule, so those times will be same as the 'sleep 1' run length

Humm, what role perf_event_attr.exclude_idle has here?

it's used for omiting samples from idle process.. but looks like it's enforced for software clock events

AFAICS it's not used in counting mode

Em Thu, Nov 23, 2017 at 04:12:05PM +0100, Jiri Olsa escreveu:

Quoted 14 lines · Arnaldo Carvalho de Melo

Quoted 13 lines

Em Thu, Nov 23, 2017 at 03:21:00PM +0100, Jiri Olsa escreveu:

Quoted 12 lines · Jiri Olsa

Quoted 11 lines · Milian Wolff

Quoted 10 lines

Quoted 10 lines

Quoted 6 lines

Sorry for being unclear: I was talking about the task-clock and cpu-clock values which you omitted from your measurements below. My example also shows that the counts for cycles and instructions are fine. But the cpu-clock and task-clock are useless as they always sum up to essentially $nproc*$runtime. What I'm hoping for are fractional values for the "N CPUs utilized".

ugh my bad.. anyway by using -a you create cpu counters which never unschedule, so those times will be same as the 'sleep 1' run length

Quoted 4 lines

Quoted 1 line

Humm, what role perf_event_attr.exclude_idle has here?

it's used for omiting samples from idle process.. but looks like it's enforced for software clock events

looks like it is NOT enforced?

Quoted 2 lines

AFAICS it's not used in counting mode

But it should? I think it should, as we see from Milian's use case.

PeterZ sent a patch, I guess we should continue from there :-)

What is wrong with perf_event_attr.exclude_idle? :-)

Quoted 1 line

What is wrong with perf_event_attr.exclude_idle? :-)

Neither task- nor cpu-clock actually implement that..

Something like the _completely_untested_ below might cure that for cpu-clock. I have the nagging feeling we actually already account the idle time _somewhere_, but I couldn't remember and was too lazy to go find -- but someone should if this were to become an actual patch.

---

kernel/events/core.c +4 -0

index a59fe11558a4..5386d551b373 100644
@@ -8900,6 +8908,10 @@ static void cpu_clock_event_update(struct perf_event *event)
 	u64 now;
 
 	now = local_clock();
+
+	if (event->attr.exclude_idle)
+		now -= idle_task(event->oncpu)->se.sum_exec_runtime;
+
 	prev = local64_xchg(&event->hw.prev_count, now);
 	local64_add(now - prev, &event->count);
 }

kernel/sched/idle_task.c +19 -0

index d518664cce4f..419c620510c6 100644
@@ -27,9 +27,14 @@ static void check_preempt_curr_idle(struct rq *rq, struct task_struct *p, int fl
 static struct task_struct *
 pick_next_task_idle(struct rq *rq, struct task_struct *prev, struct rq_flags *rf)
 {
+	struct task_struct *idle = rq->idle;
+
 	put_prev_task(rq, prev);
 	update_idle_core(rq);
 	schedstat_inc(rq->sched_goidle);
+
+	idle->se.exec_start = rq_clock_task(rq);
+
 	return rq->idle;
 }
 

@@ -48,6 +53,17 @@ dequeue_task_idle(struct rq *rq, struct task_struct *p, int flags)
 
 static void put_prev_task_idle(struct rq *rq, struct task_struct *prev)
 {
+	struct task_struct *idle = rq->idle;
+	u64 delta, now;
+
+	now = rq_clock_task(rq);
+	delta = now - idle->se.exec_start;
+	if (unlikely((s64)delta < 0))
+		delta = 0;
+
+	idle->se.sum_exec_runtime += delta;
+	idle->se.exec_start = now;
+
 	rq_last_tick_reset(rq);
 }
 

@@ -57,6 +73,9 @@ static void task_tick_idle(struct rq *rq, struct task_struct *curr, int queued)
 
 static void set_curr_task_idle(struct rq *rq)
 {
+	struct task_struct *idle = rq->idle;
+
+	idle->se.exec_start = rq_clock_task(rq);
 }
 
 static void switched_to_idle(struct rq *rq, struct task_struct *p)