x86/nmi: Push duration printk() to irq context

Calling printk() from NMI context is bad (TM), so move it to IRQ
context.

In doing so we slightly change (probably wreck) the debugfs
nmi_longest_ns thingy, in that it doesn't update to reflect the
longest, nor does writing to it reset the count.

Signed-off-by: Peter Zijlstra <peterz@infradead.org>
Cc: Don Zickus <dzickus@redhat.com>
Cc: Dave Hansen <dave.hansen@linux.intel.com>
Link: http://lkml.kernel.org/n/tip-rdw0au56a5ymis1u8p48c12d@git.kernel.org
Signed-off-by: Ingo Molnar <mingo@kernel.org>

diff --git a/arch/x86/include/asm/nmi.h b/arch/x86/include/asm/nmi.h
index 86f9301903c818c632b227537b44142b71883c8d..5f2fc4441b11016608f476848e3a60bd1e08d7a5 100644 (file)
--- a/arch/x86/include/asm/nmi.h
+++ b/arch/x86/include/asm/nmi.h
@@ -1,6 +1,7 @@
 #ifndef _ASM_X86_NMI_H
 #define _ASM_X86_NMI_H
 
+#include <linux/irq_work.h>
 #include <linux/pm.h>
 #include <asm/irq.h>
 #include <asm/io.h>
@@ -38,6 +39,8 @@ typedef int (*nmi_handler_t)(unsigned int, struct pt_regs *);
 struct nmiaction {
        struct list_head        list;
        nmi_handler_t           handler;
+       u64                     max_duration;
+       struct irq_work         irq_work;
        unsigned long           flags;
        const char              *name;
 };

diff --git a/arch/x86/kernel/nmi.c b/arch/x86/kernel/nmi.c
index 6fcb49ce50a1260d1f4bfdf0b5a065dd4f6d77c7..b4872b999a713d7fc08f7578b672d804a30dd13e 100644 (file)
--- a/arch/x86/kernel/nmi.c
+++ b/arch/x86/kernel/nmi.c
@@ -87,6 +87,7 @@ __setup("unknown_nmi_panic", setup_unknown_nmi_panic);
 #define nmi_to_desc(type) (&nmi_desc[type])
 
 static u64 nmi_longest_ns = 1 * NSEC_PER_MSEC;
+
 static int __init nmi_warning_debugfs(void)
 {
        debugfs_create_u64("nmi_longest_ns", 0644,
@@ -95,6 +96,20 @@ static int __init nmi_warning_debugfs(void)
 }
 fs_initcall(nmi_warning_debugfs);
 
+static void nmi_max_handler(struct irq_work *w)
+{
+       struct nmiaction *a = container_of(w, struct nmiaction, irq_work);
+       int remainder_ns, decimal_msecs;
+       u64 whole_msecs = ACCESS_ONCE(a->max_duration);
+
+       remainder_ns = do_div(whole_msecs, (1000 * 1000));
+       decimal_msecs = remainder_ns / 1000;
+
+       printk_ratelimited(KERN_INFO
+               "INFO: NMI handler (%ps) took too long to run: %lld.%03d msecs\n",
+               a->handler, whole_msecs, decimal_msecs);
+}
+
 static int __kprobes nmi_handle(unsigned int type, struct pt_regs *regs, bool b2b)
 {
        struct nmi_desc *desc = nmi_to_desc(type);
@@ -110,26 +125,20 @@ static int __kprobes nmi_handle(unsigned int type, struct pt_regs *regs, bool b2
         * to handle those situations.
         */
        list_for_each_entry_rcu(a, &desc->head, list) {
-               u64 before, delta, whole_msecs;
-               int remainder_ns, decimal_msecs, thishandled;
+               int thishandled;
+               u64 delta;
 
-               before = sched_clock();
+               delta = sched_clock();
                thishandled = a->handler(type, regs);
                handled += thishandled;
-               delta = sched_clock() - before;
+               delta = sched_clock() - delta;
                trace_nmi_handler(a->handler, (int)delta, thishandled);
 
-               if (delta < nmi_longest_ns)
+               if (delta < nmi_longest_ns || delta < a->max_duration)
                        continue;
 
-               nmi_longest_ns = delta;
-               whole_msecs = delta;
-               remainder_ns = do_div(whole_msecs, (1000 * 1000));
-               decimal_msecs = remainder_ns / 1000;
-               printk_ratelimited(KERN_INFO
-                       "INFO: NMI handler (%ps) took too long to run: "
-                       "%lld.%03d msecs\n", a->handler, whole_msecs,
-                       decimal_msecs);
+               a->max_duration = delta;
+               irq_work_queue(&a->irq_work);
        }
 
        rcu_read_unlock();
@@ -146,6 +155,8 @@ int __register_nmi_handler(unsigned int type, struct nmiaction *action)
        if (!action->handler)
                return -EINVAL;
 
+       init_irq_work(&action->irq_work, nmi_max_handler);
+
        spin_lock_irqsave(&desc->lock, flags);
 
        /*