Re: [PATCH v8 08/18] perf ftrace: add support for tracing option 'func_stack_trace'

[Changbin Du <changbin.du@gmail.com>]

On Fri, Aug 14, 2020 at 09:24:40AM -0300, Arnaldo Carvalho de Melo wrote:
> Em Sat, Aug 08, 2020 at 10:31:31AM +0800, Changbin Du escreveu:
> > This adds support to display call trace for function tracer. To do this,
> > just specify a '--func-opts call-graph' option.
> 
> Applied, thanks for providing the usage example and the output of the
> tool, please consider making this more compact and similar to the other
> perf tools as:
> 
>    # perf ftrace -g -T vfs_read
> 
>   # perf report -h -g
>   
>    Usage: perf report [<options>]
>   
>       -g, --call-graph <print_type,threshold[,print_limit],order,sort_key[,branch],value>
>                             Display call graph (stack chain/backtrace):
>   
>                                   print_type:     call graph printing style (graph|flat|fractal|folded|none)
>                                   threshold:      minimum call graph inclusion threshold (<percent>)
>                                   print_limit:    maximum number of call graph entry (<number>)
>                                   order:          call graph order (caller|callee)
>                                   sort_key:       call graph sort key (function|address)
>                                   branch:         include last branch info to call graph (branch)
>                                   value:          call graph value (percent|period|count)
>   
>                                   Default: graph,0.5,caller,function,percent
>   
>   # 
> 
> Is there a way to ask for a limit in the number of levels? That is
> similar to /proc/sys/kernel/perf_event_max_stack (system wide) and
> perf_event_attr.sample_max_stack (per event)?
> 
No, there is no such limit for function tracer yet (kernel doesn't support it).
It just backtraces from current to top.

For graph tracer, the option is --graph-opts depth=<n>.

> One can ask for that per event:
> 
>   # perf trace -e sched:*_wakeup/max-stack=2/ -e sched:*switch/max-stack=5/ --max-events=4
>      0.000 migration/0/12 sched:sched_switch(prev_comm: "migration/0", prev_pid: 12 (migration/0), prev_prio: 0, prev_state: 1, next_comm: "swapper/0", next_pid: 0, next_prio: 120)
>                                        __schedule ([kernel.kallsyms])
>                                        __schedule ([kernel.kallsyms])
>                                        schedule ([kernel.kallsyms])
>                                        smpboot_thread_fn ([kernel.kallsyms])
>                                        kthread ([kernel.kallsyms])
>      2.381 :0/0 sched:sched_wakeup(comm: "PacerThread", pid: 111637 (PacerThread), prio: 120, success: 1, target_cpu: 0)
>                                        ttwu_do_wakeup ([kernel.kallsyms])
>                                        ttwu_do_wakeup ([kernel.kallsyms])
>      2.387 :0/0 sched:sched_switch(prev_comm: "swapper/0", prev_pid: 0, prev_prio: 120, prev_state: 0, next_comm: "PacerThread", next_pid: 111637 (PacerThread), next_prio: 120)
>                                        __schedule ([kernel.kallsyms])
>                                        __schedule ([kernel.kallsyms])
>                                        schedule_idle ([kernel.kallsyms])
>                                        do_idle ([kernel.kallsyms])
>                                        cpu_startup_entry ([kernel.kallsyms])
>      2.410 PacerThread/111637 sched:sched_switch(prev_comm: "PacerThread", prev_pid: 111637 (PacerThread), prev_prio: 120, prev_state: 1, next_comm: "swapper/0", next_pid: 0, next_prio: 120)
>                                        __schedule ([kernel.kallsyms])
>                                        __schedule ([kernel.kallsyms])
>                                        schedule ([kernel.kallsyms])
>                                        futex_wait_queue_me ([kernel.kallsyms])
>                                        futex_wait ([kernel.kallsyms])
>   #
> 
> - Arnaldo
>  
> > $ sudo perf ftrace -T vfs_read --func-opts call-graph
> >  iio-sensor-prox-855   [003]   6168.369657: vfs_read <-ksys_read
> >  iio-sensor-prox-855   [003]   6168.369677: <stack trace>
> >  => vfs_read
> >  => ksys_read
> >  => __x64_sys_read
> >  => do_syscall_64
> >  => entry_SYSCALL_64_after_hwframe
> >  ...
> > 
> > Signed-off-by: Changbin Du <changbin.du@gmail.com>
> > 
> > ---
> > v3: switch to uniform option --func-opts.
> > v2: option name '-s' -> '--func-call-graph'
> > ---
> >  tools/perf/Documentation/perf-ftrace.txt |  4 +++
> >  tools/perf/builtin-ftrace.c              | 42 ++++++++++++++++++++++++
> >  2 files changed, 46 insertions(+)
> > 
> > diff --git a/tools/perf/Documentation/perf-ftrace.txt b/tools/perf/Documentation/perf-ftrace.txt
> > index c46d0a09b38c..8f08ad0992c2 100644
> > --- a/tools/perf/Documentation/perf-ftrace.txt
> > +++ b/tools/perf/Documentation/perf-ftrace.txt
> > @@ -76,6 +76,10 @@ OPTIONS
> >  	specify multiple functions (or glob patterns).  It will be
> >  	passed to 'set_ftrace_notrace' in tracefs.
> >  
> > +--func-opts::
> > +	List of options allowed to set:
> > +	  call-graph - Display kernel stack trace for function tracer.
> > +
> >  -G::
> >  --graph-funcs=::
> >  	Select function_graph tracer and set graph filter on the given
> > diff --git a/tools/perf/builtin-ftrace.c b/tools/perf/builtin-ftrace.c
> > index 07b81d0c1658..469b89748c42 100644
> > --- a/tools/perf/builtin-ftrace.c
> > +++ b/tools/perf/builtin-ftrace.c
> > @@ -27,6 +27,7 @@
> >  #include "util/cap.h"
> >  #include "util/config.h"
> >  #include "util/units.h"
> > +#include "util/parse-sublevel-options.h"
> >  
> >  #define DEFAULT_TRACER  "function_graph"
> >  
> > @@ -42,6 +43,7 @@ struct perf_ftrace {
> >  	int			graph_depth;
> >  	unsigned long		percpu_buffer_size;
> >  	bool			inherit;
> > +	int			func_stack_trace;
> >  };
> >  
> >  struct filter_entry {
> > @@ -202,6 +204,7 @@ static void reset_tracing_filters(void);
> >  static void reset_tracing_options(struct perf_ftrace *ftrace __maybe_unused)
> >  {
> >  	write_tracing_option_file("function-fork", "0");
> > +	write_tracing_option_file("func_stack_trace", "0");
> >  }
> >  
> >  static int reset_tracing_files(struct perf_ftrace *ftrace __maybe_unused)
> > @@ -278,6 +281,17 @@ static int set_tracing_cpu(struct perf_ftrace *ftrace)
> >  	return set_tracing_cpumask(cpumap);
> >  }
> >  
> > +static int set_tracing_func_stack_trace(struct perf_ftrace *ftrace)
> > +{
> > +	if (!ftrace->func_stack_trace)
> > +		return 0;
> > +
> > +	if (write_tracing_option_file("func_stack_trace", "1") < 0)
> > +		return -1;
> > +
> > +	return 0;
> > +}
> > +
> >  static int reset_tracing_cpu(void)
> >  {
> >  	struct perf_cpu_map *cpumap = perf_cpu_map__new(NULL);
> > @@ -426,6 +440,11 @@ static int __cmd_ftrace(struct perf_ftrace *ftrace, int argc, const char **argv)
> >  		goto out_reset;
> >  	}
> >  
> > +	if (set_tracing_func_stack_trace(ftrace) < 0) {
> > +		pr_err("failed to set tracing option func_stack_trace\n");
> > +		goto out_reset;
> > +	}
> > +
> >  	if (set_tracing_filters(ftrace) < 0) {
> >  		pr_err("failed to set tracing filters\n");
> >  		goto out_reset;
> > @@ -598,6 +617,26 @@ static int parse_buffer_size(const struct option *opt,
> >  	return -1;
> >  }
> >  
> > +static int parse_func_tracer_opts(const struct option *opt,
> > +				  const char *str, int unset)
> > +{
> > +	int ret;
> > +	struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value;
> > +	struct sublevel_option func_tracer_opts[] = {
> > +		{ .name = "call-graph",	.value_ptr = &ftrace->func_stack_trace },
> > +		{ .name = NULL, }
> > +	};
> > +
> > +	if (unset)
> > +		return 0;
> > +
> > +	ret = perf_parse_sublevel_options(str, func_tracer_opts);
> > +	if (ret)
> > +		return ret;
> > +
> > +	return 0;
> > +}
> > +
> >  static void select_tracer(struct perf_ftrace *ftrace)
> >  {
> >  	bool graph = !list_empty(&ftrace->graph_funcs) ||
> > @@ -645,6 +684,9 @@ int cmd_ftrace(int argc, const char **argv)
> >  		     parse_filter_func),
> >  	OPT_CALLBACK('N', "notrace-funcs", &ftrace.notrace, "func",
> >  		     "do not trace given functions", parse_filter_func),
> > +	OPT_CALLBACK(0, "func-opts", &ftrace, "options",
> > +		     "function tracer options, available options: call-graph",
> > +		     parse_func_tracer_opts),
> >  	OPT_CALLBACK('G', "graph-funcs", &ftrace.graph_funcs, "func",
> >  		     "trace given functions using function_graph tracer",
> >  		     parse_filter_func),
> > -- 
> > 2.25.1
> > 
> 
> -- 
> 
> - Arnaldo

-- 
Cheers,
Changbin Du