User-mode Linux kernel port

On Tue, Oct 16, 2007 at 10:36:39PM -0400, Hrishikesh wrote:
> When running powertop, I notice that there is a dramatic drop in C3 state
> residency when running the patched kernel. This happens when you run a
> patched kernel but without the NO_HZ and HR timers options disabled. C3
> state residency drops from about 90% to 50% when the UML kernel is idle.
> This does not happen when the tickless option _is_ enabled.

Which kernel is the patched kernel, the host or UML?

Whichever kernel this is, I take it that this is a bad thing?

				Jeff

-- 
Work email - jdike at linux dot intel dot com

Jeff,
This is when I patch the UML kernel with the NO_HZ patches that you put up
last month.. on 2.6.23-rc6-mm1. Powertop is running on the host kernel and
tells you which process wake up the processor from idle the most and also
which the offending function is (in this case, it shows it to be
do_nanosleep()). Yup this is a bad thing from the power consumption
viewpoint and you would like the processor to be in higher C-states most of
the time.
Regards,
Hrishikesh

On 10/17/07, Jeff Dike <jdike@...> wrote:
>
> On Tue, Oct 16, 2007 at 10:36:39PM -0400, Hrishikesh wrote:
> > When running powertop, I notice that there is a dramatic drop in C3
> state
> > residency when running the patched kernel. This happens when you run a
> > patched kernel but without the NO_HZ and HR timers options disabled. C3
> > state residency drops from about 90% to 50% when the UML kernel is idle.
> > This does not happen when the tickless option _is_ enabled.
>
> Which kernel is the patched kernel, the host or UML?
>
> Whichever kernel this is, I take it that this is a bad thing?
>
>                                 Jeff
>
> --
> Work email - jdike at linux dot intel dot com
>

On Wed, Oct 17, 2007 at 12:16:18PM -0400, Hrishikesh wrote:
> This is when I patch the UML kernel with the NO_HZ patches that you put up
> last month.. on 2.6.23-rc6-mm1. 

Hmmm, that's exactly the opposite of what I would expect.  A idle
non-NO_HZ UML should be waking up 100 times/sec, while I see much
longer sleeps with an idle NO_HZ UML, up to 2-3 seconds.

Can you strace both cases and see how often the NO_HZ UML is waking up
compared to the non-NO_HZ one?

				Jeff

-- 
Work email - jdike at linux dot intel dot com

Ok the straces do seem to tell the story; they follow below:

for the case where is the kernel is patched and NO_HZ enabled,

waitpid(3989, [{WIFSTOPPED(s) && WSTOPSIG(s) == 133}], WSTOPPED) = 3989
gettimeofday({1192649136, 409637}, NULL) = 0
gettimeofday({1192649136, 409698}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 90000}}, NULL) =
0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 91986}}) = 0
nanosleep({0, 91986000}, {0, 91986000}) = 0
gettimeofday({1192649136, 502142}, NULL) = 0
gettimeofday({1192649136, 502201}, NULL) = 0
gettimeofday({1192649136, 502260}, NULL) = 0
gettimeofday({1192649136, 502352}, NULL) = 0
gettimeofday({1192649136, 502410}, NULL) = 0
gettimeofday({1192649136, 502481}, NULL) = 0
gettimeofday({1192649136, 502578}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 10000}}, NULL) =
0
gettimeofday({1192649136, 502750}, NULL) = 0
gettimeofday({1192649136, 502814}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 290000}}, NULL)
= 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 291955}}) = 0
nanosleep({0, 291955000}, {0, 291955000}) = 0
gettimeofday({1192649136, 795308}, NULL) = 0
gettimeofday({1192649136, 795368}, NULL) = 0
gettimeofday({1192649136, 795427}, NULL) = 0
gettimeofday({1192649136, 795486}, NULL) = 0
gettimeofday({1192649136, 795544}, NULL) = 0
gettimeofday({1192649136, 795616}, NULL) = 0
gettimeofday({1192649136, 795675}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 10000}}, NULL) =
0
gettimeofday({1192649136, 795815}, NULL) = 0
gettimeofday({1192649136, 795876}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={1, 700000}}, NULL)
= 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={1, 701741}}) = 0
nanosleep({1, 701741000}, {1, 701741000}) = 0


