Re: console: lockup on boot

From: Sasha Levin
Date: Wed Jun 11 2014 - 10:56:14 EST


On 06/10/2014 11:59 AM, Peter Hurley wrote:
> On 06/06/2014 03:05 PM, Sasha Levin wrote:
>> On 05/30/2014 10:07 AM, Jan Kara wrote:
>>> On Fri 30-05-14 09:58:14, Peter Hurley wrote:
>>>>> On 05/30/2014 09:11 AM, Sasha Levin wrote:
>>>>>>> Hi all,
>>>>>>>
>>>>>>> I sometime see lockups when booting my KVM guest with the latest -next kernel,
>>>>>>> it basically hangs right when it should start 'init', and after a while I get
>>>>>>> the following spew:
>>>>>>>
>>>>>>> [ 30.790833] BUG: spinlock lockup suspected on CPU#1, swapper/1/0
>>>>>
>>>>> Maybe related to this report: https://lkml.org/lkml/2014/5/30/26
>>>>> from Jet Chen which was bisected to
>>>>>
>>>>> commit bafe980f5afc7ccc693fd8c81c8aa5a02fbb5ae0
>>>>> Author: Jan Kara <jack@xxxxxxx>
>>>>> AuthorDate: Thu May 22 10:43:35 2014 +1000
>>>>> Commit: Stephen Rothwell <sfr@xxxxxxxxxxxxxxxx>
>>>>> CommitDate: Thu May 22 10:43:35 2014 +1000
>>>>>
>>>>> printk: enable interrupts before calling console_trylock_for_printk()
>>>>> We need interrupts disabled when calling console_trylock_for_printk() only
>>>>> so that cpu id we pass to can_use_console() remains valid (for other
>>>>> things console_sem provides all the exclusion we need and deadlocks on
>>>>> console_sem due to interrupts are impossible because we use
>>>>> down_trylock()). However if we are rescheduled, we are guaranteed to run
>>>>> on an online cpu so we can easily just get the cpu id in
>>>>> can_use_console().
>>>>> We can lose a bit of performance when we enable interrupts in
>>>>> vprintk_emit() and then disable them again in console_unlock() but OTOH it
>>>>> can somewhat reduce interrupt latency caused by console_unlock()
>>>>> especially since later in the patch series we will want to spin on
>>>>> console_sem in console_trylock_for_printk().
>>>>> Signed-off-by: Jan Kara <jack@xxxxxxx>
>>>>> Signed-off-by: Andrew Morton <akpm@xxxxxxxxxxxxxxxxxxxx>
>>>>>
>>>>> ?
>>> Yeah, very likely. I think I see the problem, I'll send the fix shortly.
>>
>> Hi Jan,
>>
>> It seems that the issue I'm seeing is different from the "[prink] BUG: spinlock
>> lockup suspected on CPU#0, swapper/1".
>>
>> Is there anything else I could try here? The issue is very common during testing.
>
> Sasha,
>
> Is this bisectable? Maybe that's the best way forward here.

I've ran a bisection again and ended up at the same commit as Jet Chen (the commit
unfortunately already made it to Linus's tree).

Note that I did try Jan's proposed fix and that didn't solve the issue for me, I
believe we're seeing different issues caused by the same commit.


939f04bec1a4ef6ba4370b0f34b01decc844b1b1 is the first bad commit
commit 939f04bec1a4ef6ba4370b0f34b01decc844b1b1
Author: Jan Kara <jack@xxxxxxx>
Date: Wed Jun 4 16:11:37 2014 -0700

printk: enable interrupts before calling console_trylock_for_printk()

We need interrupts disabled when calling console_trylock_for_printk()
only so that cpu id we pass to can_use_console() remains valid (for
other things console_sem provides all the exclusion we need and
deadlocks on console_sem due to interrupts are impossible because we use
down_trylock()). However if we are rescheduled, we are guaranteed to
run on an online cpu so we can easily just get the cpu id in
can_use_console().

We can lose a bit of performance when we enable interrupts in
vprintk_emit() and then disable them again in console_unlock() but OTOH
it can somewhat reduce interrupt latency caused by console_unlock()
especially since later in the patch series we will want to spin on
console_sem in console_trylock_for_printk().

Signed-off-by: Jan Kara <jack@xxxxxxx>
Signed-off-by: Andrew Morton <akpm@xxxxxxxxxxxxxxxxxxxx>
Signed-off-by: Linus Torvalds <torvalds@xxxxxxxxxxxxxxxxxxxx>


Thanks,
Sasha
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/