[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20140611203126.GC9511@quack.suse.cz>
Date: Wed, 11 Jun 2014 22:31:26 +0200
From: Jan Kara <jack@...e.cz>
To: Peter Hurley <peter@...leysoftware.com>
Cc: Sasha Levin <sasha.levin@...cle.com>, Jan Kara <jack@...e.cz>,
pmladek@...e.cz, Andrew Morton <akpm@...ux-foundation.org>,
Jet Chen <jet.chen@...el.com>,
LKML <linux-kernel@...r.kernel.org>,
Linus Torvalds <torvalds@...ux-foundation.org>
Subject: Re: console: lockup on boot
On Wed 11-06-14 11:34:28, Peter Hurley wrote:
> On 06/11/2014 10:55 AM, Sasha Levin wrote:
> >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@...e.cz>
> >>>>>>AuthorDate: Thu May 22 10:43:35 2014 +1000
> >>>>>>Commit: Stephen Rothwell <sfr@...b.auug.org.au>
> >>>>>>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@...e.cz>
> >>>>>> Signed-off-by: Andrew Morton <akpm@...ux-foundation.org>
> >>>>>>
> >>>>>>?
> >>>> 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@...e.cz>
> >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@...e.cz>
> > Signed-off-by: Andrew Morton <akpm@...ux-foundation.org>
> > Signed-off-by: Linus Torvalds <torvalds@...ux-foundation.org>
>
> I apologize; I didn't look at the patch very closely, but now that I do,
> this sticks out:
>
> @@ -1597,17 +1599,22 @@ asmlinkage int vprintk_emit(int facility, int level,
>
> logbuf_cpu = UINT_MAX;
> raw_spin_unlock(&logbuf_lock);
> + lockdep_on();
> + local_irq_restore(flags);
> +
>
> What prevents cpu migration right here?
Nothing.
> If nothing, then logbuf_cpu is now stale and the recursion test at
> the top of vprintk_emit is doing nothing to prevent recursion.
Well, note that logbuf_cpu has just been set to UINT_MAX (i.e. undefined)
two lines above. So my patch changes nothing wrt. how printk recursion
detection works (at least AFAICT).
> + /*
> + * Disable preemption to avoid being preempted while holding
> + * console_sem which would prevent anyone from printing to console
> + */
> + preempt_disable();
> /*
> * Try to acquire and then immediately release the console semaphore.
> * The release will print out buffers and wake up /dev/kmsg and syslog()
> * users.
> */
> - if (console_trylock_for_printk(this_cpu))
> + if (console_trylock_for_printk())
> console_unlock();
Honza
--
Jan Kara <jack@...e.cz>
SUSE Labs, CR
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists