console_cpu_notify can cause scheduling BUG during CPU hotplug

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Michael Bohan]

Hi,

I've run into a crash scenario during CPU hotplug on ARM/MSM where we 
BUG() due to a schedule while atomic in v2.6.38-rc6. The issue appears 
to be that the console cpu notifier can block on a semaphore during 
cpu_stopper_thread's atomic code path. Preemption is explicitly disabled 
in cpu_stopper_thread.

The suspected path was added with this commit:

commit 034260d6779087431a8b2f67589c68b919299e5c
Author: Kevin Cernekee <cernekee@gmail.com>
Date:   Thu Jun 3 22:11:25 2010 -0700

     printk: fix delayed messages from CPU hotplug events

I was curious if this scenario was accounted for in the design of the 
console CPU notifier. One workaround for this problem is to remove 
CPU_DEAD from the possible actions in console_cpu_notify(). In fact, 
v1-v4 of the patch above did not have CPU_DEAD, CPU_DYING or 
CPU_DOWN_FAILED in the list of actions. I wasn't able to track down why 
the other cases were added in the final patch.

Crash log:

<3>[   21.408237] BUG: scheduling while atomic: migration/1/371/0x00000002
<4>[   21.408247] Modules linked in:
<4>[   21.408286] [<c0050e40>] (unwind_backtrace+0x0/0x128) from 
[<c056748c>] (schedule+0x9c/0x6c4)
<4>[   21.408303] [<c056748c>] (schedule+0x9c/0x6c4) from [<c0567d04>] 
(schedule_timeout+0x1c/0x208)
<4>[   21.408319] [<c0567d04>] (schedule_timeout+0x1c/0x208) from 
[<c0568fac>] (__down+0x68/0x98)
<4>[   21.408337] [<c0568fac>] (__down+0x68/0x98) from [<c00d844c>] 
(down+0x2c/0x3c)
<4>[   21.408354] [<c00d844c>] (down+0x2c/0x3c) from [<c00bb23c>] 
(console_lock+0x38/0x60)
<4>[   21.408377] [<c00bb23c>] (console_lock+0x38/0x60) from 
[<c0564c80>] (console_cpu_notify+0x20/0x2c)
<4>[   21.408394] [<c0564c80>] (console_cpu_notify+0x20/0x2c) from 
[<c00d8488>] (notifier_call_chain+0x2c/0x70)
<4>[   21.408410] [<c00d8488>] (notifier_call_chain+0x2c/0x70) from 
[<c00bc318>] (__cpu_notify+0x24/0x3c)
<4>[   21.408425] [<c00bc318>] (__cpu_notify+0x24/0x3c) from 
[<c0552e7c>] (take_cpu_down+0x2c/0x34)
<4>[   21.408444] [<c0552e7c>] (take_cpu_down+0x2c/0x34) from 
[<c00f34d4>] (stop_machine_cpu_stop+0xc0/0x11c)
<4>[   21.408462] [<c00f34d4>] (stop_machine_cpu_stop+0xc0/0x11c) from 
[<c00f337c>] (cpu_stopper_thread+0xc8/0x160)
<4>[   21.408482] [<c00f337c>] (cpu_stopper_thread+0xc8/0x160) from 
[<c00d30b0>] (kthread+0x80/0x88)
<4>[   21.408498] [<c00d30b0>] (kthread+0x80/0x88) from [<c004b6a0>] 
(kernel_thread_exit+0x0/0x8)

Thanks,
Mike

-- 
Employee of Qualcomm Innovation Center, Inc.
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Kevin Cernekee]

On Mon, Apr 25, 2011 at 4:33 PM, Michael Bohan <mbohan@codeaurora.org> wrote:
> I was curious if this scenario was accounted for in the design of the
> console CPU notifier. One workaround for this problem is to remove CPU_DEAD
> from the possible actions in console_cpu_notify(). In fact, v1-v4 of the
> patch above did not have CPU_DEAD, CPU_DYING or CPU_DOWN_FAILED in the list
> of actions. I wasn't able to track down why the other cases were added in
> the final patch.

Here is the background information on the CPU_{DEAD,DYING,DOWN_FAILED} cases:

http://lkml.org/lkml/2010/6/29/65

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Santosh Shilimkar]

On 4/26/2011 5:48 AM, Kevin Cernekee wrote:
> On Mon, Apr 25, 2011 at 4:33 PM, Michael Bohan<mbohan@codeaurora.org>  wrote:
>> I was curious if this scenario was accounted for in the design of the
>> console CPU notifier. One workaround for this problem is to remove CPU_DEAD
>> from the possible actions in console_cpu_notify(). In fact, v1-v4 of the
>> patch above did not have CPU_DEAD, CPU_DYING or CPU_DOWN_FAILED in the list
>> of actions. I wasn't able to track down why the other cases were added in
>> the final patch.
>
> Here is the background information on the CPU_{DEAD,DYING,DOWN_FAILED} cases:
>
> http://lkml.org/lkml/2010/6/29/65
That's right.
May be the change log for commit '034260d67' would have been
bit more descriptive about the CPU hot-plug events.

