[v2,1/4] perf-probe: Avoid setting probes on same address on same event
diff mbox series

Message ID 159438666401.62703.15196394835032087840.stgit@devnote2
State New
Headers show
Series
  • perf-probe: Fix GNU IFUNC probe issue etc.
Related show

Commit Message

Masami Hiramatsu July 10, 2020, 1:11 p.m. UTC
There is a case that the several same-name symbols points
same address. In that case, perf probe returns an error.

E.g.

  perf probe -x /lib64/libc-2.30.so -v -a "memcpy arg1=%di"
  probe-definition(0): memcpy arg1=%di
  symbol:memcpy file:(null) line:0 offset:0 return:0 lazy:(null)
  parsing arg: arg1=%di into name:arg1 %di
  1 arguments
  symbol:setjmp file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:longjmp file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:longjmp_target file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:lll_lock_wait_private file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_arena_max file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_arena_test file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_tunable_tcache_max_bytes file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_tunable_tcache_count file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_tunable_tcache_unsorted_limit file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_trim_threshold file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_top_pad file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_mmap_threshold file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_mmap_max file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_perturb file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_mxfast file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_heap_new file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_arena_reuse_free_list file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_arena_reuse file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_arena_reuse_wait file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_arena_new file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_arena_retry file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_sbrk_less file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_heap_free file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_heap_less file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_tcache_double_free file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_heap_more file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_sbrk_more file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_malloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_memalign_retry file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt_free_dyn_thresholds file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_realloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_calloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
  symbol:memory_mallopt file:(null) line:0 offset:0 return:0 lazy:(null)
  Open Debuginfo file: /usr/lib/debug/usr/lib64/libc-2.30.so.debug
  Try to find probe point from debuginfo.
  Opening /sys/kernel/debug/tracing//README write=0
  Failed to find the location of the '%di' variable at this address.
   Perhaps it has been optimized out.
   Use -V with the --range option to show '%di' location range.
  An error occurred in debuginfo analysis (-2).
  Trying to use symbols.
  Opening /sys/kernel/debug/tracing//uprobe_events write=1
  Writing event: p:probe_libc/memcpy /usr/lib64/libc-2.30.so:0x914c0 arg1=%di
  Writing event: p:probe_libc/memcpy /usr/lib64/libc-2.30.so:0x914c0 arg1=%di
  Failed to write event: File exists
    Error: Failed to add events. Reason: File exists (Code: -17)

You can see the perf tried to write completely same probe definition
twice, which caused an error.

To fix this issue, check the symbol list and drop duplicated
symbols (which has same symbol name and address) from it.

With this patch;

  # perf probe -x /lib64/libc-2.30.so -a "memcpy arg1=%di"
  Failed to find the location of the '%di' variable at this address.
   Perhaps it has been optimized out.
   Use -V with the --range option to show '%di' location range.
  Added new events:
    probe_libc:memcpy    (on memcpy in /usr/lib64/libc-2.30.so with arg1=%di)
    probe_libc:memcpy    (on memcpy in /usr/lib64/libc-2.30.so with arg1=%di)

  You can now use it in all perf tools, such as:

  	perf record -e probe_libc:memcpy -aR sleep 1


Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
Reviewed-by: Srikar Dronamraju <srikar@linux.vnet.ibm.com>
---
 Changes in V2
  - Change "find" word to "Found".
---
 tools/perf/util/probe-event.c |   10 ++++++++++
 1 file changed, 10 insertions(+)

Comments

