Re: Interesting interaction between lguest and CFS

[Ingo Molnar <mingo@elte.hu>]

* Matt Mackall <mpm@selenic.com> 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