0001 ================
0002 NMI Trace Events
0003 ================
0004
0005 These events normally show up here:
0006
0007 /sys/kernel/debug/tracing/events/nmi
0008
0009
0010 nmi_handler
0011 -----------
0012
0013 You might want to use this tracepoint if you suspect that your
0014 NMI handlers are hogging large amounts of CPU time. The kernel
0015 will warn if it sees long-running handlers::
0016
0017 INFO: NMI handler took too long to run: 9.207 msecs
0018
0019 and this tracepoint will allow you to drill down and get some
0020 more details.
0021
0022 Let's say you suspect that perf_event_nmi_handler() is causing
0023 you some problems and you only want to trace that handler
0024 specifically. You need to find its address::
0025
0026 $ grep perf_event_nmi_handler /proc/kallsyms
0027 ffffffff81625600 t perf_event_nmi_handler
0028
0029 Let's also say you are only interested in when that function is
0030 really hogging a lot of CPU time, like a millisecond at a time.
0031 Note that the kernel's output is in milliseconds, but the input
0032 to the filter is in nanoseconds! You can filter on 'delta_ns'::
0033
0034 cd /sys/kernel/debug/tracing/events/nmi/nmi_handler
0035 echo 'handler==0xffffffff81625600 && delta_ns>1000000' > filter
0036 echo 1 > enable
0037
0038 Your output would then look like::
0039
0040 $ cat /sys/kernel/debug/tracing/trace_pipe
0041 <idle>-0 [000] d.h3 505.397558: nmi_handler: perf_event_nmi_handler() delta_ns: 3236765 handled: 1
0042 <idle>-0 [000] d.h3 505.805893: nmi_handler: perf_event_nmi_handler() delta_ns: 3174234 handled: 1
0043 <idle>-0 [000] d.h3 506.158206: nmi_handler: perf_event_nmi_handler() delta_ns: 3084642 handled: 1
0044 <idle>-0 [000] d.h3 506.334346: nmi_handler: perf_event_nmi_handler() delta_ns: 3080351 handled: 1
0045
