On Thu, 21 Apr 2016 13:48:42 +0200
Petr Mladek <pmladek@xxxxxxxx> wrote:
> printk() takes some locks and could not be used a safe way in NMI context.
I just found a problem with this solution. It kills ftrace dumps from
NMI context :-(
[ 1295.168495] <...>-67423 10dNh1 382171111us : do_raw_spin_lock <-_raw_spin_lock
[ 1295.168495] <...>-67423 10dNh1 382171111us : sched_stat_runtime: comm=cc1 pid=67423 runtime=96858 [ns] vruntime=11924198270 [ns]
[ 1295.168496] <...>-67423 10dNh1 382171111us : lock_acquire: ffffffff81c5c940 read rcu_read_lock
[ 1295.168497]
[ 1295.168498] Lost 4890096 message(s)!
[ 1296.805063] ---[ end Kernel panic - not syncing: Hard LOCKUP
[ 1296.811553] unchecked MSR access error: WRMSR to 0x83f (tried to write 0x00000000000000f6) at rIP: 0xffffffff81046fc7 (native_apic_msr_write+0x27/0x40)
[ 1296.811553] Call Trace:
[ 1296.811553] <NMI>
I was hoping to see a cause of a hard lockup by enabling
ftrace_dump_on_oops. But as NMIs now have a very small buffer that
gets flushed, we need to find a new way to print out the full ftrace
buffer over serial.
Thoughts?
-- Steve
>
> The chance of a deadlock is real especially when printing stacks from all
> CPUs. This particular problem has been addressed on x86 by the commit
> a9edc8809328 ("x86/nmi: Perform a safe NMI stack trace on all CPUs").
>
> The patchset brings two big advantages. First, it makes the NMI
> backtraces safe on all architectures for free. Second, it makes all NMI
> messages almost safe on all architectures (the temporary buffer is
> limited. We still should keep the number of messages in NMI context at
> minimum).
>
> Note that there already are several messages printed in NMI context:
> WARN_ON(in_nmi()), BUG_ON(in_nmi()), anything being printed out from MCE
> handlers. These are not easy to avoid.
>
> This patch reuses most of the code and makes it generic. It is useful for
> all messages and architectures that support NMI.
>
> The alternative printk_func is set when entering and is reseted when
> leaving NMI context. It queues IRQ work to copy the messages into the
> main ring buffer in a safe context.
>
> __printk_nmi_flush() copies all available messages and reset the buffer.
> Then we could use a simple cmpxchg operations to get synchronized with
> writers. There is also used a spinlock to get synchronized with other
> flushers.
>
> We do not longer use seq_buf because it depends on external lock. It
> would be hard to make all supported operations safe for a lockless use.
> It would be confusing and error prone to make only some operations safe.
>
> The code is put into separate printk/nmi.c as suggested by Steven Rostedt.
> It needs a per-CPU buffer and is compiled only on architectures that call
> nmi_enter(). This is achieved by the new HAVE_NMI Kconfig flag.
>
> The are MN10300 and Xtensa architectures. We need to clean up NMI
> handling there first. Let's do it separately.
>
> The patch is heavily based on the draft from Peter Zijlstra, see
> https://lkml.org/lkml/2015/6/10/327
>
> [arnd@xxxxxxxx: printk-nmi: use %zu format string for size_t]
> [akpm@xxxxxxxxxxxxxxxxxxxx: min_t->min - all types are size_t here]
> Signed-off-by: Petr Mladek <pmladek@xxxxxxxx>
> Suggested-by: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
> Suggested-by: Steven Rostedt <rostedt@xxxxxxxxxxx>
> Cc: Jan Kara <jack@xxxxxxx>
> Cc: Russell King <rmk+kernel@xxxxxxxxxxxxxxxx>
> Cc: Daniel Thompson <daniel.thompson@xxxxxxxxxx>
> Cc: Jiri Kosina <jkosina@xxxxxxxx>
> Cc: Ingo Molnar <mingo@xxxxxxxxxx>
> Cc: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
> Cc: Ralf Baechle <ralf@xxxxxxxxxxxxxx>
> Cc: Benjamin Herrenschmidt <benh@xxxxxxxxxxxxxxxxxxx>
> Cc: Martin Schwidefsky <schwidefsky@xxxxxxxxxx>
> Cc: David Miller <davem@xxxxxxxxxxxxx>
> Cc: Daniel Thompson <daniel.thompson@xxxxxxxxxx>
> Signed-off-by: Andrew Morton <akpm@xxxxxxxxxxxxxxxxxxxx>
