Re: [PATCH printk v5 1/1] printk: extend console_lock for per-console locking

[John Ogness]

On 2022-05-06, Marek Szyprowski <m.szyprowski@xxxxxxxxxxx> wrote:
> The Amlogic Meson related issue has been investigated and fixed:
>
> https://lore.kernel.org/all/b7c81f02-039e-e877-d7c3-6834728d2117@xxxxxxxxxxx/
>
> but I just found that there is one more issue.
>
> It appears on QCom-based DragonBoard 410c SBC 
> (arch/arm64/boot/dts/qcom/apq8016-sbc.dts). To see it on today's linux 
> next-20220506, one has to revert 
> 42cd402b8fd4672b692400fe5f9eecd55d2794ac, otherwise lockdep triggers 
> other warning and it is turned off too early:
>
> ================================
> WARNING: inconsistent lock state
> 5.18.0-rc5-next-20220506+ #11869 Not tainted
> --------------------------------
> inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
> swapper/0/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
> ffff80000aaa8478 (&port_lock_key){?.+.}-{2:2}, at: msm_uart_irq+0x38/0x750
> {HARDIRQ-ON-W} state was registered at:
>    lock_acquire.part.0+0xe0/0x230
>    lock_acquire+0x68/0x84
>    _raw_spin_lock+0x5c/0x80
>    __msm_console_write+0x1ac/0x220
>    msm_console_write+0x48/0x60
>    __console_emit_next_record+0x188/0x420
>    printk_kthread_func+0x3a0/0x3bc
>    kthread+0x118/0x11c
>    ret_from_fork+0x10/0x20
> irq event stamp: 12182
> hardirqs last  enabled at (12181): [<ffff800008e3d2a8>] 
> cpuidle_enter_state+0xc4/0x30c
>
> stack backtrace:
> CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.18.0-rc5-next-20220506+ #11869
> Hardware name: Qualcomm Technologies, Inc. APQ 8016 SBC (DT)
> Call trace:
>   dump_backtrace.part.0+0xd0/0xe0
>   show_stack+0x18/0x6c
>   dump_stack_lvl+0x8c/0xb8
>   dump_stack+0x18/0x34
>   print_usage_bug.part.0+0x208/0x22c
>   mark_lock+0x710/0x954
>   __lock_acquire+0x9fc/0x20cc
>   lock_acquire.part.0+0xe0/0x230
>   lock_acquire+0x68/0x84
>   _raw_spin_lock_irqsave+0x80/0xcc
>   msm_uart_irq+0x38/0x750
>   __handle_irq_event_percpu+0xac/0x3d0
>   handle_irq_event+0x4c/0x120
>   handle_fasteoi_irq+0xa4/0x1a0
>   generic_handle_domain_irq+0x3c/0x60
>   gic_handle_irq+0x44/0xc4
>   call_on_irq_stack+0x2c/0x54
>   do_interrupt_handler+0x80/0x84
>   el1_interrupt+0x34/0x64
>   el1h_64_irq_handler+0x18/0x24
>   el1h_64_irq+0x64/0x68
>   cpuidle_enter_state+0xcc/0x30c
>   cpuidle_enter+0x38/0x50
>   do_idle+0x22c/0x2bc
>   cpu_startup_entry+0x28/0x30
>   rest_init+0x110/0x190
>   arch_post_acpi_subsys_init+0x0/0x18
>   start_kernel+0x6c4/0x704
>   __primary_switched+0xc0/0xc8
>   INIT: version 2.88 booting
> [info] Using makefile-style concurrent boot in runlevel S.

The console write() callback for the msm driver (__msm_console_write)
assumes interrupts are off and is doing a spin_lock(&port->lock) rather
than spin_lock_irqsave(&port->lock, flags).

The following change should address the issue:

John

diff --git a/drivers/tty/serial/msm_serial.c b/drivers/tty/serial/msm_serial.c
index 23c94b927776..ab3f360bd354 100644
--- a/drivers/tty/serial/msm_serial.c
+++ b/drivers/tty/serial/msm_serial.c
@@ -1599,6 +1599,7 @@ static inline struct uart_port *msm_get_port_from_line(unsigned int line)
 static void __msm_console_write(struct uart_port *port, const char *s,
 				unsigned int count, bool is_uartdm)
 {
+	unsigned long flags;
 	int i;
 	int num_newlines = 0;
 	bool replaced = false;
@@ -1621,7 +1622,7 @@ static void __msm_console_write(struct uart_port *port, const char *s,
 	else if (oops_in_progress)
 		locked = spin_trylock(&port->lock);
 	else
-		spin_lock(&port->lock);
+		spin_lock_irqsave(&port->lock, flags);
 
 	if (is_uartdm)
 		msm_reset_dm_count(port, count);
@@ -1660,7 +1661,7 @@ static void __msm_console_write(struct uart_port *port, const char *s,
 	}
 
 	if (locked)
-		spin_unlock(&port->lock);
+		spin_unlock_irqrestore(&port->lock, flags);
 }
 
 static void msm_console_write(struct console *co, const char *s,