• Sergey Senozhatsky's avatar
    lib/ratelimit.c: use deferred printk() version · 656d61ce
    Sergey Senozhatsky authored
    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
    
    Link: http://lkml.kernel.org/r/20170928120405.18273-1-sergey.senozhatsky@gmail.com
    Fixes: 6b1d174b ("ratelimit: extend to print suppressed messages on release")
    Signed-off-by: 's avatarSergey Senozhatsky <sergey.senozhatsky@gmail.com>
    Reported-by: 's avatarSasha Levin <levinsasha928@gmail.com>
    Reviewed-by: 's avatarPetr Mladek <pmladek@suse.com>
    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: <stable@vger.kernel.org>
    Signed-off-by: 's avatarAndrew Morton <akpm@linux-foundation.org>
    Signed-off-by: 's avatarLinus Torvalds <torvalds@linux-foundation.org>
    656d61ce
ratelimit.c 1.61 KB