1 files changed, 34 insertions, 2 deletions

diff --git a/arch/x86/kernel/nmi.c b/arch/x86/kernel/nmi.c
index 60308053fdb2..0920212e6159 100644
--- a/arch/x86/kernel/nmi.c
+++ b/arch/x86/kernel/nmi.c
@@ -14,6 +14,7 @@
 #include <linux/kprobes.h>
 #include <linux/kdebug.h>
 #include <linux/nmi.h>
+#include <linux/debugfs.h>
 #include <linux/delay.h>
 #include <linux/hardirq.h>
 #include <linux/slab.h>
@@ -29,6 +30,9 @@
 #include <asm/nmi.h>
 #include <asm/x86_init.h>
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/nmi.h>
+
 struct nmi_desc {
         spinlock_t lock;
         struct list_head head;
@@ -82,6 +86,15 @@ __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,
+                        arch_debugfs_dir, &nmi_longest_ns);
+        return 0;
+}
+fs_initcall(nmi_warning_debugfs);
+
 static int __kprobes nmi_handle(unsigned int type, struct pt_regs *regs, bool b2b)
 {
         struct nmi_desc *desc = nmi_to_desc(type);
@@ -96,8 +109,27 @@ static int __kprobes nmi_handle(unsigned int type, struct pt_regs *regs, bool b2
          * can be latched at any given time.  Walk the whole list
          * to handle those situations.
          */
-        list_for_each_entry_rcu(a, &desc->head, list)
-                handled += a->handler(type, regs);
+        list_for_each_entry_rcu(a, &desc->head, list) {
+                u64 before, delta, whole_msecs;
+                int decimal_msecs, thishandled;
+
+                before = local_clock();
+                thishandled = a->handler(type, regs);
+                handled += thishandled;
+                delta = local_clock() - before;
+                trace_nmi_handler(a->handler, (int)delta, thishandled);
+
+                if (delta < nmi_longest_ns)
+                        continue;
+
+                nmi_longest_ns = delta;
+                whole_msecs = do_div(delta, (1000 * 1000));
+                decimal_msecs = do_div(delta, 1000) % 1000;
+                printk_ratelimited(KERN_INFO
+                        "INFO: NMI handler (%ps) took too long to run: "
+                        "%lld.%03d msecs\n", a->handler, whole_msecs,
+                        decimal_msecs);
+        }
 
         rcu_read_unlock();