Arnaldo Carvalho de Melo July 16, 2020, 9:47 p.m. UTC | #1
Em Fri, Jul 10, 2020 at 10:11:04PM +0900, Masami Hiramatsu escreveu:
> There is a case that the several same-name symbols points
> same address. In that case, perf probe returns an error.
> 
> E.g.
> 
>   perf probe -x /lib64/libc-2.30.so -v -a "memcpy arg1=%di"
>   probe-definition(0): memcpy arg1=%di
>   symbol:memcpy file:(null) line:0 offset:0 return:0 lazy:(null)
>   parsing arg: arg1=%di into name:arg1 %di
>   1 arguments
>   symbol:setjmp file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:longjmp file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:longjmp_target file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:lll_lock_wait_private file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_arena_max file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_arena_test file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_tunable_tcache_max_bytes file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_tunable_tcache_count file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_tunable_tcache_unsorted_limit file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_trim_threshold file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_top_pad file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_mmap_threshold file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_mmap_max file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_perturb file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_mxfast file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_heap_new file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_arena_reuse_free_list file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_arena_reuse file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_arena_reuse_wait file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_arena_new file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_arena_retry file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_sbrk_less file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_heap_free file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_heap_less file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_tcache_double_free file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_heap_more file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_sbrk_more file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_malloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_memalign_retry file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt_free_dyn_thresholds file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_realloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_calloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
>   symbol:memory_mallopt file:(null) line:0 offset:0 return:0 lazy:(null)
>   Open Debuginfo file: /usr/lib/debug/usr/lib64/libc-2.30.so.debug
>   Try to find probe point from debuginfo.
>   Opening /sys/kernel/debug/tracing//README write=0
>   Failed to find the location of the '%di' variable at this address.
>    Perhaps it has been optimized out.
>    Use -V with the --range option to show '%di' location range.
>   An error occurred in debuginfo analysis (-2).
>   Trying to use symbols.
>   Opening /sys/kernel/debug/tracing//uprobe_events write=1
>   Writing event: p:probe_libc/memcpy /usr/lib64/libc-2.30.so:0x914c0 arg1=%di
>   Writing event: p:probe_libc/memcpy /usr/lib64/libc-2.30.so:0x914c0 arg1=%di
>   Failed to write event: File exists
>     Error: Failed to add events. Reason: File exists (Code: -17)
> 
> You can see the perf tried to write completely same probe definition
> twice, which caused an error.
> 
> To fix this issue, check the symbol list and drop duplicated
> symbols (which has same symbol name and address) from it.
> 
> With this patch;
> 
>   # perf probe -x /lib64/libc-2.30.so -a "memcpy arg1=%di"
>   Failed to find the location of the '%di' variable at this address.
>    Perhaps it has been optimized out.
>    Use -V with the --range option to show '%di' location range.
>   Added new events:
>     probe_libc:memcpy    (on memcpy in /usr/lib64/libc-2.30.so with arg1=%di)
>     probe_libc:memcpy    (on memcpy in /usr/lib64/libc-2.30.so with arg1=%di)
> 
>   You can now use it in all perf tools, such as:
> 
>   	perf record -e probe_libc:memcpy -aR sleep 1
> 
> 
> Reported-by: Andi Kleen <andi@firstfloor.org>
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> Reviewed-by: Srikar Dronamraju <srikar@linux.vnet.ibm.com>
> ---
>  Changes in V2
>   - Change "find" word to "Found".
> ---
>  tools/perf/util/probe-event.c |   10 ++++++++++
>  1 file changed, 10 insertions(+)
> 
> diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
> index df713a5d1e26..8cd1224e5f4c 100644
> --- a/tools/perf/util/probe-event.c
> +++ b/tools/perf/util/probe-event.c
> @@ -2968,6 +2968,16 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
>  	for (j = 0; j < num_matched_functions; j++) {
>  		sym = syms[j];
>  
> +		/* There can be duplicated symbols in the map */
> +		for (i = 0; i < j; i++)
> +			if (sym->start == syms[i]->start) {
> +				pr_debug("Found duplicated symbol %s @ %lx\n",
> +					 sym->name, sym->start);
> +				break;
> +			}

Breaks 32-bit builds with:

  CC       /tmp/build/perf/util/demangle-java.o
In file included from util/probe-event.c:27:
util/probe-event.c: In function 'find_probe_trace_events_from_map':
util/probe-event.c:2978:14: error: format '%lx' expects argument of type 'long unsigned int', but argument 5 has type 'u64' {aka 'long long unsigned int'} [-Werror=format=]
     pr_debug("Found duplicated symbol %s @ %lx\n",
              ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
util/debug.h:17:21: note: in definition of macro 'pr_fmt'
 #define pr_fmt(fmt) fmt
                     ^~~
util/probe-event.c:2978:5: note: in expansion of macro 'pr_debug'
     pr_debug("Found duplicated symbol %s @ %lx\n",
     ^~~~~~~~
  CC       /tmp/build/perf/util/demangle-rust.o


I'll change this to use PRIx64.

- Arnaldo

> +		if (i != j)
> +			continue;
> +
>  		tev = (*tevs) + ret;
>  		tp = &tev->point;
>  		if (ret == num_matched_functions) {
>
Masami Hiramatsu July 20, 2020, 12:01 p.m. UTC | #2
On Thu, 16 Jul 2020 18:47:14 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Fri, Jul 10, 2020 at 10:11:04PM +0900, Masami Hiramatsu escreveu:
> > There is a case that the several same-name symbols points
> > same address. In that case, perf probe returns an error.
> > 
> > E.g.
> > 
> >   perf probe -x /lib64/libc-2.30.so -v -a "memcpy arg1=%di"
> >   probe-definition(0): memcpy arg1=%di
> >   symbol:memcpy file:(null) line:0 offset:0 return:0 lazy:(null)
> >   parsing arg: arg1=%di into name:arg1 %di
> >   1 arguments
> >   symbol:setjmp file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:longjmp file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:longjmp_target file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:lll_lock_wait_private file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_arena_max file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_arena_test file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_tunable_tcache_max_bytes file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_tunable_tcache_count file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_tunable_tcache_unsorted_limit file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_trim_threshold file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_top_pad file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_mmap_threshold file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_mmap_max file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_perturb file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_mxfast file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_heap_new file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_arena_reuse_free_list file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_arena_reuse file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_arena_reuse_wait file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_arena_new file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_arena_retry file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_sbrk_less file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_heap_free file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_heap_less file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_tcache_double_free file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_heap_more file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_sbrk_more file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_malloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_memalign_retry file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt_free_dyn_thresholds file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_realloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_calloc_retry file:(null) line:0 offset:0 return:0 lazy:(null)
> >   symbol:memory_mallopt file:(null) line:0 offset:0 return:0 lazy:(null)
> >   Open Debuginfo file: /usr/lib/debug/usr/lib64/libc-2.30.so.debug
> >   Try to find probe point from debuginfo.
> >   Opening /sys/kernel/debug/tracing//README write=0
> >   Failed to find the location of the '%di' variable at this address.
> >    Perhaps it has been optimized out.
> >    Use -V with the --range option to show '%di' location range.
> >   An error occurred in debuginfo analysis (-2).
> >   Trying to use symbols.
> >   Opening /sys/kernel/debug/tracing//uprobe_events write=1
> >   Writing event: p:probe_libc/memcpy /usr/lib64/libc-2.30.so:0x914c0 arg1=%di
> >   Writing event: p:probe_libc/memcpy /usr/lib64/libc-2.30.so:0x914c0 arg1=%di
> >   Failed to write event: File exists
> >     Error: Failed to add events. Reason: File exists (Code: -17)
> > 
> > You can see the perf tried to write completely same probe definition
> > twice, which caused an error.
> > 
> > To fix this issue, check the symbol list and drop duplicated
> > symbols (which has same symbol name and address) from it.
> > 
> > With this patch;
> > 
> >   # perf probe -x /lib64/libc-2.30.so -a "memcpy arg1=%di"
> >   Failed to find the location of the '%di' variable at this address.
> >    Perhaps it has been optimized out.
> >    Use -V with the --range option to show '%di' location range.
> >   Added new events:
> >     probe_libc:memcpy    (on memcpy in /usr/lib64/libc-2.30.so with arg1=%di)
> >     probe_libc:memcpy    (on memcpy in /usr/lib64/libc-2.30.so with arg1=%di)
> > 
> >   You can now use it in all perf tools, such as:
> > 
> >   	perf record -e probe_libc:memcpy -aR sleep 1
> > 
> > 
> > Reported-by: Andi Kleen <andi@firstfloor.org>
> > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> > Reviewed-by: Srikar Dronamraju <srikar@linux.vnet.ibm.com>
> > ---
> >  Changes in V2
> >   - Change "find" word to "Found".
> > ---
> >  tools/perf/util/probe-event.c |   10 ++++++++++
> >  1 file changed, 10 insertions(+)
> > 
> > diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
> > index df713a5d1e26..8cd1224e5f4c 100644
> > --- a/tools/perf/util/probe-event.c
> > +++ b/tools/perf/util/probe-event.c
> > @@ -2968,6 +2968,16 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
> >  	for (j = 0; j < num_matched_functions; j++) {
> >  		sym = syms[j];
> >  
> > +		/* There can be duplicated symbols in the map */
> > +		for (i = 0; i < j; i++)
> > +			if (sym->start == syms[i]->start) {
> > +				pr_debug("Found duplicated symbol %s @ %lx\n",
> > +					 sym->name, sym->start);
> > +				break;
> > +			}
> 
> Breaks 32-bit builds with:
> 
>   CC       /tmp/build/perf/util/demangle-java.o
> In file included from util/probe-event.c:27:
> util/probe-event.c: In function 'find_probe_trace_events_from_map':
> util/probe-event.c:2978:14: error: format '%lx' expects argument of type 'long unsigned int', but argument 5 has type 'u64' {aka 'long long unsigned int'} [-Werror=format=]
>      pr_debug("Found duplicated symbol %s @ %lx\n",
>               ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> util/debug.h:17:21: note: in definition of macro 'pr_fmt'
>  #define pr_fmt(fmt) fmt
>                      ^~~
> util/probe-event.c:2978:5: note: in expansion of macro 'pr_debug'
>      pr_debug("Found duplicated symbol %s @ %lx\n",
>      ^~~~~~~~
>   CC       /tmp/build/perf/util/demangle-rust.o

Oops.

> I'll change this to use PRIx64.

Yeah, I should have used it.

Thank you very much!

> 
> - Arnaldo
> 
> > +		if (i != j)
> > +			continue;
> > +
> >  		tev = (*tevs) + ret;
> >  		tp = &tev->point;
> >  		if (ret == num_matched_functions) {
> > 
> 
> -- 
> 
> - Arnaldo

Patch
diff mbox series

diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index df713a5d1e26..8cd1224e5f4c 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -2968,6 +2968,16 @@  static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
 	for (j = 0; j < num_matched_functions; j++) {
 		sym = syms[j];
 
+		/* There can be duplicated symbols in the map */
+		for (i = 0; i < j; i++)
+			if (sym->start == syms[i]->start) {
+				pr_debug("Found duplicated symbol %s @ %lx\n",
+					 sym->name, sym->start);
+				break;
+			}
+		if (i != j)
+			continue;
+
 		tev = (*tevs) + ret;
 		tp = &tev->point;
 		if (ret == num_matched_functions) {