155 lines
5.3 KiB
Diff
155 lines
5.3 KiB
Diff
From: Tom Zanussi <tom.zanussi@linux.intel.com>
|
|
Date: Mon, 15 Jan 2018 20:51:48 -0600
|
|
Subject: [PATCH 14/37] tracing: Add usecs modifier for hist trigger timestamps
|
|
Origin: https://www.kernel.org/pub/linux/kernel/projects/rt/4.14/older/patches-4.14.15-rt13.tar.xz
|
|
|
|
Appending .usecs onto a common_timestamp field will cause the
|
|
timestamp value to be in microseconds instead of the default
|
|
nanoseconds. A typical latency histogram using usecs would look like
|
|
this:
|
|
|
|
# echo 'hist:keys=pid,prio:ts0=common_timestamp.usecs ...
|
|
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0 ...
|
|
|
|
This also adds an external trace_clock_in_ns() to trace.c for the
|
|
timestamp conversion.
|
|
|
|
Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
|
|
Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
|
|
---
|
|
Documentation/trace/histogram.txt | 1 +
|
|
kernel/trace/trace.c | 13 +++++++++++--
|
|
kernel/trace/trace.h | 2 ++
|
|
kernel/trace/trace_events_hist.c | 28 ++++++++++++++++++++++------
|
|
4 files changed, 36 insertions(+), 8 deletions(-)
|
|
|
|
--- a/Documentation/trace/histogram.txt
|
|
+++ b/Documentation/trace/histogram.txt
|
|
@@ -74,6 +74,7 @@
|
|
.syscall display a syscall id as a system call name
|
|
.execname display a common_pid as a program name
|
|
.log2 display log2 value rather than raw number
|
|
+ .usecs display a common_timestamp in microseconds
|
|
|
|
Note that in general the semantics of a given field aren't
|
|
interpreted when applying a modifier to it, but there are some
|
|
--- a/kernel/trace/trace.c
|
|
+++ b/kernel/trace/trace.c
|
|
@@ -1170,6 +1170,14 @@ static struct {
|
|
ARCH_TRACE_CLOCKS
|
|
};
|
|
|
|
+bool trace_clock_in_ns(struct trace_array *tr)
|
|
+{
|
|
+ if (trace_clocks[tr->clock_id].in_ns)
|
|
+ return true;
|
|
+
|
|
+ return false;
|
|
+}
|
|
+
|
|
/*
|
|
* trace_parser_get_init - gets the buffer for trace parser
|
|
*/
|
|
@@ -4699,8 +4707,9 @@ static const char readme_msg[] =
|
|
"\t .sym display an address as a symbol\n"
|
|
"\t .sym-offset display an address as a symbol and offset\n"
|
|
"\t .execname display a common_pid as a program name\n"
|
|
- "\t .syscall display a syscall id as a syscall name\n\n"
|
|
- "\t .log2 display log2 value rather than raw number\n\n"
|
|
+ "\t .syscall display a syscall id as a syscall name\n"
|
|
+ "\t .log2 display log2 value rather than raw number\n"
|
|
+ "\t .usecs display a common_timestamp in microseconds\n\n"
|
|
"\t The 'pause' parameter can be used to pause an existing hist\n"
|
|
"\t trigger or to start a hist trigger but not log any events\n"
|
|
"\t until told to do so. 'continue' can be used to start or\n"
|
|
--- a/kernel/trace/trace.h
|
|
+++ b/kernel/trace/trace.h
|
|
@@ -289,6 +289,8 @@ extern void trace_array_put(struct trace
|
|
|
|
extern int tracing_set_time_stamp_abs(struct trace_array *tr, bool abs);
|
|
|
|
+extern bool trace_clock_in_ns(struct trace_array *tr);
|
|
+
|
|
/*
|
|
* The global tracer (top) should be the first trace array added,
|
|
* but we check the flag anyway.
|
|
--- a/kernel/trace/trace_events_hist.c
|
|
+++ b/kernel/trace/trace_events_hist.c
|
|
@@ -90,12 +90,6 @@ static u64 hist_field_log2(struct hist_f
|
|
return (u64) ilog2(roundup_pow_of_two(val));
|
|
}
|
|
|
|
-static u64 hist_field_timestamp(struct hist_field *hist_field, void *event,
|
|
- struct ring_buffer_event *rbe)
|
|
-{
|
|
- return ring_buffer_event_time_stamp(rbe);
|
|
-}
|
|
-
|
|
#define DEFINE_HIST_FIELD_FN(type) \
|
|
static u64 hist_field_##type(struct hist_field *hist_field, \
|
|
void *event, \
|
|
@@ -143,6 +137,7 @@ enum hist_field_flags {
|
|
HIST_FIELD_FL_STACKTRACE = 1 << 8,
|
|
HIST_FIELD_FL_LOG2 = 1 << 9,
|
|
HIST_FIELD_FL_TIMESTAMP = 1 << 10,
|
|
+ HIST_FIELD_FL_TIMESTAMP_USECS = 1 << 11,
|
|
};
|
|
|
|
struct hist_trigger_attrs {
|
|
@@ -153,6 +148,7 @@ struct hist_trigger_attrs {
|
|
bool pause;
|
|
bool cont;
|
|
bool clear;
|
|
+ bool ts_in_usecs;
|
|
unsigned int map_bits;
|
|
};
|
|
|
|
@@ -170,6 +166,20 @@ struct hist_trigger_data {
|
|
bool enable_timestamps;
|
|
};
|
|
|
|
+static u64 hist_field_timestamp(struct hist_field *hist_field, void *event,
|
|
+ struct ring_buffer_event *rbe)
|
|
+{
|
|
+ struct hist_trigger_data *hist_data = hist_field->hist_data;
|
|
+ struct trace_array *tr = hist_data->event_file->tr;
|
|
+
|
|
+ u64 ts = ring_buffer_event_time_stamp(rbe);
|
|
+
|
|
+ if (hist_data->attrs->ts_in_usecs && trace_clock_in_ns(tr))
|
|
+ ts = ns2usecs(ts);
|
|
+
|
|
+ return ts;
|
|
+}
|
|
+
|
|
static const char *hist_field_name(struct hist_field *field,
|
|
unsigned int level)
|
|
{
|
|
@@ -634,6 +644,8 @@ static int create_key_field(struct hist_
|
|
flags |= HIST_FIELD_FL_SYSCALL;
|
|
else if (strcmp(field_str, "log2") == 0)
|
|
flags |= HIST_FIELD_FL_LOG2;
|
|
+ else if (strcmp(field_str, "usecs") == 0)
|
|
+ flags |= HIST_FIELD_FL_TIMESTAMP_USECS;
|
|
else {
|
|
ret = -EINVAL;
|
|
goto out;
|
|
@@ -643,6 +655,8 @@ static int create_key_field(struct hist_
|
|
if (strcmp(field_name, "common_timestamp") == 0) {
|
|
flags |= HIST_FIELD_FL_TIMESTAMP;
|
|
hist_data->enable_timestamps = true;
|
|
+ if (flags & HIST_FIELD_FL_TIMESTAMP_USECS)
|
|
+ hist_data->attrs->ts_in_usecs = true;
|
|
key_size = sizeof(u64);
|
|
} else {
|
|
field = trace_find_event_field(file->event_call, field_name);
|
|
@@ -1243,6 +1257,8 @@ static const char *get_hist_field_flags(
|
|
flags_str = "syscall";
|
|
else if (hist_field->flags & HIST_FIELD_FL_LOG2)
|
|
flags_str = "log2";
|
|
+ else if (hist_field->flags & HIST_FIELD_FL_TIMESTAMP_USECS)
|
|
+ flags_str = "usecs";
|
|
|
|
return flags_str;
|
|
}
|