Re: [PATCH v3] printk: fix deadlock when kernel panic

2021-02-10 Thread Petr Mladek
On Wed 2021-02-10 11:48:23, Muchun Song wrote:
> printk_safe_flush_on_panic() caused the following deadlock on our
> server:
> 
> CPU0: CPU1:
> panic rcu_dump_cpu_stacks
>   kdump_nmi_shootdown_cpus  nmi_trigger_cpumask_backtrace
> register_nmi_handler(crash_nmi_callback)  printk_safe_flush
> __printk_safe_flush
>   
> raw_spin_lock_irqsave(_lock)
> // send NMI to other processors
> apic_send_IPI_allbutself(NMI_VECTOR)
> // NMI interrupt, 
> dead loop
> crash_nmi_callback
>   printk_safe_flush_on_panic
> printk_safe_flush
>   __printk_safe_flush
> // deadlock
> raw_spin_lock_irqsave(_lock)
> 
> DEADLOCK: read_lock is taken on CPU1 and will never get released.
> 
> It happens when panic() stops a CPU by NMI while it has been in
> the middle of printk_safe_flush().
> 
> Handle the lock the same way as logbuf_lock. The printk_safe buffers
> are flushed only when both locks can be safely taken. It can avoid
> the deadlock _in this particular case_ at expense of losing contents
> of printk_safe buffers.
> 
> Note: It would actually be safe to re-init the locks when all CPUs were
>   stopped by NMI. But it would require passing this information
>   from arch-specific code. It is not worth the complexity.
>   Especially because logbuf_lock and printk_safe buffers have been
>   obsoleted by the lockless ring buffer.
> 
> Fixes: cf9b1106c81c ("printk/nmi: flush NMI messages on the system panic")
> Signed-off-by: Muchun Song 
> Reviewed-by: Petr Mladek 
> Cc: 

The patch is committed on printk/linux.git, branch for-5.12.

Best Regards,
Petr


Re: [PATCH v3] printk: fix deadlock when kernel panic

2021-02-09 Thread Sergey Senozhatsky
On (21/02/10 11:48), Muchun Song wrote:
> printk_safe_flush_on_panic() caused the following deadlock on our
> server:
> 
> CPU0: CPU1:
> panic rcu_dump_cpu_stacks
>   kdump_nmi_shootdown_cpus  nmi_trigger_cpumask_backtrace
> register_nmi_handler(crash_nmi_callback)  printk_safe_flush
> __printk_safe_flush
>   
> raw_spin_lock_irqsave(_lock)
> // send NMI to other processors
> apic_send_IPI_allbutself(NMI_VECTOR)
> // NMI interrupt, 
> dead loop
> crash_nmi_callback
>   printk_safe_flush_on_panic
> printk_safe_flush
>   __printk_safe_flush
> // deadlock
> raw_spin_lock_irqsave(_lock)
> 
> DEADLOCK: read_lock is taken on CPU1 and will never get released.
> 
> It happens when panic() stops a CPU by NMI while it has been in
> the middle of printk_safe_flush().
> 
> Handle the lock the same way as logbuf_lock. The printk_safe buffers
> are flushed only when both locks can be safely taken. It can avoid
> the deadlock _in this particular case_ at expense of losing contents
> of printk_safe buffers.
> 
> Note: It would actually be safe to re-init the locks when all CPUs were
>   stopped by NMI. But it would require passing this information
>   from arch-specific code. It is not worth the complexity.
>   Especially because logbuf_lock and printk_safe buffers have been
>   obsoleted by the lockless ring buffer.
> 
> Fixes: cf9b1106c81c ("printk/nmi: flush NMI messages on the system panic")
> Signed-off-by: Muchun Song 
> Reviewed-by: Petr Mladek 
> Cc: 

Acked-by: Sergey Senozhatsky 

-ss


[PATCH v3] printk: fix deadlock when kernel panic

2021-02-09 Thread Muchun Song
printk_safe_flush_on_panic() caused the following deadlock on our
server:

CPU0: CPU1:
panic rcu_dump_cpu_stacks
  kdump_nmi_shootdown_cpus  nmi_trigger_cpumask_backtrace
register_nmi_handler(crash_nmi_callback)  printk_safe_flush
__printk_safe_flush
  
raw_spin_lock_irqsave(_lock)
// send NMI to other processors
apic_send_IPI_allbutself(NMI_VECTOR)
// NMI interrupt, dead 
loop
crash_nmi_callback
  printk_safe_flush_on_panic
printk_safe_flush
  __printk_safe_flush
// deadlock
raw_spin_lock_irqsave(_lock)

DEADLOCK: read_lock is taken on CPU1 and will never get released.

It happens when panic() stops a CPU by NMI while it has been in
the middle of printk_safe_flush().

Handle the lock the same way as logbuf_lock. The printk_safe buffers
are flushed only when both locks can be safely taken. It can avoid
the deadlock _in this particular case_ at expense of losing contents
of printk_safe buffers.

Note: It would actually be safe to re-init the locks when all CPUs were
  stopped by NMI. But it would require passing this information
  from arch-specific code. It is not worth the complexity.
  Especially because logbuf_lock and printk_safe buffers have been
  obsoleted by the lockless ring buffer.

Fixes: cf9b1106c81c ("printk/nmi: flush NMI messages on the system panic")
Signed-off-by: Muchun Song 
Reviewed-by: Petr Mladek 
Cc: 
---
 kernel/printk/printk_safe.c | 16 
 1 file changed, 12 insertions(+), 4 deletions(-)

diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
index a0e6f746de6c..2e9e3ed7d63e 100644
--- a/kernel/printk/printk_safe.c
+++ b/kernel/printk/printk_safe.c
@@ -45,6 +45,8 @@ struct printk_safe_seq_buf {
 static DEFINE_PER_CPU(struct printk_safe_seq_buf, safe_print_seq);
 static DEFINE_PER_CPU(int, printk_context);
 
+static DEFINE_RAW_SPINLOCK(safe_read_lock);
+
 #ifdef CONFIG_PRINTK_NMI
 static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq);
 #endif
@@ -180,8 +182,6 @@ static void report_message_lost(struct printk_safe_seq_buf 
*s)
  */
 static void __printk_safe_flush(struct irq_work *work)
 {
-   static raw_spinlock_t read_lock =
-   __RAW_SPIN_LOCK_INITIALIZER(read_lock);
struct printk_safe_seq_buf *s =
container_of(work, struct printk_safe_seq_buf, work);
unsigned long flags;
@@ -195,7 +195,7 @@ static void __printk_safe_flush(struct irq_work *work)
 * different CPUs. This is especially important when printing
 * a backtrace.
 */
-   raw_spin_lock_irqsave(_lock, flags);
+   raw_spin_lock_irqsave(_read_lock, flags);
 
i = 0;
 more:
@@ -232,7 +232,7 @@ static void __printk_safe_flush(struct irq_work *work)
 
 out:
report_message_lost(s);
-   raw_spin_unlock_irqrestore(_lock, flags);
+   raw_spin_unlock_irqrestore(_read_lock, flags);
 }
 
 /**
@@ -278,6 +278,14 @@ void printk_safe_flush_on_panic(void)
raw_spin_lock_init(_lock);
}
 
+   if (raw_spin_is_locked(_read_lock)) {
+   if (num_online_cpus() > 1)
+   return;
+
+   debug_locks_off();
+   raw_spin_lock_init(_read_lock);
+   }
+
printk_safe_flush();
 }
 
-- 
2.11.0