Re: Profiling sleep times?

[Peter Zijlstra <peterz@infradead.org>]

On Mon, 2011-10-03 at 14:53 -0700, Arun Sharma wrote:
> On 10/3/11 1:17 PM, Peter Zijlstra wrote:
> > On Mon, 2011-10-03 at 12:38 -0700, Arun Sharma wrote:
> >>                           trace_sched_stat_sleep(tsk, delta);
> >
> > That one should be accessible as a tracepoint and will add delay to
> > count on each occurrence.
> 
> Right - the tracepoint seems to work. Was looking for the user stack 
> trace as well. For eg:
> 
> # cat foo.c
> #include <unistd.h>
> #include <time.h>
> #include <sys/select.h>
> 
> main()
> {
>          struct timespec ts1;
>          struct timeval tv1;
>          int i;
> 
> 
>          for (i = 0; i < 1000; i++) {
>                  ts1.tv_sec = 0;
>                  ts1.tv_nsec = 1000000;
>                  nanosleep(&ts1, NULL);
> 
>                  tv1.tv_sec = 0;
>                  tv1.tv_usec = 4000;
>                  select(0, NULL, NULL, NULL, &tv1);
>          }
> }
> 
> I want something that gives me 4 times as many samples on select() as 
> nanosleep().
> 
> perf record -g -e sched:sched_stat_sleep -- ./foo
> 
> doesn't seem to do it. Additionally, if I have a burn_1us_cpu() loop in 
> there, I'd expect to see as many samples as nanosleep() in the wall 
> clock profile.

Would you per-chance be suffering from this:

http://lkml.kernel.org/r/1317052535-1765247-2-git-send-email-avagin@openvz.org