diff options
| author | Steven Rostedt (Red Hat) <rostedt@goodmis.org> | 2016-08-04 18:49:53 +0200 |
|---|---|---|
| committer | Steven Rostedt <rostedt@goodmis.org> | 2016-09-02 18:47:55 +0200 |
| commit | 7b2c86250122de316cbab8754050622ead04af39 (patch) | |
| tree | d6605100cf4fc03d8654c9757de0e70a813151ca /kernel/trace/trace_entries.h | |
| parent | tracing: Have hwlat trace migrate across tracing_cpumask CPUs (diff) | |
| download | linux-7b2c86250122de316cbab8754050622ead04af39.tar.xz linux-7b2c86250122de316cbab8754050622ead04af39.zip | |
tracing: Add NMI tracing in hwlat detector
As NMIs can also cause latency when interrupts are disabled, the hwlat
detectory has no way to know if the latency it detects is from an NMI or an
SMI or some other hardware glitch.
As ftrace_nmi_enter/exit() funtions are no longer used (except for sh, which
isn't supported anymore), I converted those to "arch_ftrace_nmi_enter/exit"
and use ftrace_nmi_enter/exit() to check if hwlat detector is tracing or
not, and if so, it calls into the hwlat utility.
Since the hwlat detector only has a single kthread that is spinning with
interrupts disabled, it marks what CPU it is on, and if the NMI callback
happens on that CPU, it records the time spent in that NMI. This is added to
the output that is generated by the hwlat detector as:
#3 inner/outer(us): 9/9 ts:1470836488.206734548
#4 inner/outer(us): 0/8 ts:1470836497.140808588
#5 inner/outer(us): 0/6 ts:1470836499.140825168 nmi-total:5 nmi-count:1
#6 inner/outer(us): 9/9 ts:1470836501.140841748
All time is still tracked in microseconds.
The NMI information is only shown when an NMI occurred during the sample.
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Diffstat (limited to 'kernel/trace/trace_entries.h')
| -rw-r--r-- | kernel/trace/trace_entries.h | 8 |
1 files changed, 6 insertions, 2 deletions
diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h index 70d47dd99359..d1cc37e78f99 100644 --- a/kernel/trace/trace_entries.h +++ b/kernel/trace/trace_entries.h @@ -330,18 +330,22 @@ FTRACE_ENTRY(hwlat, hwlat_entry, F_STRUCT( __field( u64, duration ) __field( u64, outer_duration ) + __field( u64, nmi_total_ts ) __field_struct( struct timespec, timestamp ) __field_desc( long, timestamp, tv_sec ) __field_desc( long, timestamp, tv_nsec ) + __field( unsigned int, nmi_count ) __field( unsigned int, seqnum ) ), - F_printk("cnt:%u\tts:%010lu.%010lu\tinner:%llu\touter:%llu\n", + F_printk("cnt:%u\tts:%010lu.%010lu\tinner:%llu\touter:%llunmi-ts:%llu\tnmi-count:%u\n", __entry->seqnum, __entry->tv_sec, __entry->tv_nsec, __entry->duration, - __entry->outer_duration), + __entry->outer_duration, + __entry->nmi_total_ts, + __entry->nmi_count), FILTER_OTHER ); |