From 0191924ce5c7fa23ad2ec9d9d0f2a9a20e5a8920 Mon Sep 17 00:00:00 2001 From: Sergey Senozhatsky Date: Sat, 18 Feb 2017 00:01:42 +0000 Subject: [PATCH] printk: use rcuidle console tracepoint Use rcuidle console tracepoint because, apparently, it may be issued from an idle CPU: [ 2.581939] hw-breakpoint: Failed to enable monitor mode on CPU 0. [ 2.591613] hw-breakpoint: CPU 0 failed to disable vector catch [ 2.597686] [ 2.597717] =============================== [ 2.597717] [ ERR: suspicious RCU usage. ] [ 2.597717] 4.10.0-rc8-next-20170215+ #119 Not tainted [ 2.597717] ------------------------------- [ 2.597717] ./include/trace/events/printk.h:32 suspicious rcu_dereference_check() usage! [ 2.597717] [ 2.597717] other info that might help us debug this: [ 2.597717] [ 2.597717] [ 2.597717] RCU used illegally from idle CPU! [ 2.597717] rcu_scheduler_active = 2, debug_locks = 0 [ 2.597747] RCU used illegally from extended quiescent state! [ 2.597747] 2 locks held by swapper/0/0: [ 2.597747] #0: (cpu_pm_notifier_lock){......}, at: [] cpu_pm_exit+0x10/0x54 [ 2.597747] #1: (console_lock){+.+.+.}, at: [] vprintk_emit+0x264/0x474 [ 2.597747] [ 2.597747] stack backtrace: [ 2.597778] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.10.0-rc8-next-20170215+ #119 [ 2.597778] Hardware name: Generic OMAP4 (Flattened Device Tree) [ 2.597778] [] (unwind_backtrace) from [] (show_stack+0x10/0x14) [ 2.597778] [] (show_stack) from [] (dump_stack+0xac/0xe0) [ 2.597778] [] (dump_stack) from [] (console_unlock+0x5e8/0x650) [ 2.597778] [] (console_unlock) from [] (vprintk_emit+0x270/0x474) [ 2.597778] [] (vprintk_emit) from [] (vprintk_default+0x20/0x28) [ 2.597808] [] (vprintk_default) from [] (printk+0x20/0x30) [ 2.597808] [] (printk) from [] (reset_ctrl_regs+0x108/0x288) [ 2.597808] [] (reset_ctrl_regs) from [] (dbg_cpu_pm_notify+0x28/0x30) [ 2.597808] [] (dbg_cpu_pm_notify) from [] (notifier_call_chain+0x44/0x80) [ 2.597808] [] (notifier_call_chain) from [] (cpu_pm_exit+0x2c/0x54) [ 2.597808] [] (cpu_pm_exit) from [] (omap_enter_idle_coupled+0x80/0x208) [ 2.597808] [] (omap_enter_idle_coupled) from [] (cpuidle_enter_state+0x118/0x4ac) [ 2.597808] [] (cpuidle_enter_state) from [] (cpuidle_enter_state_coupled+0x3a8/0x40c) [ 2.597839] [] (cpuidle_enter_state_coupled) from [] (do_idle+0x1a4/0x218) [ 2.597839] [] (do_idle) from [] (cpu_startup_entry+0x18/0x1c) [ 2.597839] [] (cpu_startup_entry) from [] (start_kernel+0x35c/0x3d4) [ 2.597839] [] (start_kernel) from [<8000807c>] (0x8000807c) This RCU warning, however, is suppressed by lockdep_off() in printk(). lockdep_off() increments the ->lockdep_recursion counter and thus disables RCU_LOCKDEP_WARN() and debug_lockdep_rcu_enabled(), which want lockdep to be enabled "current->lockdep_recursion == 0". Link: http://lkml.kernel.org/r/20170217015932.11898-1-sergey.senozhatsky@gmail.com Signed-off-by: Sergey Senozhatsky Reported-by: Tony Lindgren Tested-by: Tony Lindgren Acked-by: Paul E. McKenney Acked-by: Steven Rostedt (VMware) Cc: Petr Mladek Cc: Peter Zijlstra Cc: Thomas Gleixner Cc: Tony Lindgren Cc: Russell King Cc: [3.4+] Signed-off-by: Andrew Morton --- kernel/printk/printk.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 8b2696420abb5d..4ba3d34938c033 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -1516,7 +1516,7 @@ static void call_console_drivers(int level, { struct console *con; - trace_console(text, len); + trace_console_rcuidle(text, len); if (!console_drivers) return;