Skip to contentSkip to conversation

High, likely incorrect process cpu usage counters with kvm and 2.6.2[67]

REGRESSION Applied Avi Kivity 4 participants 6 messages Aug 31, 2008 – Sep 5, 2008

Subsystems (2)
lore
Share & tools
lore

Avi Kivity

author
#0 lore raw

Running an idle Windows VM on Linux 2.6.26+ with kvm, one sees high values for the kvm process in top (30%-70% cpu), where one would normally expect 0%-1%. Surprisingly, the per-cpu system counters show almost 100% idle, leading me to believe this is an accounting error and that the process does not actually consume this much cpu.

I bisected this to a scheduler change, namely

commit 3e51f33fcc7f55e6df25d15b55ed10c8b4da84cd

Author: Peter Zijlstra <[email protected]>
Date:   Sat May 3 18:29:28 2008 +0200

sched: add optional support for CONFIG_HAVE_UNSTABLE_SCHED_CLOCK

this replaces the rq->clock stuff (and possibly cpu_clock()).

- architectures that have an 'imperfect' hardware clock can set CONFIG_HAVE_UNSTABLE_SCHED_CLOCK

- the 'jiffie' window might be superfulous when we update tick_gtod before the __update_sched_clock() call in sched_clock_tick()

- cpu_clock() might be implemented as:

sched_clock_cpu(smp_processor_id())

if the accuracy proves good enough - how far can TSC drift in a single jiffie when considering the filtering and idle hooks?

[ [email protected]: various fixes and cleanups ]

Which is a bit too complex for me to work out.

Further information:
- the kvm thread which has the incorrect counter is the one that actually executes guest code
- this thread mostly sleeps in schedule(), as one would expect
- it is periodically woken up by a timer; perhaps the problem is that the process is sampled using the same timer, so it always shows as running (though I'd expect it to report 100% cpu in that case).

Any help will be appreciated (or provided).

Signature · 1 line
error compiling committee.c: too many arguments to function
#1 lore raw
Quoted 5 lines · Avi Kivity

Running an idle Windows VM on Linux 2.6.26+ with kvm, one sees high values for the kvm process in top (30%-70% cpu), where one would normally expect 0%-1%. Surprisingly, the per-cpu system counters show almost 100% idle, leading me to believe this is an accounting error and that the process does not actually consume this much cpu.

Busted process accounting - This looks the same as
http://bugzilla.kernel.org/show_bug.cgi?id=11209 . Please verify. Peter's patch in latest git stops showing "incorrect looking" CPU usage but at least the process times are still wrong, horribly.
In fact the CPU usage thing in -rc5 is likely also incorrect but I need to analyze that bit a little more.

Quoted 1 line

From Today's Git -

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND

12961 parag 20 0 83000 8908 6628 R 0 0.1 5124415h npviewer.bin

Quoted 17 lines

I bisected this to a scheduler change, namely

commit 3e51f33fcc7f55e6df25d15b55ed10c8b4da84cd

Author: Peter Zijlstra <[email protected]>
Date:   Sat May 3 18:29:28 2008 +0200

sched: add optional support for CONFIG_HAVE_UNSTABLE_SCHED_CLOCK
this replaces the rq->clock stuff (and possibly cpu_clock()).
- architectures that have an 'imperfect' hardware clock can set CONFIG_HAVE_UNSTABLE_SCHED_CLOCK
- the 'jiffie' window might be superfulous when we update tick_gtod before the __update_sched_clock() call in sched_clock_tick()
- cpu_clock() might be implemented as:
sched_clock_cpu(smp_processor_id())
if the accuracy proves good enough - how far can TSC drift in a
single jiffie when considering the filtering and idle hooks?

Quoted 3 lines
[ [email protected]: various fixes and cleanups ]

That patch sounds like it had open questions? Really giving this is a long standing bad regression, all the offending patches should be reverted in absence of a fix, no?

Parag

author
#2 lore raw
Quoted 17 lines · Parag Warudkar
Quoted 6 lines · Avi Kivity

Running an idle Windows VM on Linux 2.6.26+ with kvm, one sees high values for the kvm process in top (30%-70% cpu), where one would normally expect 0%-1%. Surprisingly, the per-cpu system counters show almost 100% idle, leading me to believe this is an accounting error and that the process does not actually consume this much cpu.

Busted process accounting - This looks the same as
http://bugzilla.kernel.org/show_bug.cgi?id=11209 . Please verify. Peter's patch in latest git stops showing "incorrect looking" CPU usage but at least the process times are still wrong, horribly.
In fact the CPU usage thing in -rc5 is likely also incorrect but I need to analyze that bit a little more.

Quoted 7 lines

From Today's Git -

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND

12961 parag 20 0 83000 8908 6628 R 0 0.1 5124415h npviewer.bin

Yes, it looks very similar. In my tests, %CPU is consistent with TIME; it's just not consistent with what's actually happening and with the global statistics.

Signature · 1 line
error compiling committee.c: too many arguments to function
#3 lore raw

PATCH 1/1 sched_clock: fix NOHZ interaction

In reply to Avi Kivity

Avi, the below fixes it for me..

---
Subject: sched_clock: fix NOHZ interaction
From: Peter Zijlstra <[email protected]>
Date: Mon Sep 01 16:44:23 CEST 2008

If HLT stops the TSC, we'll fail to account idle time, thereby inflating the actual process times. Fix this by re-calibrating the clock against GTOD when leaving nohz mode.

---
 kernel/time/tick-sched.c |    3 +++
 1 file changed, 3 insertions(+)
kernel/time/tick-sched.c +3 -0
Index: linux-2.6/kernel/time/tick-sched.c
===================================================================
@@ -162,6 +162,8 @@ void tick_nohz_stop_idle(int cpu)
 		ts->idle_lastupdate = now;
 		ts->idle_sleeptime = ktime_add(ts->idle_sleeptime, delta);
 		ts->idle_active = 0;
+
+		sched_clock_idle_wakeup_event(0);
 	}
 }
 
@@ -177,6 +179,7 @@ static ktime_t tick_nohz_start_idle(stru
 	}
 	ts->idle_entrytime = now;
 	ts->idle_active = 1;
+	sched_clock_idle_sleep_event();
 	return now;
 }
 
author
#4 lore raw

Re: [PATCH] sched_clock: fix NOHZ interaction

Quoted 2 lines · Peter Zijlstra

Avi, the below fixes it for me..

For me too. Thanks!

Signature · 1 line
error compiling committee.c: too many arguments to function
Applied
#5 lore raw

Re: [PATCH] sched_clock: fix NOHZ interaction

Quoted 5 lines · Avi Kivity
Quoted 2 lines · Peter Zijlstra

Avi, the below fixes it for me..

For me too. Thanks!

applied to tip/sched/urgent - thanks!

Ingo