alistair23-linux/kernel/trace/trace_functions_graph.c
Steven Rostedt 437f24fb89 ftrace: add cpu annotation for function graph tracer
Impact: enhancement for function graph tracer

When run on a SMP box, the function graph tracer is confusing because
it shows the different CPUS as changes in the trace.

This patch adds the annotation of 'CPU[###]' where ### is a three digit
number. The output will look similar to this:

CPU[001]     dput() {
CPU[000] } 726
CPU[001]     } 487
CPU[000] do_softirq() {
CPU[001]   } 2221
CPU[000]   __do_softirq() {
CPU[000]     __local_bh_disable() {
CPU[001]   unroll_tree_refs() {
CPU[000]     } 569
CPU[001]   } 501
CPU[000]     rcu_process_callbacks() {
CPU[001]   kfree() {

What makes this nice is that now you can grep the file and produce
readable format for a particular CPU.

 # cat /debug/tracing/trace > /tmp/trace
 # grep '^CPU\[000\]' /tmp/trace > /tmp/trace0
 # grep '^CPU\[001\]' /tmp/trace > /tmp/trace1

Will give you:

 # head /tmp/trace0
CPU[000] ------------8<---------- thread sshd-3899 ------------8<----------
CPU[000]     inotify_dentry_parent_queue_event() {
CPU[000]     } 2531
CPU[000]     inotify_inode_queue_event() {
CPU[000]     } 505
CPU[000]   } 69626
CPU[000] } 73089
CPU[000] audit_syscall_exit() {
CPU[000]   path_put() {
CPU[000]     dput() {

 # head /tmp/trace1
CPU[001] ------------8<---------- thread pcscd-3446 ------------8<----------
CPU[001]               } 4186
CPU[001]               dput() {
CPU[001]               } 543
CPU[001]               vfs_permission() {
CPU[001]                 inode_permission() {
CPU[001]                   shmem_permission() {
CPU[001]                     generic_permission() {
CPU[001]                     } 501
CPU[001]                   } 2205

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
2008-11-26 06:52:57 +01:00

176 lines
3.9 KiB
C

/*
*
* Function graph tracer.
* Copyright (c) 2008 Frederic Weisbecker <fweisbec@gmail.com>
* Mostly borrowed from function tracer which
* is Copyright (c) Steven Rostedt <srostedt@redhat.com>
*
*/
#include <linux/debugfs.h>
#include <linux/uaccess.h>
#include <linux/ftrace.h>
#include <linux/fs.h>
#include "trace.h"
#define TRACE_GRAPH_INDENT 2
#define TRACE_GRAPH_PRINT_OVERRUN 0x1
static struct tracer_opt trace_opts[] = {
/* Display overruns or not */
{ TRACER_OPT(overrun, TRACE_GRAPH_PRINT_OVERRUN) },
{ } /* Empty entry */
};
static struct tracer_flags tracer_flags = {
.val = 0, /* Don't display overruns by default */
.opts = trace_opts
};
/* pid on the last trace processed */
static pid_t last_pid[NR_CPUS] = { [0 ... NR_CPUS-1] = -1 };
static int graph_trace_init(struct trace_array *tr)
{
int cpu, ret;
for_each_online_cpu(cpu)
tracing_reset(tr, cpu);
ret = register_ftrace_graph(&trace_graph_return,
&trace_graph_entry);
if (ret)
return ret;
tracing_start_cmdline_record();
return 0;
}
static void graph_trace_reset(struct trace_array *tr)
{
tracing_stop_cmdline_record();
unregister_ftrace_graph();
}
/* If the pid changed since the last trace, output this event */
static int verif_pid(struct trace_seq *s, pid_t pid, int cpu)
{
char *comm;
if (last_pid[cpu] != -1 && last_pid[cpu] == pid)
return 1;
last_pid[cpu] = pid;
comm = trace_find_cmdline(pid);
return trace_seq_printf(s, "\nCPU[%03d]"
" ------------8<---------- thread %s-%d"
" ------------8<----------\n\n",
cpu, comm, pid);
}
static enum print_line_t
print_graph_entry(struct ftrace_graph_ent *call, struct trace_seq *s,
struct trace_entry *ent, int cpu)
{
int i;
int ret;
if (!verif_pid(s, ent->pid, cpu))
return TRACE_TYPE_PARTIAL_LINE;
ret = trace_seq_printf(s, "CPU[%03d] ", cpu);
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
ret = trace_seq_printf(s, " ");
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
}
ret = seq_print_ip_sym(s, call->func, 0);
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
ret = trace_seq_printf(s, "() {\n");
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
return TRACE_TYPE_HANDLED;
}
static enum print_line_t
print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
struct trace_entry *ent, int cpu)
{
int i;
int ret;
if (!verif_pid(s, ent->pid, cpu))
return TRACE_TYPE_PARTIAL_LINE;
ret = trace_seq_printf(s, "CPU[%03d] ", cpu);
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
ret = trace_seq_printf(s, " ");
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
}
ret = trace_seq_printf(s, "} ");
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
ret = trace_seq_printf(s, "%llu\n", trace->rettime - trace->calltime);
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) {
ret = trace_seq_printf(s, " (Overruns: %lu)\n",
trace->overrun);
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
}
return TRACE_TYPE_HANDLED;
}
enum print_line_t
print_graph_function(struct trace_iterator *iter)
{
struct trace_seq *s = &iter->seq;
struct trace_entry *entry = iter->ent;
switch (entry->type) {
case TRACE_GRAPH_ENT: {
struct ftrace_graph_ent_entry *field;
trace_assign_type(field, entry);
return print_graph_entry(&field->graph_ent, s, entry,
iter->cpu);
}
case TRACE_GRAPH_RET: {
struct ftrace_graph_ret_entry *field;
trace_assign_type(field, entry);
return print_graph_return(&field->ret, s, entry, iter->cpu);
}
default:
return TRACE_TYPE_UNHANDLED;
}
}
static struct tracer graph_trace __read_mostly = {
.name = "function-graph",
.init = graph_trace_init,
.reset = graph_trace_reset,
.print_line = print_graph_function,
.flags = &tracer_flags,
};
static __init int init_graph_trace(void)
{
return register_tracer(&graph_trace);
}
device_initcall(init_graph_trace);