Regards
Santosh

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Michael Bohan]

On 4/25/2011 10:58 PM, Santosh Shilimkar wrote:
> On 4/26/2011 5:48 AM, Kevin Cernekee wrote:
>> On Mon, Apr 25, 2011 at 4:33 PM, Michael Bohan<mbohan@codeaurora.org>
>> wrote:
>>> I was curious if this scenario was accounted for in the design of the
>>> console CPU notifier. One workaround for this problem is to remove
>>> CPU_DEAD
>>> from the possible actions in console_cpu_notify(). In fact, v1-v4 of the
>>> patch above did not have CPU_DEAD, CPU_DYING or CPU_DOWN_FAILED in
>>> the list
>>> of actions. I wasn't able to track down why the other cases were
>>> added in
>>> the final patch.
>>
>> Here is the background information on the CPU_{DEAD,DYING,DOWN_FAILED}
>> cases:
>>
>> http://lkml.org/lkml/2010/6/29/65
> That's right.
> May be the change log for commit '034260d67' would have been
> bit more descriptive about the CPU hot-plug events.

Thanks for the clarification. Now regarding the problem, it seems like 
we can't be taking a semaphore in that path. That is to say, we can't be 
calling console_lock from within stop_machine. A few options that come 
to mind:

-Use console_trylock and accept the possibility that the output is not 
guaranteed to be synchronous with the hotplug operation.
-Defer the console output emission (eg. workqueue) during hotplug.
-Hybrid of the two: if the console_trylock fails, then we defer the 
console output emission.

Any opinions? I can submit a patch if one of these approaches is reasonable.

Thanks,
Mike

-- 
Employee of Qualcomm Innovation Center, Inc.
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Borislav Petkov]

On Tue, Apr 26, 2011 at 02:06:28PM -0700, Michael Bohan wrote:
> On 4/25/2011 10:58 PM, Santosh Shilimkar wrote:
> >On 4/26/2011 5:48 AM, Kevin Cernekee wrote:
> >>On Mon, Apr 25, 2011 at 4:33 PM, Michael Bohan<mbohan@codeaurora.org>
> >>wrote:
> >>>I was curious if this scenario was accounted for in the design of the
> >>>console CPU notifier. One workaround for this problem is to remove
> >>>CPU_DEAD
> >>>from the possible actions in console_cpu_notify(). In fact, v1-v4 of the
> >>>patch above did not have CPU_DEAD, CPU_DYING or CPU_DOWN_FAILED in
> >>>the list
> >>>of actions. I wasn't able to track down why the other cases were
> >>>added in
> >>>the final patch.
> >>
> >>Here is the background information on the CPU_{DEAD,DYING,DOWN_FAILED}
> >>cases:
> >>
> >>http://lkml.org/lkml/2010/6/29/65
> >That's right.
> >May be the change log for commit '034260d67' would have been
> >bit more descriptive about the CPU hot-plug events.
> 
> Thanks for the clarification. Now regarding the problem, it seems
> like we can't be taking a semaphore in that path. That is to say, we
> can't be calling console_lock from within stop_machine. A few
> options that come to mind:
> 
> -Use console_trylock and accept the possibility that the output is
> not guaranteed to be synchronous with the hotplug operation.
> -Defer the console output emission (eg. workqueue) during hotplug.
> -Hybrid of the two: if the console_trylock fails, then we defer the
> console output emission.
> 
> Any opinions? I can submit a patch if one of these approaches is reasonable.

Great, whatever you guys come up with, we'd like to give it a run too.
We (AMD) hit the same issue in one of our tests but in our case we end
up in an endless loop of the state machine at stop_machine_cpu_stop()
since the core being offlined cannot ack the state transition to
STOPMACHINE_EXIT due to a similar reason.

One possible fix is dropping CPU_DYING from console_cpu_notify()
since it is called into by the offlining path in
kernel/cpu.c::take_cpu_down().

Thanks.

-- 
Regards/Gruss,
    Boris.

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Michael Bohan]

On 4/27/2011 12:38 AM, Borislav Petkov wrote:
> Great, whatever you guys come up with, we'd like to give it a run too.
> We (AMD) hit the same issue in one of our tests but in our case we end
> up in an endless loop of the state machine at stop_machine_cpu_stop()
> since the core being offlined cannot ack the state transition to
> STOPMACHINE_EXIT due to a similar reason.
>
> One possible fix is dropping CPU_DYING from console_cpu_notify()
> since it is called into by the offlining path in
> kernel/cpu.c::take_cpu_down().

