function-graph: add option to calculate graph time or not
authorSteven Rostedt <srostedt@redhat.com>
Wed, 25 Mar 2009 03:17:58 +0000 (23:17 -0400)
committerSteven Rostedt <srostedt@redhat.com>
Wed, 25 Mar 2009 03:41:11 +0000 (23:41 -0400)
graph time is the time that a function is executing another function.
Thus if function A calls B, if graph-time is set, then the time for
A includes B. This is the default behavior. But if graph-time is off,
then the time spent executing B is subtracted from A.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
include/linux/ftrace.h
kernel/trace/ftrace.c
kernel/trace/trace.c
kernel/trace/trace.h
kernel/trace/trace_functions_graph.c

index 015a3d22cf7434deb500233623ae14b778d05e5b..9e0a8d245e55dc382354328da3002ecbe5df6d86 100644 (file)
@@ -365,6 +365,7 @@ struct ftrace_ret_stack {
        unsigned long ret;
        unsigned long func;
        unsigned long long calltime;
+       unsigned long long subtime;
 };
 
 /*
@@ -376,8 +377,6 @@ extern void return_to_handler(void);
 
 extern int
 ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth);
-extern void
-ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret);
 
 /*
  * Sometimes we don't want to trace a function with the function
index ed1fc5021d441d15e97f0c6e3da932347b6727c9..71e5faef12ab912a7c5e7589348f04d0621ae4ce 100644 (file)
@@ -604,6 +604,7 @@ static int profile_graph_entry(struct ftrace_graph_ent *trace)
 static void profile_graph_return(struct ftrace_graph_ret *trace)
 {
        struct ftrace_profile_stat *stat;
+       unsigned long long calltime;
        struct ftrace_profile *rec;
        unsigned long flags;
 
@@ -612,9 +613,27 @@ static void profile_graph_return(struct ftrace_graph_ret *trace)
        if (!stat->hash)
                goto out;
 
+       calltime = trace->rettime - trace->calltime;
+
+       if (!(trace_flags & TRACE_ITER_GRAPH_TIME)) {
+               int index;
+
+               index = trace->depth;
+
+               /* Append this call time to the parent time to subtract */
+               if (index)
+                       current->ret_stack[index - 1].subtime += calltime;
+
+               if (current->ret_stack[index].subtime < calltime)
+                       calltime -= current->ret_stack[index].subtime;
+               else
+                       calltime = 0;
+       }
+
        rec = ftrace_find_profiled_func(stat, trace->func);
        if (rec)
-               rec->time += trace->rettime - trace->calltime;
+               rec->time += calltime;
+
  out:
        local_irq_restore(flags);
 }
index 821bf49771d4cf842f09f2b070c159b74ed28231..5d1a16cae3761d9d4f8653118cca429c38ba9344 100644 (file)
@@ -255,7 +255,8 @@ static DECLARE_WAIT_QUEUE_HEAD(trace_wait);
 
 /* trace_flags holds trace_options default values */
 unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
-       TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO | TRACE_ITER_SLEEP_TIME;
+       TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO | TRACE_ITER_SLEEP_TIME |
+       TRACE_ITER_GRAPH_TIME;
 
 /**
  * trace_wake_up - wake up tasks waiting for trace input
@@ -317,6 +318,7 @@ static const char *trace_options[] = {
        "latency-format",
        "global-clock",
        "sleep-time",
+       "graph-time",
        NULL
 };
 
index c66ca3b6605027b624d61c7aedc116b2374eb812..e3429a8ab0596a879447e2861d0911a6ba1d5856 100644 (file)
@@ -685,6 +685,7 @@ enum trace_iterator_flags {
        TRACE_ITER_LATENCY_FMT          = 0x40000,
        TRACE_ITER_GLOBAL_CLK           = 0x80000,
        TRACE_ITER_SLEEP_TIME           = 0x100000,
+       TRACE_ITER_GRAPH_TIME           = 0x200000,
 };
 
 /*
index 85bba0f018b04cd115bb3b4d73fe7a5d642708a1..10f6ad7d85f655e9bea1fa8af0ef868138dfa5f7 100644 (file)
@@ -78,13 +78,14 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth)
        current->ret_stack[index].ret = ret;
        current->ret_stack[index].func = func;
        current->ret_stack[index].calltime = calltime;
+       current->ret_stack[index].subtime = 0;
        *depth = index;
 
        return 0;
 }
 
 /* Retrieve a function return address to the trace stack on thread info.*/
-void
+static void
 ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
 {
        int index;
@@ -104,9 +105,6 @@ ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
        trace->calltime = current->ret_stack[index].calltime;
        trace->overrun = atomic_read(&current->trace_overrun);
        trace->depth = index;
-       barrier();
-       current->curr_ret_stack--;
-
 }
 
 /*
@@ -121,6 +119,8 @@ unsigned long ftrace_return_to_handler(void)
        ftrace_pop_return_trace(&trace, &ret);
        trace.rettime = trace_clock_local();
        ftrace_graph_return(&trace);
+       barrier();
+       current->curr_ret_stack--;
 
        if (unlikely(!ret)) {
                ftrace_graph_stop();