On Tue, Jan 16, 2024 at 10:48:44AM +0200, Ilpo Järvinen wrote: > On Tue, 16 Jan 2024, Leonardo Bras wrote: > > > With PREEMPT_RT enabled, a spin_lock_irqsave() becomes a possibly sleeping > > spin_lock(), without preempt_disable() or irq_disable(). > > > > This allows a task T1 to get preempted or interrupted while holding the > > port->lock. If the preempting task T2 need the lock, spin_lock() code > > will schedule T1 back until it finishes using the lock, and then go back to > > T2. > > > > There is an issue if a T1 holding port->lock is interrupted by an > > IRQ, and this IRQ handler needs to get port->lock for writting (printk): > > spin_lock() code will try to reschedule the interrupt handler, which is in > > atomic context, causing a BUG() for trying to reschedule/sleep in atomic > > context. Hello Ilpo, thanks for replying! > > I thought that the printk side was supposed to be become aware when it's > not safe to write to serial side so the printing can be deferred... Has > that plan changed? > > -- > i. I was not aware of this plan. Well, at least in an PREEMPT_RT=y kernel I have found this same bug reproducing several times, and through the debugging that I went through I saw no mechanism for preventing it. This is one example of the bug: While writing to serial with serial8250_tx_chars in a irq_thread handler there is an interruption, and __report_bad_irq() tries to printk stuff to the console, and when printk goes down to serial8250_console_write() and tried to get the port->lock, which causes the "BUG: scheduling while atomic": [ 42.485878] irq 4: nobody cared (try booting with the "irqpoll" option) [ 42.485886] BUG: scheduling while atomic: irq/4-ttyS0/751/0x00010002 [ 42.485890] Modules linked in: [ 42.485892] Preemption disabled at: [ 42.485893] [<ffffffff8118ac80>] irq_enter_rcu+0x10/0x80 [ 42.485919] CPU: 0 PID: 751 Comm: irq/4-ttyS0 Not tainted 6.7.0-rc6+ #6 [ 42.485927] Hardware name: Red Hat KVM/RHEL, BIOS 1.16.3-1.el9 04/01/2014 [ 42.485929] Call Trace: [ 42.485940] <IRQ> [ 42.485944] dump_stack_lvl+0x33/0x50 [ 42.485976] __schedule_bug+0x89/0xa0 [ 42.485991] schedule_debug.constprop.0+0xd1/0x120 [ 42.485996] __schedule+0x50/0x690 [ 42.486026] schedule_rtlock+0x1e/0x40 [ 42.486029] rtlock_slowlock_locked+0xe7/0x2b0 [ 42.486047] rt_spin_lock+0x41/0x60 [ 42.486051] serial8250_console_write+0x1be/0x460 [ 42.486094] console_flush_all+0x18d/0x3c0 [ 42.486111] console_unlock+0x6c/0xd0 [ 42.486117] vprintk_emit+0x1d6/0x290 [ 42.486122] _printk+0x58/0x80 [ 42.486139] __report_bad_irq+0x26/0xc0 [ 42.486147] note_interrupt+0x2a1/0x2f0 [ 42.486155] handle_irq_event+0x84/0x90 [ 42.486161] handle_edge_irq+0x9f/0x260 [ 42.486168] __common_interrupt+0x68/0x100 [ 42.486178] common_interrupt+0x9f/0xc0 [ 42.486184] </IRQ> Thanks! Leo > > > So for the case (PREEMPT_RT && in_atomic()) try to get the lock, and if it > > fails proceed anyway, just like it's done in oops_in_progress case. > > > > Signed-off-by: Leonardo Bras <leobras@xxxxxxxxxx> > > --- > > drivers/tty/serial/8250/8250_port.c | 2 +- > > 1 file changed, 1 insertion(+), 1 deletion(-) > > > > diff --git a/drivers/tty/serial/8250/8250_port.c b/drivers/tty/serial/8250/8250_port.c > > index 8ca061d3bbb92..8480832846319 100644 > > --- a/drivers/tty/serial/8250/8250_port.c > > +++ b/drivers/tty/serial/8250/8250_port.c > > @@ -3397,7 +3397,7 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s, > > > > touch_nmi_watchdog(); > > > > - if (oops_in_progress) > > + if (oops_in_progress || (IS_ENABLED(CONFIG_PREEMPT_RT) && in_atomic()) > > locked = uart_port_trylock_irqsave(port, &flags); > > else > > uart_port_lock_irqsave(port, &flags); > > >
