Re: [PATCH 5/5] perf probe: Trace a magic number if variable is not found

[Arnaldo Carvalho de Melo <arnaldo.melo@gmail.com>]

Em Tue, Nov 05, 2019 at 09:17:28AM +0900, Masami Hiramatsu escreveu:
> Trace a magic number as immediate value if the target variable
> is not found at some probe points which is based on one probe
> event.
> 
> This feature is good for the case if you trace a source code
> line with some local variables, which is compiled into several
> instructions and some of the variables are optimized out on
> some instructions. Even if so, with this feature, perf probe
> trace a magic number instead of such disappeared variables and
> fold those probes on one event.

This too depends on a function introduced in previous patches on hold.

- Arnaldo
 
> E.g. without this patch,
> # perf probe -D "pud_page_vaddr pud"
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> Failed to find 'pud' in this function.
> p:probe/pud_page_vaddr_L0 _text+23480787 pud=%ax:x64
> p:probe/pud_page_vaddr_L0 _text+23808289 pud=%bp:x64
> p:probe/pud_page_vaddr_L0 _text+23558066 pud=%ax:x64
> p:probe/pud_page_vaddr_L0 _text+327957 pud=%r8:x64
> p:probe/pud_page_vaddr_L0 _text+348032 pud=%bx:x64
> p:probe/pud_page_vaddr_L0 _text+23816654 pud=%bx:x64
> 
> With this patch,
> # perf probe -D "pud_page_vaddr pud" | head -n 10
> spurious_kernel_fault is blacklisted function, skip it.
> vmalloc_fault is blacklisted function, skip it.
> p:probe/pud_page_vaddr_L0 _text+23480787 pud=%ax:x64
> p:probe/pud_page_vaddr_L0 _text+148635 pud=\deade12d:x64
> p:probe/pud_page_vaddr_L0 _text+23808289 pud=%bp:x64
> p:probe/pud_page_vaddr_L0 _text+315510 pud=\deade12d:x64
> p:probe/pud_page_vaddr_L0 _text+23807045 pud=\deade12d:x64
> p:probe/pud_page_vaddr_L0 _text+23557349 pud=%ax:x64
> p:probe/pud_page_vaddr_L0 _text+313681 pud=%di:x64
> p:probe/pud_page_vaddr_L0 _text+313599 pud=\deade12d:x64
> p:probe/pud_page_vaddr_L0 _text+313477 pud=\deade12d:x64
> p:probe/pud_page_vaddr_L0 _text+323667 pud=\deade12d:x64
> 
> 
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> ---
>  tools/perf/util/probe-event.c  |    2 +
>  tools/perf/util/probe-event.h  |    3 ++
>  tools/perf/util/probe-finder.c |   62 +++++++++++++++++++++++++++++++++++++---
>  tools/perf/util/probe-finder.h |    1 +
>  4 files changed, 63 insertions(+), 5 deletions(-)
> 
> diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
> index 23db6786c3ea..ceeb75849311 100644
> --- a/tools/perf/util/probe-event.c
> +++ b/tools/perf/util/probe-event.c
> @@ -46,7 +46,7 @@
>  #define PERFPROBE_GROUP "probe"
>  
>  bool probe_event_dry_run;	/* Dry run flag */
> -struct probe_conf probe_conf;
> +struct probe_conf probe_conf = { .magic_num = DEFAULT_PROBE_MAGIC_NUM };
>  
>  #define semantic_error(msg ...) pr_err("Semantic error :" msg)
>  
> diff --git a/tools/perf/util/probe-event.h b/tools/perf/util/probe-event.h
> index 96a319cd2378..4f0eb3a20c36 100644
> --- a/tools/perf/util/probe-event.h
> +++ b/tools/perf/util/probe-event.h
> @@ -16,10 +16,13 @@ struct probe_conf {
>  	bool	no_inlines;
>  	bool	cache;
>  	int	max_probes;
> +	unsigned long	magic_num;
>  };
>  extern struct probe_conf probe_conf;
>  extern bool probe_event_dry_run;
>  
> +#define DEFAULT_PROBE_MAGIC_NUM	0xdeade12d	/* u32: 3735937325 */
> +
>  struct symbol;
>  
>  /* kprobe-tracer and uprobe-tracer tracing point */
> diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
> index 2e3a468c8350..eff6063bebe6 100644
> --- a/tools/perf/util/probe-finder.c
> +++ b/tools/perf/util/probe-finder.c
> @@ -536,6 +536,14 @@ static int convert_variable_fields(Dwarf_Die *vr_die, const char *varname,
>  		return 0;
>  }
>  
> +static void print_var_not_found(const char *varname)
> +{
> +	pr_err("Failed to find the location of the '%s' variable at this address.\n"
> +	       " Perhaps it has been optimized out.\n"
> +	       " Use -V with the --range option to show '%s' location range.\n",
> +		varname, varname);
> +}
> +
>  /* Show a variables in kprobe event format */
>  static int convert_variable(Dwarf_Die *vr_die, struct probe_finder *pf)
>  {
> @@ -547,11 +555,11 @@ static int convert_variable(Dwarf_Die *vr_die, struct probe_finder *pf)
>  
>  	ret = convert_variable_location(vr_die, pf->addr, pf->fb_ops,
>  					&pf->sp_die, pf->machine, pf->tvar);
> +	if (ret == -ENOENT && pf->skip_empty_arg)
> +		/* This can be found in other place. skip it */
> +		return 0;
>  	if (ret == -ENOENT || ret == -EINVAL) {
> -		pr_err("Failed to find the location of the '%s' variable at this address.\n"
> -		       " Perhaps it has been optimized out.\n"
> -		       " Use -V with the --range option to show '%s' location range.\n",
> -		       pf->pvar->var, pf->pvar->var);
> +		print_var_not_found(pf->pvar->var);
>  	} else if (ret == -ENOTSUP)
>  		pr_err("Sorry, we don't support this variable location yet.\n");
>  	else if (ret == 0 && pf->pvar->field) {
> @@ -598,6 +606,8 @@ static int find_variable(Dwarf_Die *sc_die, struct probe_finder *pf)
>  		/* Search again in global variables */
>  		if (!die_find_variable_at(&pf->cu_die, pf->pvar->var,
>  						0, &vr_die)) {
> +			if (pf->skip_empty_arg)
> +				return 0;
>  			pr_warning("Failed to find '%s' in this function.\n",
>  				   pf->pvar->var);
>  			ret = -ENOENT;
> @@ -1348,6 +1358,44 @@ static int add_probe_trace_event(Dwarf_Die *sc_die, struct probe_finder *pf)
>  	return ret;
>  }
>  
> +static int fill_empty_trace_arg(struct perf_probe_event *pev,
> +				struct probe_trace_event *tevs, int ntevs)
> +{
> +	char **valp;
> +	char *type;
> +	int i, j, ret;
> +
> +	for (i = 0; i < pev->nargs; i++) {
> +		type = NULL;
> +		for (j = 0; j < ntevs; j++) {
> +			if (tevs[j].args[i].value) {
> +				type = tevs[j].args[i].type;
> +				break;
> +			}
> +		}
> +		if (j == ntevs) {
> +			print_var_not_found(pev->args[i].var);
> +			return -ENOENT;
> +		}
> +		for (j = 0; j < ntevs; j++) {
> +			valp = &tevs[j].args[i].value;
> +			if (*valp)
> +				continue;
> +
> +			ret = asprintf(valp, "\\%lx", probe_conf.magic_num);
> +			if (ret < 0)
> +				return -ENOMEM;
> +			/* Note that type can be NULL */
> +			if (type) {
> +				tevs[j].args[i].type = strdup(type);
> +				if (!tevs[j].args[i].type)
> +					return -ENOMEM;
> +			}
> +		}
> +	}
> +	return 0;
> +}
> +
>  /* Find probe_trace_events specified by perf_probe_event from debuginfo */
>  int debuginfo__find_trace_events(struct debuginfo *dbg,
>  				 struct perf_probe_event *pev,
> @@ -1366,7 +1414,13 @@ int debuginfo__find_trace_events(struct debuginfo *dbg,
>  	tf.tevs = *tevs;
>  	tf.ntevs = 0;
>  
> +	if (pev->event && pev->nargs != 0 && immediate_value_is_supported())
> +		tf.pf.skip_empty_arg = true;
> +
>  	ret = debuginfo__find_probes(dbg, &tf.pf);
> +	if (ret >= 0 && tf.pf.skip_empty_arg)
> +		ret = fill_empty_trace_arg(pev, tf.tevs, tf.ntevs);
> +
>  	if (ret < 0) {
>  		for (i = 0; i < tf.ntevs; i++)
>  			clear_probe_trace_event(&tf.tevs[i]);
> diff --git a/tools/perf/util/probe-finder.h b/tools/perf/util/probe-finder.h
> index 670c477bf8cf..11be10080613 100644
> --- a/tools/perf/util/probe-finder.h
> +++ b/tools/perf/util/probe-finder.h
> @@ -87,6 +87,7 @@ struct probe_finder {
>  	unsigned int		machine;	/* Target machine arch */
>  	struct perf_probe_arg	*pvar;		/* Current target variable */
>  	struct probe_trace_arg	*tvar;		/* Current result variable */
> +	bool			skip_empty_arg;	/* Skip non-exist args */
>  };
>  
>  struct trace_event_finder {

-- 

- Arnaldo