for the case where the kernel is patched, but NO_HZ is __not__ enabled,
there is a do_nanosleep() every 100 or so us.

setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 436325}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 436434}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 436532}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 436629}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 436725}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 436822}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 436919}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0
gettimeofday({1192648953, 437015}, NULL) = 0
setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
{it_interval={0, 0}, it_value={0, 0}}) = 0
nanosleep({0, 0}, {0, 0})               = 0

Regards,
Hrishikesh


On 10/17/07, Jeff Dike <jdike@...> wrote:
>
> On Wed, Oct 17, 2007 at 12:16:18PM -0400, Hrishikesh wrote:
> > This is when I patch the UML kernel with the NO_HZ patches that you put
> up
> > last month.. on 2.6.23-rc6-mm1.
>
> Hmmm, that's exactly the opposite of what I would expect.  A idle
> non-NO_HZ UML should be waking up 100 times/sec, while I see much
> longer sleeps with an idle NO_HZ UML, up to 2-3 seconds.
>
> Can you strace both cases and see how often the NO_HZ UML is waking up
> compared to the non-NO_HZ one?
>
>                                 Jeff
>
> --
> Work email - jdike at linux dot intel dot com
>

On Wed, Oct 17, 2007 at 03:43:01PM -0400, Hrishikesh wrote:
> Ok the straces do seem to tell the story; they follow below:

Except they're telling the wrong story:

> for the case where is the kernel is patched and NO_HZ enabled,

> {it_interval={0, 0}, it_value={0, 91986}}) = 0
> nanosleep({0, 91986000}, {0, 91986000}) = 0

.1 sec

> {it_interval={0, 0}, it_value={0, 291955}}) = 0
> nanosleep({0, 291955000}, {0, 291955000}) = 0

.3 sec

> {it_interval={0, 0}, it_value={1, 701741}}) = 0
> nanosleep({1, 701741000}, {1, 701741000}) = 0

1.7 sec

> for the case where the kernel is patched, but NO_HZ is __not__ enabled,
> there is a do_nanosleep() every 100 or so us.
> 
> setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
> {it_interval={0, 0}, it_value={0, 0}}) = 0
> nanosleep({0, 0}, {0, 0})               = 0

This actually looks very broken - it's sleeping for no time,
practically a busy-loop.  And this case is keeping the host in C3
longer than the second-long sleeps in the first case?

				Jeff

-- 
Work email - jdike at linux dot intel dot com

No, I think I haven't been clear enough. The story is right :-) When it is
"busy-looping" like in the second case is when the C3 residency comes down,
as expected. Like you said, it looks broken, and has to be fixed.
Regards,
Hrishikesh

On 10/17/07, Jeff Dike <jdike@...> wrote:
>
> On Wed, Oct 17, 2007 at 03:43:01PM -0400, Hrishikesh wrote:
> > Ok the straces do seem to tell the story; they follow below:
>
> Except they're telling the wrong story:
>
> > for the case where is the kernel is patched and NO_HZ enabled,
>
> > {it_interval={0, 0}, it_value={0, 91986}}) = 0
> > nanosleep({0, 91986000}, {0, 91986000}) = 0
>
> .1 sec
>
> > {it_interval={0, 0}, it_value={0, 291955}}) = 0
> > nanosleep({0, 291955000}, {0, 291955000}) = 0
>
> .3 sec
>
> > {it_interval={0, 0}, it_value={1, 701741}}) = 0
> > nanosleep({1, 701741000}, {1, 701741000}) = 0
>
> 1.7 sec
>
> > for the case where the kernel is patched, but NO_HZ is __not__ enabled,
> > there is a do_nanosleep() every 100 or so us.
> >
> > setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
> > {it_interval={0, 0}, it_value={0, 0}}) = 0
> > nanosleep({0, 0}, {0, 0})               = 0
>
> This actually looks very broken - it's sleeping for no time,
> practically a busy-loop.  And this case is keeping the host in C3
> longer than the second-long sleeps in the first case?
>
>                                 Jeff
>
> --
> Work email - jdike at linux dot intel dot com
>

