Re: Interesting interaction between lguest and CFS

From: Ingo Molnar
Date: Tue Jun 05 2007 - 03:19:28 EST



* Matt Mackall <mpm@xxxxxxxxxxx> wrote:

> sleep_max : 57476665627
> block_max : 18014060106626075

hm, this block_max looks a bit suspect, it's 003fffb1359e341b. Does your
box make any use of cpufreq? (what CPU is it?)

> strace -f doesn't kill the latency, here's an strace:
>
> 24936 13:39:44.469329 rt_sigprocmask(SIG_BLOCK, [USR1], NULL, 8) = 0
> 24936 13:39:44.469572 select(4, [0 3], NULL, NULL, {0, 0}) = 0 (Timeout)
> 24936 13:39:44.469677 rt_sigprocmask(SIG_UNBLOCK, [USR1], NULL, 8) = 0
> 24936 13:39:44.469765 read(7, 0xbfe6c010, 8) = -1 EINTR (Interrupted system call)
> 24936 13:39:48.699490 --- SIGUSR1 (User defined signal 1) @ 0 (0) ---

hm, this indeed implicates some wakeup problem. lguest task 24936's
relevant stats are:

block_start : 0
sleep_max : 21492554
block_max : 27044576
exec_max : 4008057
wait_max : 1253670288

the wait_max means it was delayed on the runqueue for 1.2 seconds. Could
you try to get a /proc/sched_debug snapshot done exactly during the
'delay' window - it's 4 seconds so you should in theory be able to
trigger it by doing something like:

sleep 3; cat /proc/sched_debug > sched_debug.txt

Click into the lguest window and trigger the delay.

Ingo
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/