linux-kernel - Re: [prink] BUG: spinlock lockup suspected on CPU#0, swapper/1

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20140530161948.GZ13658@twins.programming.kicks-ass.net>
Date:	Fri, 30 May 2014 18:19:48 +0200
From:	Peter Zijlstra <peterz@...radead.org>
To:	Jan Kara <jack@...e.cz>
Cc:	Jet Chen <jet.chen@...el.com>,
	Fengguang Wu <fengguang.wu@...el.com>,
	Yuanhan Liu <yuanhan.liu@...el.com>,
	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
	Sasha Levin <sasha.levin@...cle.com>,
	Peter Hurley <peter@...leysoftware.com>,
	Andrew Morton <akpm@...ux-foundation.org>
Subject: Re: [prink]  BUG: spinlock lockup suspected on CPU#0, swapper/1

On Fri, May 30, 2014 at 06:16:47PM +0200, Peter Zijlstra wrote:
> On Fri, May 30, 2014 at 05:50:51PM +0200, Jan Kara wrote:
> > > [    7.492350] ======================================================
> > > [    7.492350] [ INFO: possible circular locking dependency detected ]
> > > [    7.492350] 3.15.0-rc5-00567-gbafe980 #1 Not tainted
> > > [    7.492350] -------------------------------------------------------
> > > [    7.492350] swapper/1 is trying to acquire lock:
> > > [    7.492350]  (&irq_desc_lock_class){-.-...}, at: [<8107dc8c>] __irq_get_desc_lock+0x3c/0x70
> > > [    7.492350] 
> > > [    7.492350] but task is already holding lock:
> > > [    7.492350]  (&port_lock_key){......}, at: [<815f5b27>] serial8250_startup+0x337/0x720
> > > [    7.492350] 
> > > [    7.492350] which lock already depends on the new lock.
> > > [    7.492350] 
> > > [    7.492350] 
> > > [    7.492350] the existing dependency chain (in reverse order) is:
> > > [    7.492350] 
> > > -> #2 (&port_lock_key){......}:
> > > [    7.492350]        [<810750e5>] lock_acquire+0x85/0x190
> > > [    7.492350]        [<81baed9d>] _raw_spin_lock_irqsave+0x4d/0x60
> > > [    7.492350]        [<8106eb1c>] down_trylock+0xc/0x30
> > > [    7.492350]        [<8107b795>] console_trylock+0x15/0xb0
> > > [    7.492350]        [<8107be8f>] vprintk_emit+0x14f/0x4d0
> > > [    7.492350]        [<81b969b9>] printk+0x38/0x3a
> > > [    7.492350]        [<82137f78>] print_ICs+0x5b/0x3e7
> > > [    7.492350]        [<8212bb41>] do_one_initcall+0x8b/0x128
> > > [    7.492350]        [<8212bd7d>] kernel_init_freeable+0x19f/0x236
> > > [    7.492350]        [<81b9238b>] kernel_init+0xb/0xd0
> > > [    7.492350]        [<81bb0080>] ret_from_kernel_thread+0x20/0x30
> >
> >   But this looks really strange. How can we possibly get port_lock_key in
> > down_trylock() which calls raw_spin_lock_irqsave() on console_sem->lock?
> > That looks like some strange lockdep key aliasing issue? Peter do you have
> > any idea?
> 
> No, strange that, I can't say I've ever seen a bogus stracktrace in
> lockdep reports like this.
> 
> So this is through: check_prev_add()->save_trace(). And that doesn't
> reuse entries, at worst it can truncate a trace when we run out of
> entries, but the above looks complete since it terminates in
> lock_acquire(), which is the right place to be.
> 
> But its worse than that, the above trace should link i8259A_lock to
> port_lock_key, and I can't see where we would have taken i8259A_lock
> either.

Oh, wait, I missed it, that would be: print_ICs()->print_PIC(), it takes
that lock there.

Content of type "application/pgp-signature" skipped