Jeff,
>From looking at the straces, I think it is breaking because in
default_idle(), when we call disable_timer(), it always returns 0 which
means that idle_sleep() and hence nanosleep() are being called with "0
nsecs". This naturally causes the almost busy-loop. I can't quite put my
finger on where it is happening, but when CONFIG_NO_HZ is not enabled, the
timer_one_shot() is not being called at all. This means that the timer is
never set and hence returns 0 as old value whenever setitimer is called
later.
Hope that helps,
Hrishikesh

On 10/17/07, Jeff Dike <jdike@...> wrote:
>
> On Wed, Oct 17, 2007 at 03:43:01PM -0400, Hrishikesh wrote:
> > Ok the straces do seem to tell the story; they follow below:
>
> Except they're telling the wrong story:
>
> > for the case where is the kernel is patched and NO_HZ enabled,
>
> > {it_interval={0, 0}, it_value={0, 91986}}) = 0
> > nanosleep({0, 91986000}, {0, 91986000}) = 0
>
> .1 sec
>
> > {it_interval={0, 0}, it_value={0, 291955}}) = 0
> > nanosleep({0, 291955000}, {0, 291955000}) = 0
>
> .3 sec
>
> > {it_interval={0, 0}, it_value={1, 701741}}) = 0
> > nanosleep({1, 701741000}, {1, 701741000}) = 0
>
> 1.7 sec
>
> > for the case where the kernel is patched, but NO_HZ is __not__ enabled,
> > there is a do_nanosleep() every 100 or so us.
> >
> > setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
> > {it_interval={0, 0}, it_value={0, 0}}) = 0
> > nanosleep({0, 0}, {0, 0})               = 0
>
> This actually looks very broken - it's sleeping for no time,
> practically a busy-loop.  And this case is keeping the host in C3
> longer than the second-long sleeps in the first case?
>
>                                 Jeff
>
> --
> Work email - jdike at linux dot intel dot com
>

On Wed, Oct 17, 2007 at 07:29:47PM -0400, Hrishikesh wrote:
> No, I think I haven't been clear enough. The story is right :-) When it is
> "busy-looping" like in the second case is when the C3 residency comes down,
> as expected. Like you said, it looks broken, and has to be fixed.

Yes, your original post was a bit confusing:

> This happens when you run a
> patched kernel but without the NO_HZ and HR timers options disabled.

To my highly logical mind, that double-negative says that you saw the
C3 drop with NO_HZ and hrtimers enabled.

There was also this, which I paid insufficient attention to:

> This does not happen when the tickless option _is_ enabled.

However, it does look like the tickless support induces UML into a
busy loop when NO_HZ is disabled.

BTW, can you measure C3 time with a before-NO_HZ UML, so we can see
that NO_HZ has some sort of benefit on power consumption?

				Jeff

-- 
Work email - jdike at linux dot intel dot com

Hey Jeff,
Yes, that double negative was a slipup. I did get some numbers out and they
look pretty good. I ran upto 5 instances of UML simultaneously and in the
tickful case, each instance adds roughly about 100 wakeups per second. So
after 5 instances, C3 residency comes down to about 95% when all the
instances are simply idling. With NO_HZ applied, the change is minimal with
C3 residency still approximately 98%. UML is not even among the top three of
the bad-list of wakers-up :-)
Hrishikesh

On 10/18/07, Jeff Dike <jdike@...> wrote:
>
> On Wed, Oct 17, 2007 at 07:29:47PM -0400, Hrishikesh wrote:
> > No, I think I haven't been clear enough. The story is right :-) When it
> is
> > "busy-looping" like in the second case is when the C3 residency comes
> down,
> > as expected. Like you said, it looks broken, and has to be fixed.
>
> Yes, your original post was a bit confusing:
>
> > This happens when you run a
> > patched kernel but without the NO_HZ and HR timers options disabled.
>
> To my highly logical mind, that double-negative says that you saw the
> C3 drop with NO_HZ and hrtimers enabled.
>
> There was also this, which I paid insufficient attention to:
>
> > This does not happen when the tickless option _is_ enabled.
>
> However, it does look like the tickless support induces UML into a
> busy loop when NO_HZ is disabled.
>
> BTW, can you measure C3 time with a before-NO_HZ UML, so we can see
> that NO_HZ has some sort of benefit on power consumption?
>
>                                 Jeff
>
> --
> Work email - jdike at linux dot intel dot com
>

On Tue, Oct 23, 2007 at 04:21:03PM -0300, Hrishikesh wrote:
> Yes, that double negative was a slipup. I did get some numbers out and they
> look pretty good. I ran upto 5 instances of UML simultaneously and in the
> tickful case, each instance adds roughly about 100 wakeups per second. 

HZ == 100, so that makes sense.

> So
> after 5 instances, C3 residency comes down to about 95% when all the
> instances are simply idling. With NO_HZ applied, the change is minimal with
> C3 residency still approximately 98%. UML is not even among the top three of
> the bad-list of wakers-up :-)

Cool.  I'm suprised that 500 wakeups/sec only brings you down < 5%.

So, things are good, except I need to figure out the !NO_HZ busy loop.

				Jeff

-- 
Work email - jdike at linux dot intel dot com

On 10/23/07, Jeff Dike <jdike@...> wrote:
>
> On Tue, Oct 23, 2007 at 04:21:03PM -0300, Hrishikesh wrote:
> >> Yes, that double negative was a slipup. I did get some numbers out and
> they
> >> look pretty good. I ran upto 5 instances of UML simultaneously and in
> the
> >> tickful case, each instance adds roughly about 100 wakeups per second.
>
> > HZ == 100, so that makes sense.


>> So
> >> after 5 instances, C3 residency comes down to about 95% when all the
> >> instances are simply idling. With NO_HZ applied, the change is minimal
> with
> >> C3 residency still approximately 98%. UML is not even among the top
> three of
> >> the bad-list of wakers-up :-)
>
> > Cool.  I'm suprised that 500 wakeups/sec only brings you down < 5%.


Hmm,  powertop shows  500 wakeups  on  part of UML, but the actual number of
wakeups for the processor is much  lesser..  Guess there is  some  batching
that  is happening.

> So, things are good, except I need to figure out the !NO_HZ busy loop.
> >
> >                                Jeff
> >
> > --
> > Work email - jdike at linux dot intel dot com


Hrishi

On Wed, Oct 17, 2007 at 03:43:01PM -0400, Hrishikesh wrote:
> for the case where the kernel is patched, but NO_HZ is __not__ enabled,
> there is a do_nanosleep() every 100 or so us.
> 
> setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}},
> {it_interval={0, 0}, it_value={0, 0}}) = 0
> nanosleep({0, 0}, {0, 0})               = 0

Can you reproduce this with current mainline?  I can't:

1194371604.120203 setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 10000}}, NULL) = 0
1194371604.120256 setitimer(ITIMER_VIRTUAL, {it_interval={0, 0}, it_value={0, 0}}, {it_interval={0, 0}, it_value={0, 11998}}) = 0
1194371604.120306 nanosleep({0, 11998000}, {0, 11998000}) = 0

It's correctly reading the current alarm and sleeping for that long.
It could be more efficient, but this isn't a busy loop.

				Jeff

-- 
Work email - jdike at linux dot intel dot com