This seems to be a different problem. Could you elaborate about why 
removing CPU_DYING from console_cpu_notify resolves your problem? What 
are other possible fixes?

In the failure case I witnessed, we're attempting to sleep in atomic 
mode, which is a clear violation caused by the addition of CPU_DYING. I 
haven't thoroughly investigated whether other actions in 
console_cpu_notify (eg. ONLINE, DEAD, DOWN_FAILED, UP_CANCELED) are in 
atomic mode violation as well.

Thanks,
Mike

-- 
Employee of Qualcomm Innovation Center, Inc.
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Borislav Petkov]

On Wed, Apr 27, 2011 at 03:12:19PM -0700, Michael Bohan wrote:
> On 4/27/2011 12:38 AM, Borislav Petkov wrote:
> >Great, whatever you guys come up with, we'd like to give it a run too.
> >We (AMD) hit the same issue in one of our tests but in our case we end
> >up in an endless loop of the state machine at stop_machine_cpu_stop()
> >since the core being offlined cannot ack the state transition to
> >STOPMACHINE_EXIT due to a similar reason.
> >
> >One possible fix is dropping CPU_DYING from console_cpu_notify()
> >since it is called into by the offlining path in
> >kernel/cpu.c::take_cpu_down().
> 
> This seems to be a different problem. Could you elaborate about why
> removing CPU_DYING from console_cpu_notify resolves your problem?

Ok, I have to admit, I haven't spent a whole lot of time debugging this
but here's what I know:

First of all, how we trigger this? Our crazy testers have a script that
takes cores off- and online in a random manner repeatedly and, if you go
to another tty and do 'dmesg' in the same time, you can be absolutely
sure that after a few times, you end up in the endless loop scenario
above.

Don't ask me why they do that - they're just crazy! :) But yeah,
even with a the test sequence as far fetched as this one, the kernel
shouldn't "freeze".

Wait... I'm looking at the code now and it looks like Tejun changed the
state machine implementation (3fc1f1e27a5b807791d72e5d992aa33b668a6626)
so we'll have to retest to see whether this still happens.

Can you trigger your crash with latest kernel too?

Thanks.

-- 
Regards/Gruss,
    Boris.

console_cpu_notify can cause scheduling BUG during CPU hotplug

[Michael Bohan]

On 4/30/2011 1:38 AM, Borislav Petkov wrote:
> On Wed, Apr 27, 2011 at 03:12:19PM -0700, Michael Bohan wrote:
>> On 4/27/2011 12:38 AM, Borislav Petkov wrote:
>>> Great, whatever you guys come up with, we'd like to give it a run too.
>>> We (AMD) hit the same issue in one of our tests but in our case we end
>>> up in an endless loop of the state machine at stop_machine_cpu_stop()
>>> since the core being offlined cannot ack the state transition to
>>> STOPMACHINE_EXIT due to a similar reason.
>>>
>>> One possible fix is dropping CPU_DYING from console_cpu_notify()
>>> since it is called into by the offlining path in
>>> kernel/cpu.c::take_cpu_down().
>>
>> This seems to be a different problem. Could you elaborate about why
>> removing CPU_DYING from console_cpu_notify resolves your problem?
>
> Ok, I have to admit, I haven't spent a whole lot of time debugging this
> but here's what I know:
>
> First of all, how we trigger this? Our crazy testers have a script that
> takes cores off- and online in a random manner repeatedly and, if you go
> to another tty and do 'dmesg' in the same time, you can be absolutely
> sure that after a few times, you end up in the endless loop scenario
> above.

Our test scenario is similar to this. In the crash I reported, there 
needs to be contention for the console semaphore to trigger the BUG().

I get the impression that this sort of scenario is not tested 
extensively in Linux. Otherwise I think others would have reported the 
BUG I hit.

> Wait... I'm looking at the code now and it looks like Tejun changed the
> state machine implementation (3fc1f1e27a5b807791d72e5d992aa33b668a6626)
> so we'll have to retest to see whether this still happens.

Tejen's change (3fc1f1e27a5b807791d72e5d992aa33b668a6626) was first in 
v2.6.35, so it looks like you're using a pretty old kernel. Kevin's 
change (034260d6779087431a8b2f67589c68b919299e5c) was not in until 
v2.6.36, so therefore I'm a bit confused what code base you're running.

You mentioned before that one possible fix is dropping CPU_DYING from 
console_cpu_notify, but based on what you said, it doesn't seem like 
your kernel should be new enough have this functionality. Did you 
cherry-pick Kevin's change on top of an older code base? If so, that is 
likely dangerous.

Please keep me in loop with your findings on a more recent kernel.

 > Can you trigger your crash with latest kernel too?

The latest I've tested is v2.6.38, but the code related to blocking on 
the console semaphore with preemption disabled does not appear changed 
on the most recent code base.

Thanks,
Mike

-- 
Employee of Qualcomm Innovation Center, Inc.
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum