Documentation/trace/events-nmi.rst

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