[PATCH] tracing, function graph: Remove the noisy output when use function graph filter

[PATCH] tracing, function graph: Remove the noisy output when use function graph filter

[Lai Jiangshan]

If we use function graph filter(echo some_functions >> set_graph_function)
we are only interested in the graph of some_functions.

But if a interrupt occurs when these functions are being traced(or preparing),
the graphs of the handlers of this interrupt are also recorded.
These events that we aren't interested in are totally noisy.

This patch remove them(very very seldom noise is still left,
It's OK for tracing, doesn't it?).

Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
---
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 79f4bac..9c130b3 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -12,6 +12,8 @@
 #include <linux/slab.h>
 #include <linux/fs.h>
 
+#include <asm/irq_regs.h>
+
 #include "trace.h"
 #include "trace_output.h"
 
@@ -213,13 +215,19 @@ int trace_graph_entry(struct ftrace_graph_ent *trace)
 	int ret;
 	int cpu;
 	int pc;
+	int depth = trace->depth;
+	unsigned long long cntxt = (unsigned long)(void *)get_irq_regs();
 
 	if (!ftrace_trace_task(current))
 		return 0;
 
 	/* trace it when it is-nested-in or is a function enabled. */
-	if (!(trace->depth || ftrace_graph_addr(trace->func)))
-		return 0;
+	if (!ftrace_graph_addr(trace->func)) {
+		if (!depth || current->ret_stack[depth - 1].subtime != cntxt)
+			return 0;
+	}
+	/* We don't use subtime here, reuse it to save context. */
+	current->ret_stack[depth].subtime = cntxt;
 
 	local_irq_save(flags);
 	cpu = raw_smp_processor_id();

Re: [PATCH] tracing, function graph: Remove the noisy output when use function graph filter

[Steven Rostedt]

On Thu, 2010-06-17 at 16:58 +0800, Lai Jiangshan wrote:
> If we use function graph filter(echo some_functions >> set_graph_function)
> we are only interested in the graph of some_functions.
> 
> But if a interrupt occurs when these functions are being traced(or preparing),
> the graphs of the handlers of this interrupt are also recorded.
> These events that we aren't interested in are totally noisy.

Umm, sorry, I prefer the noise.  When analyzing the network stack, I
like to see the interrupts that preempt the code.

What you could do is add an function_graph option that disables it, but
do not make it the default.

> 
> This patch remove them(very very seldom noise is still left,
> It's OK for tracing, doesn't it?).
> 
> Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
> ---
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index 79f4bac..9c130b3 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -12,6 +12,8 @@
>  #include <linux/slab.h>
>  #include <linux/fs.h>
>  
> +#include <asm/irq_regs.h>
> +
>  #include "trace.h"
>  #include "trace_output.h"
>  
> @@ -213,13 +215,19 @@ int trace_graph_entry(struct ftrace_graph_ent *trace)
>  	int ret;
>  	int cpu;
>  	int pc;
> +	int depth = trace->depth;
> +	unsigned long long cntxt = (unsigned long)(void *)get_irq_regs();
>  
>  	if (!ftrace_trace_task(current))
>  		return 0;
>  
>  	/* trace it when it is-nested-in or is a function enabled. */
> -	if (!(trace->depth || ftrace_graph_addr(trace->func)))
> -		return 0;
> +	if (!ftrace_graph_addr(trace->func)) {
> +		if (!depth || current->ret_stack[depth - 1].subtime != cntxt)
> +			return 0;
> +	}

This will slow down the tracing when inside the function. You are
testing every function to see if we should show the trace, even when we
are inside a function we are tracing.


> +	/* We don't use subtime here, reuse it to save context. */
> +	current->ret_stack[depth].subtime = cntxt;

This should then be a union if it is used for two things. That documents
it better.


>  
>  	local_irq_save(flags);
>  	cpu = raw_smp_processor_id();

If you make the above into an option, then we can have

	int no_irqs = tracer_flags.val & TRACE_GRAPH_NO_IRQS;
	[...]

	if (!(trace->depth || ftrace_graph_addr(trace->func)))
		return 0;

	if (no_irqs) {
		cntx = (unsigned long)(void *)get_irq_regs();
		if (trace->depth &&
		    current->ret_stack[depth - 1].subtime != cntxt)
			return 0;
		current->ret_stack[depth].subtime = cntxt;
	}

Also, I'm not really happy about the double use of subtime. It pevents
the function graph from ever ignoring the time it calls the child
functions.

-- Steve