1NMI Trace Events 2 3These events normally show up here: 4 5 /sys/kernel/debug/tracing/events/nmi 6 7-- 8 9nmi_handler: 10 11You might want to use this tracepoint if you suspect that your 12NMI handlers are hogging large amounts of CPU time. The kernel 13will warn if it sees long-running handlers: 14 15 INFO: NMI handler took too long to run: 9.207 msecs 16 17and this tracepoint will allow you to drill down and get some 18more details. 19 20Let's say you suspect that perf_event_nmi_handler() is causing 21you some problems and you only want to trace that handler 22specifically. You need to find its address: 23 24 $ grep perf_event_nmi_handler /proc/kallsyms 25 ffffffff81625600 t perf_event_nmi_handler 26 27Let's also say you are only interested in when that function is 28really hogging a lot of CPU time, like a millisecond at a time. 29Note that the kernel's output is in milliseconds, but the input 30to the filter is in nanoseconds! You can filter on 'delta_ns': 31 32cd /sys/kernel/debug/tracing/events/nmi/nmi_handler 33echo 'handler==0xffffffff81625600 && delta_ns>1000000' > filter 34echo 1 > enable 35 36Your output would then look like: 37 38$ cat /sys/kernel/debug/tracing/trace_pipe 39<idle>-0 [000] d.h3 505.397558: nmi_handler: perf_event_nmi_handler() delta_ns: 3236765 handled: 1 40<idle>-0 [000] d.h3 505.805893: nmi_handler: perf_event_nmi_handler() delta_ns: 3174234 handled: 1 41<idle>-0 [000] d.h3 506.158206: nmi_handler: perf_event_nmi_handler() delta_ns: 3084642 handled: 1 42<idle>-0 [000] d.h3 506.334346: nmi_handler: perf_event_nmi_handler() delta_ns: 3080351 handled: 1 43 44