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

Re: 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

Re: 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

Re: 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

Re: 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.

Re: 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

Re: 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.

Re: 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

Re: console_cpu_notify can cause scheduling BUG during CPU hotplug

[Shen Canquan]

Hi Mike ,
     I found the previous email about "console_cpu_notify can cause scheduling BUG during CPU hotplug" .  
Now I have the same problem . My test enviroment is the following:
I am in xen virtualization environment. and I install the lastest stable kernel(linux 3.0.3) in domU . When I use the 
xm vcpu-set <n> to test vcpu add and remove function . and when I run the above command more than 100 times. 
and use the top tool to look the cpu info. It will hang of linux.
   When I dump the core of linux kernel and analyse it , I found the reason is the same of this email.
    Can you tell me the progress of this problem. Thanks.

---------
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 

Re: console_cpu_notify can cause scheduling BUG during CPU hotplug

[canquan.shen]

Hi mbohan and petkovbb,
    The dead lock scenario is the following:
    In my test enviroment. It has two cpus. cpu#0 just complete to run 
the following stack(in top tool).
  #0 [ffff880079223b68] schedule at ffffffff813acda2
  #1 [ffff880079223cb0] __cond_resched at ffffffff8104a3f5
  #2 [ffff880079223cd0] _cond_resched at ffffffff813ad56d
  #3 [ffff880079223ce0] console_conditional_schedule at ffffffff813ad5cd
  #4 [ffff880079223cf0] do_con_write at ffffffff8127ed24
  #5 [ffff880079223de0] con_write at ffffffff81281109
  #6 [ffff880079223e00] n_tty_write at ffffffff8126bd40
  #7 [ffff880079223ea0] tty_write at ffffffff81268530
  #8 [ffff880079223f10] vfs_write at ffffffff811124db
  #9 [ffff880079223f40] sys_write at ffffffff81112680
#10 [ffff880079223f80] system_call_fastpath at ffffffff813b5812
   It has locked the console_sem in console_lock function(do_con_write 
call the console_lock). and it does not unlock the  console_sem because 
it run sheduler function (because it check need_schedule flag) before unlock
   And then cpu remove has happened. all cpu execute the 
stop_machine_cpu_stop in cpu_stopper_thread. In the 
stop_machine_cpu_stop function. cpu#0 is warting cpu#1 run compelte, but 
cpu#1 has schedule because it wait for console_sem lock. please see the 
following stack.

  #0 [ffff88007afd3ae0] schedule at ffffffff813acda2
  #1 [ffff88007afd3c28] schedule_timeout at ffffffff813ad785
  #2 [ffff88007afd3cc8] __down at ffffffff813ae621
  #3 [ffff88007afd3d18] down at ffffffff81072587
  #4 [ffff88007afd3d38] console_lock at ffffffff81051977
  #5 [ffff88007afd3d48] console_cpu_notify at ffffffff813a7650
  #6 [ffff88007afd3d58] notifier_call_chain at ffffffff813b2cdf
  #7 [ffff88007afd3d98] __raw_notifier_call_chain at ffffffff810726d9
  #8 [ffff88007afd3da8] take_cpu_down at ffffffff81395a75
  #9 [ffff88007afd3dc8] stop_machine_cpu_stop at ffffffff8109df7e
#10 [ffff88007afd3df8] cpu_stopper_thread at ffffffff8109de1d
#11 [ffff88007afd3ee8] kthread at ffffffff8106cff6
#12 [ffff88007afd3f48] kernel_thread_helper at ffffffff813b6944

  However the console_sem lock is wait for cpu#0 to unlock. it cause 
dead lock.

--
canquan.shen


On 2011/8/30 16:37, Shen Canquan wrote:
> Hi Mike ,
>       I found the previous email about "console_cpu_notify can cause scheduling BUG during CPU hotplug" .
> Now I have the same problem . My test enviroment is the following:
> I am in xen virtualization environment. and I install the lastest stable kernel(linux 3.0.3) in domU . When I use the
> xm vcpu-set<n>  to test vcpu add and remove function . and when I run the above command more than 100 times.
> and use the top tool to look the cpu info. It will hang of linux.
>     When I dump the core of linux kernel and analyse it , I found the reason is the same of this email.
>      Can you tell me the progress of this problem. Thanks.
>
> ---------
> 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
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/
>
> .
>