On Fri, Feb 5, 2021 at 7:09 PM Petr Mladek <pmla...@suse.com> wrote: > > Hi, > > first, I am sorry for the late reply. I have been somehow distracted > this week. > > On Mon 2021-02-01 18:26:01, Muchun Song wrote: > > We found a deadlock bug on our server when the kernel panic. It can be > > described in the following diagram. > > > > 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(&read_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 > > // deal lock > > raw_spin_lock_irqsave(&read_lock) > > Great catch! > > > kernel/printk/printk_safe.c | 58 > > ++++++++++++++++++++++++++------------------- > > 1 file changed, 34 insertions(+), 24 deletions(-) > > > > diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c > > index a0e6f746de6c..86d9fa74ac5c 100644 > > --- a/kernel/printk/printk_safe.c > > +++ b/kernel/printk/printk_safe.c > > @@ -174,30 +174,13 @@ static void report_message_lost(struct > > printk_safe_seq_buf *s) > > printk_deferred("Lost %d message(s)!\n", lost); > > } > > > > -/* > > - * Flush data from the associated per-CPU buffer. The function > > - * can be called either via IRQ work or independently. > > - */ > > -static void __printk_safe_flush(struct irq_work *work) > > +static void __printk_safe_flush_work(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; > > size_t len; > > - int i; > > + int i = 0; > > > > - /* > > - * The lock has two functions. First, one reader has to flush all > > - * available message to make the lockless synchronization with > > - * writers easier. Second, we do not want to mix messages from > > - * different CPUs. This is especially important when printing > > - * a backtrace. > > - */ > > - raw_spin_lock_irqsave(&read_lock, flags); > > - > > - i = 0; > > more: > > len = atomic_read(&s->len); > > > > @@ -232,6 +215,26 @@ static void __printk_safe_flush(struct irq_work *work) > > > > out: > > report_message_lost(s); > > +} > > + > > +/* > > + * Flush data from the associated per-CPU buffer. The function > > + * can be called either via IRQ work or independently. > > + */ > > +static void printk_safe_flush_work(struct irq_work *work) > > +{ > > + unsigned long flags; > > + static DEFINE_RAW_SPINLOCK(read_lock); > > + > > + /* > > + * The lock has two functions. First, one reader has to flush all > > + * available message to make the lockless synchronization with > > + * writers easier. Second, we do not want to mix messages from > > + * different CPUs. This is especially important when printing > > + * a backtrace. > > + */ > > + raw_spin_lock_irqsave(&read_lock, flags); > > + __printk_safe_flush_work(work); > > raw_spin_unlock_irqrestore(&read_lock, flags); > > } > > > > @@ -248,9 +251,9 @@ void printk_safe_flush(void) > > > > for_each_possible_cpu(cpu) { > > #ifdef CONFIG_PRINTK_NMI > > - __printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work); > > + printk_safe_flush_work(&per_cpu(nmi_print_seq, cpu).work); > > #endif > > - __printk_safe_flush(&per_cpu(safe_print_seq, cpu).work); > > + printk_safe_flush_work(&per_cpu(safe_print_seq, cpu).work); > > } > > } > > > > @@ -266,6 +269,8 @@ void printk_safe_flush(void) > > */ > > void printk_safe_flush_on_panic(void) > > { > > + int cpu; > > + > > /* > > * Make sure that we could access the main ring buffer. > > * Do not risk a double release when more CPUs are up. > > @@ -278,7 +283,12 @@ void printk_safe_flush_on_panic(void) > > raw_spin_lock_init(&logbuf_lock); > > } > > > > - printk_safe_flush(); > > + for_each_possible_cpu(cpu) { > > +#ifdef CONFIG_PRINTK_NMI > > + __printk_safe_flush_work(&per_cpu(nmi_print_seq, cpu).work); > > +#endif > > + __printk_safe_flush_work(&per_cpu(safe_print_seq, cpu).work); > > + } > > There might be two CPUs running this code when more CPUs are still running. > The might definitely be the case here: > > if (!_crash_kexec_post_notifiers) { > printk_safe_flush_on_panic(); > __crash_kexec(NULL); > > __printk_safe_flush_work() is relatively safe even in this case. > It accesses only data that are limited by s->len that is updated > atomically. > > But it calls: > > + printk_safe_flush_on_panic() > + __printk_safe_flush_work() > + printk_safe_flush_buffer() > + printk_safe_flush_line() > + printk_deferred() > > where printk_deferred() used logbuf_lock() until v5.11-rc1, see > the commit b031a684bfd01d633c ("printk: remove logbuf_lock > writer-protection of ringbuffer"). > > We need a solution that might be backported back to v4.7-rc1 > where logbuf_lock() might cause a deadlock.
Agree. > > Also we really want to call printk_safe_flush_on_panic() > in panic(). It is trying hard but it should not cause > deadlock. > > Therefore, I suggest to handle read_lock the same way in > printk_safe_flush_on_panic() as we handle logbuf_lock there. > > I mean to make it global in printk_safe.c: > > static DEFINE_RAW_SPINLOCK(safe_read_lock); > > and do something like this in printk_safe_flush_on_panic() > > if (raw_spin_is_locked(&safe_read_lock)) { > if (num_online_cpus() > 1) > return; > > debug_locks_off(); > raw_spin_lock_init(&safe_read_lock); > } > > How does that sound, please? Great. It is also a solution. It seems simple. I will do this. Thanks. > > Best Regards, > Petr