* [PATCH] ratelimit: use deferred printk() version
@ 2017-09-28 12:04 Sergey Senozhatsky
2017-09-28 12:13 ` Sergey Senozhatsky
0 siblings, 1 reply; 4+ messages in thread
From: Sergey Senozhatsky @ 2017-09-28 12:04 UTC (permalink / raw)
To: Peter Zijlstra, Petr Mladek
Cc: linux-kernel, Sergey Senozhatsky, Sergey Senozhatsky, stable,
Thomas Gleixner, Ingo Molnar, Borislav Petkov, Steven Rostedt
printk_ratelimit() invokes ___ratelimit() which may invoke a normal
printk() (pr_warn() in this particular case) to warn about suppressed
output. Given that printk_ratelimit() may be called from anywhere,
that pr_warn() is dangerous - it may end up deadlocking the system.
Fix ___ratelimit() by using deferred printk().
Sasha reported the following lockdep error:
: Unregister pv shared memory for cpu 8
: select_fallback_rq: 3 callbacks suppressed
: process 8583 (trinity-c78) no longer affine to cpu8
:
: ======================================================
: WARNING: possible circular locking dependency detected
: 4.14.0-rc2-next-20170927+ #252 Not tainted
: ------------------------------------------------------
: migration/8/62 is trying to acquire lock:
: (&port_lock_key){-.-.}, at: serial8250_console_write()
:
: but task is already holding lock:
: (&rq->lock){-.-.}, at: sched_cpu_dying()
:
: which lock already depends on the new lock.
:
:
: the existing dependency chain (in reverse order) is:
:
: -> #3 (&rq->lock){-.-.}:
: __lock_acquire()
: lock_acquire()
: _raw_spin_lock()
: task_fork_fair()
: sched_fork()
: copy_process.part.31()
: _do_fork()
: kernel_thread()
: rest_init()
: start_kernel()
: x86_64_start_reservations()
: x86_64_start_kernel()
: verify_cpu()
:
: -> #2 (&p->pi_lock){-.-.}:
: __lock_acquire()
: lock_acquire()
: _raw_spin_lock_irqsave()
: try_to_wake_up()
: default_wake_function()
: woken_wake_function()
: __wake_up_common()
: __wake_up_common_lock()
: __wake_up()
: tty_wakeup()
: tty_port_default_wakeup()
: tty_port_tty_wakeup()
: uart_write_wakeup()
: serial8250_tx_chars()
: serial8250_handle_irq.part.25()
: serial8250_default_handle_irq()
: serial8250_interrupt()
: __handle_irq_event_percpu()
: handle_irq_event_percpu()
: handle_irq_event()
: handle_level_irq()
: handle_irq()
: do_IRQ()
: ret_from_intr()
: native_safe_halt()
: default_idle()
: arch_cpu_idle()
: default_idle_call()
: do_idle()
: cpu_startup_entry()
: rest_init()
: start_kernel()
: x86_64_start_reservations()
: x86_64_start_kernel()
: verify_cpu()
:
: -> #1 (&tty->write_wait){-.-.}:
: __lock_acquire()
: lock_acquire()
: _raw_spin_lock_irqsave()
: __wake_up_common_lock()
: __wake_up()
: tty_wakeup()
: tty_port_default_wakeup()
: tty_port_tty_wakeup()
: uart_write_wakeup()
: serial8250_tx_chars()
: serial8250_handle_irq.part.25()
: serial8250_default_handle_irq()
: serial8250_interrupt()
: __handle_irq_event_percpu()
: handle_irq_event_percpu()
: handle_irq_event()
: handle_level_irq()
: handle_irq()
: do_IRQ()
: ret_from_intr()
: native_safe_halt()
: default_idle()
: arch_cpu_idle()
: default_idle_call()
: do_idle()
: cpu_startup_entry()
: rest_init()
: start_kernel()
: x86_64_start_reservations()
: x86_64_start_kernel()
: verify_cpu()
:
: -> #0 (&port_lock_key){-.-.}:
: check_prev_add()
: __lock_acquire()
: lock_acquire()
: _raw_spin_lock_irqsave()
: serial8250_console_write()
: univ8250_console_write()
: console_unlock()
: vprintk_emit()
: vprintk_default()
: vprintk_func()
: printk()
: ___ratelimit()
: __printk_ratelimit()
: select_fallback_rq()
: sched_cpu_dying()
: cpuhp_invoke_callback()
: take_cpu_down()
: multi_cpu_stop()
: cpu_stopper_thread()
: smpboot_thread_fn()
: kthread()
: ret_from_fork()
:
: other info that might help us debug this:
:
: Chain exists of:
: &port_lock_key --> &p->pi_lock --> &rq->lock
:
: Possible unsafe locking scenario:
:
: CPU0 CPU1
: ---- ----
: lock(&rq->lock);
: lock(&p->pi_lock);
: lock(&rq->lock);
: lock(&port_lock_key);
:
: *** DEADLOCK ***
:
: 4 locks held by migration/8/62:
: #0: (&p->pi_lock){-.-.}, at: sched_cpu_dying()
: #1: (&rq->lock){-.-.}, at: sched_cpu_dying()
: #2: (printk_ratelimit_state.lock){....}, at: ___ratelimit()
: #3: (console_lock){+.+.}, at: vprintk_emit()
:
: stack backtrace:
: CPU: 8 PID: 62 Comm: migration/8 Not tainted 4.14.0-rc2-next-20170927+ #252
: Call Trace:
: dump_stack()
: print_circular_bug()
: check_prev_add()
: ? add_lock_to_list.isra.26()
: ? check_usage()
: ? kvm_clock_read()
: ? kvm_sched_clock_read()
: ? sched_clock()
: ? check_preemption_disabled()
: __lock_acquire()
: ? __lock_acquire()
: ? add_lock_to_list.isra.26()
: ? debug_check_no_locks_freed()
: ? memcpy()
: lock_acquire()
: ? serial8250_console_write()
: _raw_spin_lock_irqsave()
: ? serial8250_console_write()
: serial8250_console_write()
: ? serial8250_start_tx()
: ? lock_acquire()
: ? memcpy()
: univ8250_console_write()
: console_unlock()
: ? __down_trylock_console_sem()
: vprintk_emit()
: vprintk_default()
: vprintk_func()
: printk()
: ? show_regs_print_info()
: ? lock_acquire()
: ___ratelimit()
: __printk_ratelimit()
: select_fallback_rq()
: sched_cpu_dying()
: ? sched_cpu_starting()
: ? rcutree_dying_cpu()
: ? sched_cpu_starting()
: cpuhp_invoke_callback()
: ? cpu_disable_common()
: take_cpu_down()
: ? trace_hardirqs_off_caller()
: ? cpuhp_invoke_callback()
: multi_cpu_stop()
: ? __this_cpu_preempt_check()
: ? cpu_stop_queue_work()
: cpu_stopper_thread()
: ? cpu_stop_create()
: smpboot_thread_fn()
: ? sort_range()
: ? schedule()
: ? __kthread_parkme()
: kthread()
: ? sort_range()
: ? kthread_create_on_node()
: ret_from_fork()
: process 9121 (trinity-c78) no longer affine to cpu8
: smpboot: CPU 8 is now offline
Fixes: 6b1d174b0c27b ("ratelimit: extend to print suppressed messages on release")
Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Reported-by: Sasha Levin <levinsasha928@gmail.com>
Cc: stable@vger.kernel.org
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Borislav Petkov <bp@suse.de>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Petr Mladek <pmladek@suse.com>
---
lib/ratelimit.c | 4 +++-
1 file changed, 3 insertions(+), 1 deletion(-)
diff --git a/lib/ratelimit.c b/lib/ratelimit.c
index 08f8043cac61..d01f47135239 100644
--- a/lib/ratelimit.c
+++ b/lib/ratelimit.c
@@ -48,7 +48,9 @@ int ___ratelimit(struct ratelimit_state *rs, const char *func)
if (time_is_before_jiffies(rs->begin + rs->interval)) {
if (rs->missed) {
if (!(rs->flags & RATELIMIT_MSG_ON_RELEASE)) {
- pr_warn("%s: %d callbacks suppressed\n", func, rs->missed);
+ printk_deferred(KERN_WARNING
+ "%s: %d callbacks suppressed\n",
+ func, rs->missed);
rs->missed = 0;
}
}
--
2.14.2
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH] ratelimit: use deferred printk() version
2017-09-28 12:04 [PATCH] ratelimit: use deferred printk() version Sergey Senozhatsky
@ 2017-09-28 12:13 ` Sergey Senozhatsky
2017-09-29 4:55 ` Sergey Senozhatsky
0 siblings, 1 reply; 4+ messages in thread
From: Sergey Senozhatsky @ 2017-09-28 12:13 UTC (permalink / raw)
To: Sergey Senozhatsky
Cc: Peter Zijlstra, Petr Mladek, linux-kernel, Sergey Senozhatsky,
stable, Thomas Gleixner, Ingo Molnar, Borislav Petkov,
Steven Rostedt, Sasha Levin
(Cc-ing Sasha)
On (09/28/17 21:04), Sergey Senozhatsky wrote:
[..]
> : process 9121 (trinity-c78) no longer affine to cpu8
> : smpboot: CPU 8 is now offline
>
> Fixes: 6b1d174b0c27b ("ratelimit: extend to print suppressed messages on release")
> Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> Reported-by: Sasha Levin <levinsasha928@gmail.com>
> Cc: stable@vger.kernel.org
> Cc: Peter Zijlstra <peterz@infradead.org>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: Ingo Molnar <mingo@elte.hu>
> Cc: Borislav Petkov <bp@suse.de>
> Cc: Steven Rostedt <rostedt@goodmis.org>
> Cc: Petr Mladek <pmladek@suse.com>
ok... today I learned that git send-email does not automatically
add Reported-by people to the list of recipients... a bit unexpected...
sorry Sasha, I should have checked that.
Link: lkml.kernel.org/r/20170928120405.18273-1-sergey.senozhatsky@gmail.com
-ss
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] ratelimit: use deferred printk() version
2017-09-28 12:13 ` Sergey Senozhatsky
@ 2017-09-29 4:55 ` Sergey Senozhatsky
2017-10-02 9:29 ` Petr Mladek
0 siblings, 1 reply; 4+ messages in thread
From: Sergey Senozhatsky @ 2017-09-29 4:55 UTC (permalink / raw)
To: Peter Zijlstra, Petr Mladek
Cc: Andrew Morton, linux-kernel, Sergey Senozhatsky, stable,
Thomas Gleixner, Ingo Molnar, Borislav Petkov, Steven Rostedt,
Sasha Levin, Sergey Senozhatsky
Hello,
(Cc-ing Andrew lkml.kernel.org/r/20170928120405.18273-1-sergey.senozhatsky@gmail.com )
On (09/28/17 21:13), Sergey Senozhatsky wrote:
> (Cc-ing Sasha)
>
> On (09/28/17 21:04), Sergey Senozhatsky wrote:
> [..]
> > : process 9121 (trinity-c78) no longer affine to cpu8
> > : smpboot: CPU 8 is now offline
> >
> > Fixes: 6b1d174b0c27b ("ratelimit: extend to print suppressed messages on release")
> > Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> > Reported-by: Sasha Levin <levinsasha928@gmail.com>
> > Cc: stable@vger.kernel.org
> > Cc: Peter Zijlstra <peterz@infradead.org>
> > Cc: Thomas Gleixner <tglx@linutronix.de>
> > Cc: Ingo Molnar <mingo@elte.hu>
> > Cc: Borislav Petkov <bp@suse.de>
> > Cc: Steven Rostedt <rostedt@goodmis.org>
> > Cc: Petr Mladek <pmladek@suse.com>
a quick question, who is going to pick it up? or shall we ask Andrew?
-ss
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] ratelimit: use deferred printk() version
2017-09-29 4:55 ` Sergey Senozhatsky
@ 2017-10-02 9:29 ` Petr Mladek
0 siblings, 0 replies; 4+ messages in thread
From: Petr Mladek @ 2017-10-02 9:29 UTC (permalink / raw)
To: Sergey Senozhatsky
Cc: Peter Zijlstra, Andrew Morton, linux-kernel, Sergey Senozhatsky,
stable, Thomas Gleixner, Ingo Molnar, Borislav Petkov,
Steven Rostedt, Sasha Levin
On Fri 2017-09-29 13:55:46, Sergey Senozhatsky wrote:
> Hello,
>
> (Cc-ing Andrew lkml.kernel.org/r/20170928120405.18273-1-sergey.senozhatsky@gmail.com )
>
> On (09/28/17 21:13), Sergey Senozhatsky wrote:
> > (Cc-ing Sasha)
> >
> > On (09/28/17 21:04), Sergey Senozhatsky wrote:
> > [..]
> > > : process 9121 (trinity-c78) no longer affine to cpu8
> > > : smpboot: CPU 8 is now offline
> > >
> > > Fixes: 6b1d174b0c27b ("ratelimit: extend to print suppressed messages on release")
> > > Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> > > Reported-by: Sasha Levin <levinsasha928@gmail.com>
> > > Cc: stable@vger.kernel.org
> > > Cc: Peter Zijlstra <peterz@infradead.org>
> > > Cc: Thomas Gleixner <tglx@linutronix.de>
> > > Cc: Ingo Molnar <mingo@elte.hu>
> > > Cc: Borislav Petkov <bp@suse.de>
> > > Cc: Steven Rostedt <rostedt@goodmis.org>
> > > Cc: Petr Mladek <pmladek@suse.com>
The change looks reasonable to me. Thanks a lot for digging into the
reported problem. Feel free to add:
Reviewed-by: Petr Mladek <pmladek@suse.com>
> a quick question, who is going to pick it up? or shall we ask Andrew?
I see that Andrew already took it. Thanks!
Best Regards,
Petr
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2017-10-02 9:29 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-09-28 12:04 [PATCH] ratelimit: use deferred printk() version Sergey Senozhatsky
2017-09-28 12:13 ` Sergey Senozhatsky
2017-09-29 4:55 ` Sergey Senozhatsky
2017-10-02 9:29 ` Petr Mladek
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).