| 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: <20161221143605.2272-7-sergey.senozhatsky@gmail.com>
Date: Wed, 21 Dec 2016 23:36:04 +0900
From: Sergey Senozhatsky <sergey.senozhatsky@...il.com>
To: Andrew Morton <akpm@...ux-foundation.org>
Cc: Petr Mladek <pmladek@...e.com>, Jan Kara <jack@...e.cz>,
Tejun Heo <tj@...nel.org>, Calvin Owens <calvinowens@...com>,
Steven Rostedt <rostedt@...dmis.org>,
Ingo Molnar <mingo@...hat.com>,
Peter Zijlstra <peterz@...radead.org>,
Andy Lutomirski <luto@...nel.org>,
Linus Torvalds <torvalds@...ux-foundation.org>,
Peter Hurley <peter@...leysoftware.com>,
linux-kernel@...r.kernel.org,
Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
Subject: [PATCHv6 6/7] printk: use printk_safe buffers in printk
Use printk_safe per-CPU buffers in printk recursion-prone blocks:
-- around logbuf_lock protected sections in vprintk_emit() and
console_unlock()
-- around down_trylock_console_sem() and up_console_sem()
Note that this solution addresses deadlocks caused by printk()
recursive calls only. That is vprintk_emit() and console_unlock().
Another thing to note is that we now keep lockdep enabled in printk,
because we are protected against the printk recursion caused by lockdep
in vprintk_emit() by the printk-safe mechanism - we first switch to
per-CPU buffers and only then access the deadlock-prone locks.
Examples:
1) printk() from logbuf_lock spin_lock section
Assume the following code:
printk()
raw_spin_lock(&logbuf_lock);
WARN_ON(1);
raw_spin_unlock(&logbuf_lock);
which now produces:
------------[ cut here ]------------
WARNING: CPU: 0 PID: 366 at kernel/printk/printk.c:1811 vprintk_emit+0x1cd/0x438
CPU: 0 PID: 366 Comm: bash
Call Trace:
[<ffffffff81045658>] warn_slowpath_null+0x1d/0x1f
[<ffffffff81091527>] vprintk_emit+0x1cd/0x438
[<ffffffff810918fe>] vprintk_default+0x1d/0x1f
[<ffffffff810fdf6a>] printk+0x48/0x50
[..]
[<ffffffff813caaaa>] entry_SYSCALL_64_fastpath+0x18/0xad
---[ end trace ]---
2) printk() from semaphore sem->lock spin_lock section
Assume the following code
printk()
console_trylock()
down_trylock()
raw_spin_lock_irqsave(&sem->lock, flags);
WARN_ON(1);
raw_spin_unlock_irqrestore(&sem->lock, flags);
which now produces:
------------[ cut here ]------------
WARNING: CPU: 1 PID: 363 at kernel/locking/semaphore.c:141 down_trylock+0x3d/0x62
CPU: 1 PID: 363 Comm: bash
Call Trace:
[<ffffffff81045658>] warn_slowpath_null+0x1d/0x1f
[<ffffffff810838df>] down_trylock+0x3d/0x62
[<ffffffff8109177e>] ? vprintk_emit+0x3f9/0x414
[<ffffffff810905cb>] console_trylock+0x31/0xeb
[<ffffffff8109177e>] vprintk_emit+0x3f9/0x414
[<ffffffff81091905>] vprintk_default+0x1d/0x1f
[<ffffffff810fdf71>] printk+0x48/0x50
[..]
[<ffffffff813caaaa>] entry_SYSCALL_64_fastpath+0x18/0xad
---[ end trace ]---
3) printk() from console_unlock()
Assume the following code:
printk()
console_unlock()
raw_spin_lock(&logbuf_lock);
WARN_ON(1);
raw_spin_unlock(&logbuf_lock);
which now produces:
------------[ cut here ]------------
WARNING: CPU: 1 PID: 329 at kernel/printk/printk.c:2384 console_unlock+0x12d/0x559
CPU: 1 PID: 329 Comm: bash
Call Trace:
[<ffffffff8103d6ca>] warn_slowpath_null+0x18/0x1a
[<ffffffff8107f917>] console_unlock+0x12d/0x559
[<ffffffff810772c4>] ? trace_hardirqs_on_caller+0x16d/0x189
[<ffffffff810772ed>] ? trace_hardirqs_on+0xd/0xf
[<ffffffff810800a6>] vprintk_emit+0x363/0x374
[<ffffffff81080219>] vprintk_default+0x18/0x1a
[<ffffffff810c7f77>] printk+0x43/0x4b
[..]
[<ffffffff814c2d6a>] entry_SYSCALL_64_fastpath+0x18/0xad
---[ end trace ]---
4) printk() from try_to_wake_up()
Assume the following code:
printk()
console_unlock()
up()
try_to_wake_up()
raw_spin_lock_irqsave(&p->pi_lock, flags);
WARN_ON(1);
raw_spin_unlock_irqrestore(&p->pi_lock, flags);
which now produces:
------------[ cut here ]------------
WARNING: CPU: 3 PID: 363 at kernel/sched/core.c:2028 try_to_wake_up+0x7f/0x4f7
CPU: 3 PID: 363 Comm: bash
Call Trace:
[<ffffffff81045658>] warn_slowpath_null+0x1d/0x1f
[<ffffffff8106c8d0>] try_to_wake_up+0x7f/0x4f7
[<ffffffff8106cd5d>] wake_up_process+0x15/0x17
[<ffffffff813c82c6>] __up.isra.0+0x56/0x63
[<ffffffff810839a3>] up+0x32/0x42
[<ffffffff8108f624>] __up_console_sem+0x37/0x55
[<ffffffff810910ff>] console_unlock+0x21e/0x4c2
[<ffffffff810917bf>] vprintk_emit+0x41c/0x462
[<ffffffff81091971>] vprintk_default+0x1d/0x1f
[<ffffffff810fdfdd>] printk+0x48/0x50
[..]
[<ffffffff813cab2a>] entry_SYSCALL_64_fastpath+0x18/0xad
---[ end trace ]---
5) printk() from call_console_drivers()
Assume the following code:
printk()
console_unlock()
call_console_drivers()
...
WARN_ON(1);
which now produces:
------------[ cut here ]------------
WARNING: CPU: 2 PID: 305 at kernel/printk/printk.c:1604 call_console_drivers+0x3a/0xb0
CPU: 2 PID: 305 Comm: bash
Call Trace:
[<ffffffff810399c0>] warn_slowpath_null+0x18/0x1a
[<ffffffff8106b218>] call_console_drivers.isra.6.constprop.16+0x3a/0xb0
[<ffffffff8106cc46>] console_unlock+0x471/0x48e
[<ffffffff8106ce57>] vprintk_emit+0x1f4/0x206
[<ffffffff8106cfcb>] vprintk_default+0x18/0x1a
[<ffffffff8106af66>] vprintk_func+0x6e/0x70
[<ffffffff810abbe3>] printk+0x3e/0x46
[..]
[<ffffffff8145a860>] entry_SYSCALL_64_fastpath+0x13/0x94
---[ end trace ]---
Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@...il.com>
Reviewed-by: Petr Mladek <pmladek@...e.com>
---
kernel/printk/printk.c | 42 +++++++++++++++++++++++++++---------------
1 file changed, 27 insertions(+), 15 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 6ec61ae0d122..c188219e596f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -213,17 +213,31 @@ static int nr_ext_console_drivers;
static int __down_trylock_console_sem(unsigned long ip)
{
- if (down_trylock(&console_sem))
+ int lock_failed;
+ unsigned long flags;
+
+ printk_safe_enter(flags);
+ lock_failed = down_trylock(&console_sem);
+ printk_safe_exit(flags);
+
+ if (lock_failed)
return 1;
mutex_acquire(&console_lock_dep_map, 0, 1, ip);
return 0;
}
#define down_trylock_console_sem() __down_trylock_console_sem(_RET_IP_)
-#define up_console_sem() do { \
- mutex_release(&console_lock_dep_map, 1, _RET_IP_);\
- up(&console_sem);\
-} while (0)
+static void __up_console_sem(unsigned long ip)
+{
+ unsigned long flags;
+
+ mutex_release(&console_lock_dep_map, 1, ip);
+
+ printk_safe_enter(flags);
+ up(&console_sem);
+ printk_safe_exit(flags);
+}
+#define up_console_sem() __up_console_sem(_RET_IP_)
/*
* This is used for debugging the mess that is the VT code by
@@ -1689,7 +1703,7 @@ asmlinkage int vprintk_emit(int facility, int level,
boot_delay_msec(level);
printk_delay();
- local_irq_save(flags);
+ printk_safe_enter(flags);
this_cpu = smp_processor_id();
/*
@@ -1705,13 +1719,12 @@ asmlinkage int vprintk_emit(int facility, int level,
*/
if (!oops_in_progress && !lockdep_recursing(current)) {
recursion_bug = true;
- local_irq_restore(flags);
+ printk_safe_exit(flags);
return 0;
}
zap_locks();
}
- lockdep_off();
/* This stops the holder of console_sem just where we want him */
raw_spin_lock(&logbuf_lock);
logbuf_cpu = this_cpu;
@@ -1771,12 +1784,10 @@ asmlinkage int vprintk_emit(int facility, int level,
logbuf_cpu = UINT_MAX;
raw_spin_unlock(&logbuf_lock);
- lockdep_on();
- local_irq_restore(flags);
+ printk_safe_exit(flags);
/* If called from the scheduler, we can not call up(). */
if (!in_sched) {
- lockdep_off();
/*
* Try to acquire and then immediately release the console
* semaphore. The release will print out buffers and wake up
@@ -1784,7 +1795,6 @@ asmlinkage int vprintk_emit(int facility, int level,
*/
if (console_trylock())
console_unlock();
- lockdep_on();
}
return printed_len;
@@ -2209,7 +2219,8 @@ void console_unlock(void)
size_t len;
int level;
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ printk_safe_enter(flags);
+ raw_spin_lock(&logbuf_lock);
if (seen_seq != log_next_seq) {
wake_klogd = true;
seen_seq = log_next_seq;
@@ -2259,7 +2270,7 @@ void console_unlock(void)
stop_critical_timings(); /* don't trace print latency */
call_console_drivers(level, ext_text, ext_len, text, len);
start_critical_timings();
- local_irq_restore(flags);
+ printk_safe_exit(flags);
if (do_cond_resched)
cond_resched();
@@ -2282,7 +2293,8 @@ void console_unlock(void)
*/
raw_spin_lock(&logbuf_lock);
retry = console_seq != log_next_seq;
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ raw_spin_unlock(&logbuf_lock);
+ printk_safe_exit(flags);
if (retry && console_trylock())
goto again;
--
2.11.0
Powered by blists - more mailing lists