Commit-ID: 49ff590390a22c49e9063dcdec4cd5903127526b
Gitweb: http://git.kernel.org/tip/49ff590390a22c49e9063dcdec4cd5903127526b
Author: Steven Rostedt <srostedt@xxxxxxxxxx>
AuthorDate: Fri, 11 Sep 2009 00:30:26 -0400
Committer: Steven Rostedt <rostedt@xxxxxxxxxxx>
CommitDate: Fri, 11 Sep 2009 10:59:49 -0400
tracing: add latency format to function_graph tracer
While debugging something with the function_graph tracer, I found the
need to see the preempt count of the traces. Unfortunately, since
the function graph tracer has its own output formatting, it does not
honor the latency-format option.
This patch makes the function_graph tracer honor the latency-format
option, but still keeps control of the output. But now we have the
same details that the latency-format supplies.
# tracer: function_graph
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| /
# ||||
# CPU|||| DURATION FUNCTION CALLS
# | |||| | | | | | |
3) d..1 1.333 us | idle_cpu();
3) d.h1 | tick_check_idle() {
3) d.h1 0.550 us | tick_check_oneshot_broadcast();
3) d.h1 | tick_nohz_stop_idle() {
3) d.h1 | ktime_get() {
3) d.h1 | ktime_get_ts() {
Signed-off-by: Steven Rostedt <rostedt@xxxxxxxxxxx>
---
kernel/trace/trace_functions_graph.c | 74 +++++++++++++++++++++++++++++++---
1 files changed, 68 insertions(+), 6 deletions(-)
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index b3749a2..ee791a9 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -364,6 +364,29 @@ print_graph_proc(struct trace_seq *s, pid_t pid)
}
+static enum print_line_t
+print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
+{
+ int hardirq, softirq;
+
+ hardirq = entry->flags & TRACE_FLAG_HARDIRQ;
+ softirq = entry->flags & TRACE_FLAG_SOFTIRQ;
+
+ if (!trace_seq_printf(s, " %c%c%c",
+ (entry->flags & TRACE_FLAG_IRQS_OFF) ? 'd' :
+ (entry->flags & TRACE_FLAG_IRQS_NOSUPPORT) ?
+ 'X' : '.',
+ (entry->flags & TRACE_FLAG_NEED_RESCHED) ?
+ 'N' : '.',
+ (hardirq && softirq) ? 'H' :
+ hardirq ? 'h' : softirq ? 's' : '.'))
+ return 0;
+
+ if (entry->preempt_count)
+ return trace_seq_printf(s, "%x", entry->preempt_count);
+ return trace_seq_puts(s, ".");
+}
+
/* If the pid changed since the last trace, output this event */
static enum print_line_t
verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
@@ -521,6 +544,7 @@ print_graph_irq(struct trace_iterator *iter, unsigned long addr,
if (ret == TRACE_TYPE_PARTIAL_LINE)
return TRACE_TYPE_PARTIAL_LINE;
}
+
/* Proc */
if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
ret = print_graph_proc(s, pid);
@@ -758,6 +782,13 @@ print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
return TRACE_TYPE_PARTIAL_LINE;
}
+ /* Latency format */
+ if (trace_flags & TRACE_ITER_LATENCY_FMT) {
+ ret = print_graph_lat_fmt(s, ent);
+ if (ret == TRACE_TYPE_PARTIAL_LINE)
+ return TRACE_TYPE_PARTIAL_LINE;
+ }
+
return 0;
}
@@ -952,28 +983,59 @@ print_graph_function(struct trace_iterator *iter)
return TRACE_TYPE_HANDLED;
}
+static void print_lat_header(struct seq_file *s)
+{
+ static const char spaces[] = " " /* 16 spaces */
+ " " /* 4 spaces */
+ " "; /* 17 spaces */
+ int size = 0;
+
+ if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
+ size += 16;
+ if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
+ size += 4;
+ if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
+ size += 17;
+
+ seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces);
+ seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces);
+ seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces);
+ seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces);
+ seq_printf(s, "#%.*s||| / \n", size, spaces);
+ seq_printf(s, "#%.*s|||| \n", size, spaces);
+}
+
static void print_graph_headers(struct seq_file *s)
{
+ int lat = trace_flags & TRACE_ITER_LATENCY_FMT;
+
+ if (lat)
+ print_lat_header(s);
+
/* 1st line */
- seq_printf(s, "# ");
+ seq_printf(s, "#");
if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
seq_printf(s, " TIME ");
if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
- seq_printf(s, "CPU");
+ seq_printf(s, " CPU");
if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
- seq_printf(s, " TASK/PID ");
+ seq_printf(s, " TASK/PID ");
+ if (lat)
+ seq_printf(s, "||||");
if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
seq_printf(s, " DURATION ");
seq_printf(s, " FUNCTION CALLS\n");
/* 2nd line */
- seq_printf(s, "# ");
+ seq_printf(s, "#");
if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
seq_printf(s, " | ");
if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
- seq_printf(s, "| ");
+ seq_printf(s, " | ");
if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
- seq_printf(s, " | | ");
+ seq_printf(s, " | | ");
+ if (lat)
+ seq_printf(s, "||||");
if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
seq_printf(s, " | | ");
seq_printf(s, " | | | |\n");
--
To unsubscribe from this list: send the line "unsubscribe linux-tip-commits" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
|