Messages in this thread | | | Date | Wed, 4 Jul 2018 01:31:45 +0900 | From | Sergey Senozhatsky <> | Subject | Re: printk() from NMI backtrace can delay a lot |
| |
Hello, Tejun
On (07/03/18 08:29), Tejun Heo wrote: > Hello, Sergey. > > On Tue, Jul 03, 2018 at 01:30:21PM +0900, Sergey Senozhatsky wrote: > > Cc-ing Linus, Tejun, Andrew > > [I'll keep the entire lockdep report] > > > > On (07/02/18 19:26), Tetsuo Handa wrote: > > [..] > > > 2018-07-02 12:13:13 192.168.159.129:6666 [ 151.606834] swapper/0/0 is trying to acquire lock: > > > 2018-07-02 12:13:13 192.168.159.129:6666 [ 151.606835] 00000000316e1432 (console_owner){-.-.}, at: console_unlock+0x1ce/0x8b0 > > > 2018-07-02 12:13:13 192.168.159.129:6666 [ 151.606840] > > > 2018-07-02 12:13:13 192.168.159.129:6666 [ 151.606841] but task is already holding lock: > > > 2018-07-02 12:13:13 192.168.159.129:6666 [ 151.606842] 000000009b45dcb4 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state+0x3b2/0x900 > > > 2018-07-02 12:13:13 192.168.159.129:6666 [ 151.606847] > > > 2018-07-02 12:13:13 192.168.159.129:6666 [ 151.606848] which lock already depends on the new lock. > ... > > But anyway. So we can have [but I'm not completely sure. Maybe lockdep has > > something else on its mind] something like this: > > > > CPU1 CPU0 > > > > #IRQ #soft irq > > serial8250_handle_irq() wq_watchdog_timer_fn() > > spin_lock(&uart_port->lock) show_workqueue_state() > > serial8250_rx_chars() spin_lock(&pool->lock) > > tty_flip_buffer_push() printk() > > tty_schedule_flip() serial8250_console_write() > > queue_work() spin_lock(&uart_port->lock) > > __queue_work() > > spin_lock(&pool->lock) > > > > We need to break the pool->lock -> uart_port->lock chain. > > > > - use printk_deferred() to show WQs states [show_workqueue_state() is > > a timer callback, so local IRQs are enabled]. But show_workqueue_state() > > is also available via sysrq. > > > > - what Alan Cox suggested: use spin_trylock() in serial8250_console_write() > > and just discard (do not print anything on console) console->writes() that > > can deadlock us [uart_port->lock is already locked]. This basically means > > that sometimes there will be no output on a serial console, or there > > will be missing line. Which kind of contradicts the purpose of print > > out. > > > > We are facing the risk of no output on serial consoles in both case. Thus > > there must be some other way out of this. > > show_workqueue_state() is only used when something is already horribly > broken or when invoked through sysrq.
Tetsuo is hammering sysrq for fun and profit ;)
> I'm not sure it's worthwhile to make invasive changes to avoid lockdep > warnings. If anything, we should make show_workqueue_state() avoid > grabbing pool->lock (e.g. use trylock and fallback to probe_kernel_reads > if that fails). I'm a bit skeptical how actually useful that'd be tho.
So, I agree.
Another option *possibly* could be...
... maybe we can brake another lock dependency. I don't quite understand, and surely I'm missing something here, why serial driver call tty_flip_buffer_push() under uart_port->lock. E.g.
serial_driver_handle_irq() { spin_lock(uart_port->lock);
.. TX() / RX()
tty_flip_buffer_push(uart_port->tty_port); spin_unlock(uart_port->lock); }
it might be the case that we can do
serial_driver_handle_irq() { spin_loc(uart_port->lock);
.. TX / RX
spin_unlock(uart_port->lock);
tty_flip_buffer_push(uart_port->tty_port); }
This should break this chain
uart_port->lock -> pool->lock // -> sheduler/etc.
Can we do it? What am I missing?
-ss
| |