| 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
| ||
|
Message-ID: <20140428175139.GD9091@quack.suse.cz>
Date: Mon, 28 Apr 2014 19:51:39 +0200
From: Jan Kara <jack@...e.cz>
To: Steven Rostedt <rostedt@...dmis.org>
Cc: Peter Zijlstra <peterz@...radead.org>,
"Shevchenko, Andriy" <andriy.shevchenko@...el.com>,
Jan Kara <jack@...e.cz>,
Andrew Morton <akpm@...ux-foundation.org>,
"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
Ingo Molnar <mingo@...nel.org>
Subject: Re: lockdep warning after recent cleanup in console code
On Mon 28-04-14 13:43:31, Steven Rostedt wrote:
> Things have changed with regard to printk() in linux-next. Now it
> appears that lockdep is going haywire over it. I don't understand the
> exact reason for the lockdep_off() and lockdep_on() logic that is in
> printk(), but it obviously seems to be causing issues with the new
> changes.
>
> Care to take a look?
The obvious cause is that I moved lockdep_on() somewhat earlier in
vprintk_emit() so lockdep now covers more of printk code. And apparently
something is wrong there...
Honza
>
> -- Steve
>
>
> On Mon, 28 Apr 2014 16:35:26 +0000
> "Shevchenko, Andriy" <andriy.shevchenko@...el.com> wrote:
>
> > Hei!
> >
> > During weekend the linux-next was being broken by introducing a lockdep
> > warning in the console code
> >
> > [ 0.000000] BIOS-e820: [mem 0x00000000e0000000-0x00000000ffffffff]
> > reserved
> > [ 0.000000]
> > [ 0.000000] =============================================
> > [ 0.000000] [ INFO: possible recursive locking detected ]
> > [ 0.000000] 3.15.0-rc2-next-20140428-00030-gd3550d8 #38 Not tainted
> > [ 0.000000] ---------------------------------------------
> > [ 0.000000] swapper/0 is trying to acquire lock:
> > [ 0.000000] (console_lock){......}, at: [<c10728cc>]
> > register_console+0x15e/0x295
> > [ 0.000000]
> > [ 0.000000] but task is already holding lock:
> > [ 0.000000] (console_lock){......}, at: [<c1071e7a>] vprintk_emit
> > +0x381/0x3ea
> > [ 0.000000]
> > [ 0.000000] other info that might help us debug this:
> > [ 0.000000] Possible unsafe locking scenario:
> > [ 0.000000]
> > [ 0.000000] CPU0
> > [ 0.000000] ----
> > [ 0.000000] lock(console_lock);
> > [ 0.000000] lock(console_lock);
> > [ 0.000000]
> > [ 0.000000] *** DEADLOCK ***
> > [ 0.000000]
> > [ 0.000000] May be due to missing lock nesting notation
> > [ 0.000000]
> > [ 0.000000] 3 locks held by swapper/0:
> > [ 0.000000] #0: (console_lock){......}, at: [<c1071e7a>]
> > vprintk_emit+0x381/0x3ea
> > [ 0.000000] #1: (console_lock){......}, at: [<c1071e7a>]
> > vprintk_emit+0x381/0x3ea
> > [ 0.000000] #2: (console_lock){......}, at: [<c1071e7a>]
> > vprintk_emit+0x381/0x3ea
> > [ 0.000000]
> > [ 0.000000] stack backtrace:
> > [ 0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted
> > 3.15.0-rc2-next-20140428-00030-gd3550d8 #38
> > [ 0.000000] 00000000 00000000 c186de1c c15878ae c1daf840 c186de88
> > c106c154 c1794d9d
> > [ 0.000000] c17958f7 c1794c9c 0000002a 00000000 00000000 c1daf840
> > c1983700 00000080
> > [ 0.000000] 04002001 c187a0b0 00000000 c1879ba0 c1879b40 c1879b40
> > 00200046 00000000
> > [ 0.000000] Call Trace:
> > [ 0.000000] [<c15878ae>] dump_stack+0x49/0x73
> > [ 0.000000] [<c106c154>] __lock_acquire+0xb31/0xc7c
> > [ 0.000000] [<c106c33b>] lock_acquire+0x9c/0x111
> > [ 0.000000] [<c10728cc>] ? register_console+0x15e/0x295
> > [ 0.000000] [<c10707dd>] console_lock+0x41/0x46
> > [ 0.000000] [<c10728cc>] ? register_console+0x15e/0x295
> > [ 0.000000] [<c10728cc>] register_console+0x15e/0x295
> > [ 0.000000] [<c1582f80>] early_console_register+0x33/0x35
> > [ 0.000000] [<c1910411>] setup_early_printk+0x144/0x151
> > [ 0.000000] [<c19013f6>] do_early_param+0x41/0x73
> > [ 0.000000] [<c19013b5>] ? loglevel+0x2c/0x2c
> > [ 0.000000] [<c104c766>] parse_args+0x24f/0x307
> > [ 0.000000] [<c19013b5>] ? loglevel+0x2c/0x2c
> > [ 0.000000] [<c190169d>] parse_early_options+0x1c/0x21
> > [ 0.000000] [<c190169d>] ? parse_early_options+0x1c/0x21
> > [ 0.000000] [<c19013b5>] ? loglevel+0x2c/0x2c
> > [ 0.000000] [<c19016cc>] parse_early_param+0x2a/0x36
> > [ 0.000000] [<c19042c0>] setup_arch+0x3c9/0xc55
> > [ 0.000000] [<c1071ebe>] ? vprintk_emit+0x3c5/0x3ea
> > [ 0.000000] [<c1584869>] ? printk+0x28/0x2d
> > [ 0.000000] [<c1901754>] start_kernel+0x72/0x305
> > [ 0.000000] [<c19012b4>] i386_start_kernel+0x82/0x86
> > [ 0.000000] bootconsole [earlyhsu0] enabled
> >
> > Bisecting shows the culprit (which I guessed before), namely commit
> > 5dc90cb49691755faaad2a395d297d0162075eca ("printk: enable interrupts
> > before calling console_trylock_for_printk()").
> >
> > Following patch helps me, but I'm not familiar with console locking
> > scheme, I believe there is a better solution.
> >
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -1700,8 +1700,10 @@ asmlinkage int vprintk_emit(int facility, int
> > level,
> > * The release will print out buffers and wake up /dev/kmsg and
> > syslog()
> > * users.
> > */
> > + lockdep_off();
> > if (console_trylock_for_printk())
> > console_unlock();
> > + lockdep_on();
> > preempt_enable();
> >
> > return printed_len;
> >
> >
>
--
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