[PATCH perf/core 0/4] perf-probe: Fix and improve module probe events

[PATCH perf/core 0/4] perf-probe: Fix and improve module probe events

[Masami Hiramatsu]

Hello,

This series fixes some issues on offline/online module
probe support and improve perf-probe to probe module
without -m option (Thanks Arnaldo!).
This includes below patches.

 - [1/4] Fix perf-probe --list to show correct probe location
         in module.
 - [2/4] Improve error checking for the probes for offline
         kernel.
 - [3/4] (V2) Fix perf-probe to probe correctly on gcc generated
         functions in module.
 - [4/4] Improve perf-probe to find probe events in module
         without -m option.

Thank you,

---

Masami Hiramatsu (4):
      perf-probe: Fix to show correct locations for events on modules
      perf-probe: Add error checks to offline probe post-processing
      perf-probe: Fix to probe on gcc generated functions in modules
      perf-probe: Find probe events without target module


 tools/perf/util/probe-event.c  |  165 ++++++++++++++++++++++++++++------------
 tools/perf/util/probe-finder.c |   15 ++--
 tools/perf/util/probe-finder.h |    3 +
 3 files changed, 125 insertions(+), 58 deletions(-)

--
Masami Hiramatsu (Linaro)

[PATCH perf/core 1/4] perf-probe: Fix to show correct locations for events on modules

[Masami Hiramatsu]

Fix to show correct locations for events on modules by
relocating given address. Currently the relocation is
done when we failed to find the address in debuginfo,
but for modules it always makes a mistakes.

E.g. without this fix, events on module seems wrong,
but other cases (kernel and user space) looks good.

  # perf probe -l
    probe:SyS_remap_file_pages (on SyS_remap_file_pages@mm/mmap.c)
    probe:chv_prepare_pll (on intel_plane_atomic_get_property+16@drm/i915/intel_atomic_plane.c in i915)
    probe_perf:alias_lookup (on alias_lookup@util/alias.c in /home/mhiramat/ksrc/linux/tools/perf/perf)

With this fix, all cases are OK now.

  # perf probe -l
    probe:SyS_remap_file_pages (on SyS_remap_file_pages@mm/mmap.c)
    probe:chv_prepare_pll (on chv_prepare_pll@gpu/drm/i915/intel_display.c in i915)
    probe_perf:alias_lookup (on alias_lookup@util/alias.c in /home/mhiramat/ksrc/linux/tools/perf/perf)

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/perf/util/probe-finder.c |   10 +++-------
 1 file changed, 3 insertions(+), 7 deletions(-)

diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
index df4debe..0278fe1 100644
--- a/tools/perf/util/probe-finder.c
+++ b/tools/perf/util/probe-finder.c
@@ -1543,16 +1543,12 @@ int debuginfo__find_probe_point(struct debuginfo *dbg, unsigned long addr,
 	Dwarf_Addr _addr = 0, baseaddr = 0;
 	const char *fname = NULL, *func = NULL, *basefunc = NULL, *tmp;
 	int baseline = 0, lineno = 0, ret = 0;
-	bool reloc = false;
 
-retry:
+	/* We always need to relocate the address for aranges */
+	if (debuginfo__get_text_offset(dbg, &baseaddr) == 0)
+		addr += baseaddr;
 	/* Find cu die */
 	if (!dwarf_addrdie(dbg->dbg, (Dwarf_Addr)addr, &cudie)) {
-		if (!reloc && debuginfo__get_text_offset(dbg, &baseaddr) == 0) {
-			addr += baseaddr;
-			reloc = true;
-			goto retry;
-		}
 		pr_warning("Failed to find debug information for address %lx\n",
 			   addr);
 		ret = -EINVAL;

[PATCH perf/core 2/4] perf-probe: Add error checks to offline probe post-processing

[Masami Hiramatsu]

Add error check codes to post process and improve it for
offline probe events as;
 - post process fails if no matched symbol found in map(-ENOENT)
   or strdup() failed(-ENOMEM).
 - Even if the symbol name is same, it updates symbol address
   and offset.

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/perf/util/probe-event.c |   50 +++++++++++++++++++++++++++--------------
 1 file changed, 33 insertions(+), 17 deletions(-)

diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index 4a57c8a..aa8a922 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -610,6 +610,33 @@ static int find_perf_probe_point_from_dwarf(struct probe_trace_point *tp,
 	return ret ? : -ENOENT;
 }
 
+/* Adjust symbol name and address */
+static int post_process_probe_trace_point(struct probe_trace_point *tp,
+					   struct map *map, unsigned long offs)
+{
+	struct symbol *sym;
+	u64 addr = tp->address + tp->offset - offs;
+
+	sym = map__find_symbol(map, addr);
+	if (!sym)
+		return -ENOENT;
+
+	if (strcmp(sym->name, tp->symbol)) {
+		/* If we have no realname, use symbol for it */
+		if (!tp->realname)
+			tp->realname = tp->symbol;
+		else
+			free(tp->symbol);
+		tp->symbol = strdup(sym->name);
+		if (!tp->symbol)
+			return -ENOMEM;
+	}
+	tp->offset = addr - sym->start;
+	tp->address -= offs;
+
+	return 0;
+}
+
 /*
  * Rename DWARF symbols to ELF symbols -- gcc sometimes optimizes functions
  * and generate new symbols with suffixes such as .constprop.N or .isra.N
@@ -622,11 +649,9 @@ static int
 post_process_offline_probe_trace_events(struct probe_trace_event *tevs,
 					int ntevs, const char *pathname)
 {
-	struct symbol *sym;
 	struct map *map;
 	unsigned long stext = 0;
-	u64 addr;
-	int i;
+	int i, ret = 0;
 
 	/* Prepare a map for offline binary */
 	map = dso__new_map(pathname);
@@ -636,23 +661,14 @@ post_process_offline_probe_trace_events(struct probe_trace_event *tevs,
 	}
 
 	for (i = 0; i < ntevs; i++) {
-		addr = tevs[i].point.address + tevs[i].point.offset - stext;
-		sym = map__find_symbol(map, addr);
-		if (!sym)
-			continue;
-		if (!strcmp(sym->name, tevs[i].point.symbol))
-			continue;
-		/* If we have no realname, use symbol for it */
-		if (!tevs[i].point.realname)
-			tevs[i].point.realname = tevs[i].point.symbol;
-		else
-			free(tevs[i].point.symbol);
-		tevs[i].point.symbol = strdup(sym->name);
-		tevs[i].point.offset = addr - sym->start;
+		ret = post_process_probe_trace_point(&tevs[i].point,
+						     map, stext);
+		if (ret < 0)
+			break;
 	}
 	map__put(map);
 
-	return 0;
+	return ret;
 }
 
 static int add_exec_to_probe_trace_events(struct probe_trace_event *tevs,

[PATCH perf/core 3/4] perf-probe: Fix to probe on gcc generated functions in modules

[Masami Hiramatsu]

Fix to probe on gcc generated functions on modules. Since
probing on a module is based on its symbol name, it should
be adjusted on actual symbols.

E.g. without this fix, perf probe shows probe definition
on non-exist symbol as below.

  $ perf probe -m build-x86_64/net/netfilter/nf_nat.ko -F in_range*
  in_range.isra.12
  $ perf probe -m build-x86_64/net/netfilter/nf_nat.ko -D in_range
  p:probe/in_range nf_nat:in_range+0

With this fix, perf probe correctly shows a probe on
gcc-generated symbol.

  $ perf probe -m build-x86_64/net/netfilter/nf_nat.ko -D in_range
  p:probe/in_range nf_nat:in_range.isra.12+0

This also fixes same problem on online module as below.

  $ perf probe -m i915 -D assert_plane
  p:probe/assert_plane i915:assert_plane.constprop.134+0

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/perf/util/probe-event.c  |   45 ++++++++++++++++++++++++++--------------
 tools/perf/util/probe-finder.c |    7 ++++--
 tools/perf/util/probe-finder.h |    3 +++
 3 files changed, 37 insertions(+), 18 deletions(-)

diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index aa8a922..6a6f44d 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -698,18 +698,31 @@ static int add_exec_to_probe_trace_events(struct probe_trace_event *tevs,
 	return ret;
 }
 
-static int add_module_to_probe_trace_events(struct probe_trace_event *tevs,
-					    int ntevs, const char *module)
+static int
+post_process_module_probe_trace_events(struct probe_trace_event *tevs,
+				       int ntevs, const char *module,
+				       struct debuginfo *dinfo)
 {
+	Dwarf_Addr text_offs = 0;
 	int i, ret = 0;
 	char *mod_name = NULL;
+	struct map *map;
 
 	if (!module)
 		return 0;
 
-	mod_name = find_module_name(module);
+	map = get_target_map(module, false);
+	if (!map || debuginfo__get_text_offset(dinfo, &text_offs, true) < 0) {
+		pr_warning("Failed to get ELF symbols for %s\n", module);
+		return -EINVAL;
+	}
 
+	mod_name = find_module_name(module);
 	for (i = 0; i < ntevs; i++) {
+		ret = post_process_probe_trace_point(&tevs[i].point,
+						map, (unsigned long)text_offs);
+		if (ret < 0)
+			break;
 		tevs[i].point.module =
 			strdup(mod_name ? mod_name : module);
 		if (!tevs[i].point.module) {
@@ -719,6 +732,8 @@ static int add_module_to_probe_trace_events(struct probe_trace_event *tevs,
 	}
 
 	free(mod_name);
+	map__put(map);
+
 	return ret;
 }
 
@@ -776,7 +791,7 @@ arch__post_process_probe_trace_events(struct perf_probe_event *pev __maybe_unuse
 static int post_process_probe_trace_events(struct perf_probe_event *pev,
 					   struct probe_trace_event *tevs,
 					   int ntevs, const char *module,
-					   bool uprobe)
+					   bool uprobe, struct debuginfo *dinfo)
 {
 	int ret;
 
@@ -784,7 +799,8 @@ static int post_process_probe_trace_events(struct perf_probe_event *pev,
 		ret = add_exec_to_probe_trace_events(tevs, ntevs, module);
 	else if (module)
 		/* Currently ref_reloc_sym based probe is not for drivers */
-		ret = add_module_to_probe_trace_events(tevs, ntevs, module);
+		ret = post_process_module_probe_trace_events(tevs, ntevs,
+							     module, dinfo);
 	else
 		ret = post_process_kernel_probe_trace_events(tevs, ntevs);
 
@@ -828,30 +844,27 @@ static int try_to_find_probe_trace_events(struct perf_probe_event *pev,
 		}
 	}
 
-	debuginfo__delete(dinfo);
-
 	if (ntevs > 0) {	/* Succeeded to find trace events */
 		pr_debug("Found %d probe_trace_events.\n", ntevs);
 		ret = post_process_probe_trace_events(pev, *tevs, ntevs,
-						pev->target, pev->uprobes);
+					pev->target, pev->uprobes, dinfo);
 		if (ret < 0 || ret == ntevs) {
+			pr_debug("Post processing failed or all events are skipped. (%d)\n", ret);
 			clear_probe_trace_events(*tevs, ntevs);
 			zfree(tevs);
+			ntevs = 0;
 		}
-		if (ret != ntevs)
-			return ret < 0 ? ret : ntevs;
-		ntevs = 0;
-		/* Fall through */
 	}
 
+	debuginfo__delete(dinfo);
+
 	if (ntevs == 0)	{	/* No error but failed to find probe point. */
 		pr_warning("Probe point '%s' not found.\n",
 			   synthesize_perf_probe_point(&pev->point));
 		return -ENOENT;
-	}
-	/* Error path : ntevs < 0 */
-	pr_debug("An error occurred in debuginfo analysis (%d).\n", ntevs);
-	if (ntevs < 0) {
+	} else if (ntevs < 0) {
+		/* Error path : ntevs < 0 */
+		pr_debug("An error occurred in debuginfo analysis (%d).\n", ntevs);
 		if (ntevs == -EBADF)
 			pr_warning("Warning: No dwarf info found in the vmlinux - "
 				"please rebuild kernel with CONFIG_DEBUG_INFO=y.\n");
diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
index 0278fe1..0d9d6e0 100644
--- a/tools/perf/util/probe-finder.c
+++ b/tools/perf/util/probe-finder.c
@@ -1501,7 +1501,8 @@ int debuginfo__find_available_vars_at(struct debuginfo *dbg,
 }
 
 /* For the kernel module, we need a special code to get a DIE */
-static int debuginfo__get_text_offset(struct debuginfo *dbg, Dwarf_Addr *offs)
+int debuginfo__get_text_offset(struct debuginfo *dbg, Dwarf_Addr *offs,
+				bool adjust_offset)
 {
 	int n, i;
 	Elf32_Word shndx;
@@ -1530,6 +1531,8 @@ static int debuginfo__get_text_offset(struct debuginfo *dbg, Dwarf_Addr *offs)
 			if (!shdr)
 				return -ENOENT;
 			*offs = shdr->sh_addr;
+			if (adjust_offset)
+				*offs -= shdr->sh_offset;
 		}
 	}
 	return 0;
@@ -1545,7 +1548,7 @@ int debuginfo__find_probe_point(struct debuginfo *dbg, unsigned long addr,
 	int baseline = 0, lineno = 0, ret = 0;
 
 	/* We always need to relocate the address for aranges */
-	if (debuginfo__get_text_offset(dbg, &baseaddr) == 0)
+	if (debuginfo__get_text_offset(dbg, &baseaddr, false) == 0)
 		addr += baseaddr;
 	/* Find cu die */
 	if (!dwarf_addrdie(dbg->dbg, (Dwarf_Addr)addr, &cudie)) {
diff --git a/tools/perf/util/probe-finder.h b/tools/perf/util/probe-finder.h
index f1d8558..2956c51 100644
--- a/tools/perf/util/probe-finder.h
+++ b/tools/perf/util/probe-finder.h
@@ -46,6 +46,9 @@ int debuginfo__find_trace_events(struct debuginfo *dbg,
 int debuginfo__find_probe_point(struct debuginfo *dbg, unsigned long addr,
 				struct perf_probe_point *ppt);
 
+int debuginfo__get_text_offset(struct debuginfo *dbg, Dwarf_Addr *offs,
+			       bool adjust_offset);
+
 /* Find a line range */
 int debuginfo__find_line_range(struct debuginfo *dbg, struct line_range *lr);
 

[PATCH perf/core 4/4] perf-probe: Find probe events without target module

[Masami Hiramatsu]

Find probe events without -m "module" option. If perf-probe
failed to find given function in kernel image, it tries to
find same symbol and module in kallsyms, and retry search
in the found module. E.g.

  # perf probe -D i915_capabilities
  p:probe/i915_capabilities i915:i915_capabilities+0

Note: without -m option, perf probe can not find inlined
function since there is no symbol information in kallsyms.

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
Suggested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/util/probe-event.c |   74 ++++++++++++++++++++++++++++++-----------
 1 file changed, 55 insertions(+), 19 deletions(-)

diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index 6a6f44d..09bd093 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -858,11 +858,7 @@ static int try_to_find_probe_trace_events(struct perf_probe_event *pev,
 
 	debuginfo__delete(dinfo);
 
-	if (ntevs == 0)	{	/* No error but failed to find probe point. */
-		pr_warning("Probe point '%s' not found.\n",
-			   synthesize_perf_probe_point(&pev->point));
-		return -ENOENT;
-	} else if (ntevs < 0) {
+	if (ntevs < 0) {
 		/* Error path : ntevs < 0 */
 		pr_debug("An error occurred in debuginfo analysis (%d).\n", ntevs);
 		if (ntevs == -EBADF)
@@ -2073,8 +2069,10 @@ static int find_perf_probe_point_from_map(struct probe_trace_point *tp,
 	} else {
 		if (tp->symbol && !addr) {
 			if (kernel_get_symbol_address_by_name(tp->symbol,
-						&addr, true, false) < 0)
+						&addr, true, false) < 0) {
+				ret = 0;
 				goto out;
+			}
 		}
 		if (addr) {
 			addr += tp->offset;
@@ -2829,9 +2827,7 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
 	 */
 	num_matched_functions = find_probe_functions(map, pp->function, syms);
 	if (num_matched_functions == 0) {
-		pr_err("Failed to find symbol %s in %s\n", pp->function,
-			pev->target ? : "kernel");
-		ret = -ENOENT;
+		ret = 0;
 		goto out;
 	} else if (num_matched_functions > probe_conf.max_probes) {
 		pr_err("Too many functions matched in %s\n",
@@ -3233,6 +3229,43 @@ static int find_probe_trace_events_from_cache(struct perf_probe_event *pev,
 	return ret;
 }
 
+static int __convert_to_probe_trace_events(struct perf_probe_event *pev,
+					   struct probe_trace_event **tevs)
+{
+	int ret;
+
+	/* At first, we need to lookup cache entry */
+	ret = find_probe_trace_events_from_cache(pev, tevs);
+	if (ret > 0 || pev->sdt)	/* SDT can be found only in the cache */
+		return ret == 0 ? -ENOENT : ret; /* Found in probe cache */
+
+	/* Convert perf_probe_event with debuginfo */
+	ret = try_to_find_probe_trace_events(pev, tevs);
+	if (ret != 0)
+		return ret;	/* Found in debuginfo or got an error */
+
+	return find_probe_trace_events_from_map(pev, tevs);
+}
+
+static char *find_module_from_kallsyms(const char *symbol_name)
+{
+	struct machine *machine = machine__new_kallsyms();
+	struct symbol *sym;
+	struct map *map;
+	char *module;
+
+	pr_debug("Try to find module for %s\n", symbol_name);
+	sym = machine__find_kernel_function_by_name(machine, symbol_name, &map);
+	if (!sym || map->dso->short_name[0] != '[')
+		return NULL;
+	pr_debug("Found: %s in %s\n", sym->name, map->dso->short_name);
+	module = strdup(map->dso->short_name + 1);
+	if (module)
+		module[strlen(module) - 1] = '\0';
+
+	return module;
+}
+
 static int convert_to_probe_trace_events(struct perf_probe_event *pev,
 					 struct probe_trace_event **tevs)
 {
@@ -3255,17 +3288,20 @@ static int convert_to_probe_trace_events(struct perf_probe_event *pev,
 	if (ret > 0)
 		return ret;
 
-	/* At first, we need to lookup cache entry */
-	ret = find_probe_trace_events_from_cache(pev, tevs);
-	if (ret > 0 || pev->sdt)	/* SDT can be found only in the cache */
-		return ret == 0 ? -ENOENT : ret; /* Found in probe cache */
-
-	/* Convert perf_probe_event with debuginfo */
-	ret = try_to_find_probe_trace_events(pev, tevs);
-	if (ret != 0)
-		return ret;	/* Found in debuginfo or got an error */
+	ret = __convert_to_probe_trace_events(pev, tevs);
+	/* Not found. will retry to check kmodule if possible */
+	if (ret == 0 && !pev->uprobes && !pev->target) {
+		pev->target = find_module_from_kallsyms(pev->point.function);
+		if (pev->target)
+			ret = __convert_to_probe_trace_events(pev, tevs);
+	}
 
-	return find_probe_trace_events_from_map(pev, tevs);
+	if (ret == 0) {
+		pr_warning("Probe point '%s' not found.\n",
+			   synthesize_perf_probe_point(&pev->point));
+		ret = -ENOENT;
+	}
+	return ret;
 }
 
 int convert_perf_probe_events(struct perf_probe_event *pevs, int npevs)

Re: [PATCH perf/core 1/4] perf-probe: Fix to show correct locations for events on modules

[Arnaldo Carvalho de Melo]

Em Sat, Jan 07, 2017 at 02:25:09PM +0900, Masami Hiramatsu escreveu:
> Fix to show correct locations for events on modules by
> relocating given address. Currently the relocation is
> done when we failed to find the address in debuginfo,
> but for modules it always makes a mistakes.

Try to provide precise instructions on how to reproduce, for instance,
here I'm not being able to reproduce:

[root@jouet ~]# perf probe -m i915 chv_prepare_pll
Added new event:
  probe:chv_prepare_pll (on chv_prepare_pll in i915)

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

	perf record -e probe:chv_prepare_pll -aR sleep 1

[root@jouet ~]# perf probe -l
  probe:chv_prepare_pll (on chv_prepare_pll in i915)
  probe:e1000_xmit_frame (on e1000_get_link_up_info_80003es2lan:7@intel/e1000e/80003es2lan.c in e1000e)
[root@jouet ~]#

So it doesn't seem to "always make mistakes", what are the precise
conditions to reproduce this problem?

Running with 'perf probe -vv -m i915 chv_prepare_pll' to get more
debugging info:

Failed to get build-id from i915.
Cache open error: -1
Open Debuginfo file: /lib/modules/4.9.0+/kernel/drivers/gpu/drm/i915/i915.ko
Try to find probe point from debuginfo.
Matched function: chv_prepare_pll [6ce853]
found inline addr: 0x883a0
Probe point found: chv_prepare_pll+0
Found 1 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Writing event: p:probe/chv_prepare_pll i915:chv_prepare_pll+0
Added new event:
  probe:chv_prepare_pll (on chv_prepare_pll in i915)

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

	perf record -e probe:chv_prepare_pll -aR sleep 1

[root@jouet ~]#

- Arnaldo
 
> E.g. without this fix, events on module seems wrong,
> but other cases (kernel and user space) looks good.
> 
>   # perf probe -l
>     probe:SyS_remap_file_pages (on SyS_remap_file_pages@mm/mmap.c)
>     probe:chv_prepare_pll (on intel_plane_atomic_get_property+16@drm/i915/intel_atomic_plane.c in i915)
>     probe_perf:alias_lookup (on alias_lookup@util/alias.c in /home/mhiramat/ksrc/linux/tools/perf/perf)
> 
> With this fix, all cases are OK now.
> 
>   # perf probe -l
>     probe:SyS_remap_file_pages (on SyS_remap_file_pages@mm/mmap.c)
>     probe:chv_prepare_pll (on chv_prepare_pll@gpu/drm/i915/intel_display.c in i915)
>     probe_perf:alias_lookup (on alias_lookup@util/alias.c in /home/mhiramat/ksrc/linux/tools/perf/perf)
> 
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> ---
>  tools/perf/util/probe-finder.c |   10 +++-------
>  1 file changed, 3 insertions(+), 7 deletions(-)
> 
> diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
> index df4debe..0278fe1 100644
> --- a/tools/perf/util/probe-finder.c
> +++ b/tools/perf/util/probe-finder.c
> @@ -1543,16 +1543,12 @@ int debuginfo__find_probe_point(struct debuginfo *dbg, unsigned long addr,
>  	Dwarf_Addr _addr = 0, baseaddr = 0;
>  	const char *fname = NULL, *func = NULL, *basefunc = NULL, *tmp;
>  	int baseline = 0, lineno = 0, ret = 0;
> -	bool reloc = false;
>  
> -retry:
> +	/* We always need to relocate the address for aranges */
> +	if (debuginfo__get_text_offset(dbg, &baseaddr) == 0)
> +		addr += baseaddr;
>  	/* Find cu die */
>  	if (!dwarf_addrdie(dbg->dbg, (Dwarf_Addr)addr, &cudie)) {
> -		if (!reloc && debuginfo__get_text_offset(dbg, &baseaddr) == 0) {
> -			addr += baseaddr;
> -			reloc = true;
> -			goto retry;
> -		}
>  		pr_warning("Failed to find debug information for address %lx\n",
>  			   addr);
>  		ret = -EINVAL;

Re: [PATCH perf/core 1/4] perf-probe: Fix to show correct locations for events on modules

[Masami Hiramatsu]

On Tue, 10 Jan 2017 10:18:35 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Sat, Jan 07, 2017 at 02:25:09PM +0900, Masami Hiramatsu escreveu:
> > Fix to show correct locations for events on modules by
> > relocating given address. Currently the relocation is
> > done when we failed to find the address in debuginfo,
> > but for modules it always makes a mistakes.
> 
> Try to provide precise instructions on how to reproduce, for instance,
> here I'm not being able to reproduce:
> 
> [root@jouet ~]# perf probe -m i915 chv_prepare_pll
> Added new event:
>   probe:chv_prepare_pll (on chv_prepare_pll in i915)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe:chv_prepare_pll -aR sleep 1
> 
> [root@jouet ~]# perf probe -l
>   probe:chv_prepare_pll (on chv_prepare_pll in i915)
>   probe:e1000_xmit_frame (on e1000_get_link_up_info_80003es2lan:7@intel/e1000e/80003es2lan.c in e1000e)
> [root@jouet ~]#
> 
> So it doesn't seem to "always make mistakes", what are the precise
> conditions to reproduce this problem?

Hmm, OK, I also found same issue. I'll recheck that...

Thank you,

> 
> Running with 'perf probe -vv -m i915 chv_prepare_pll' to get more
> debugging info:
> 
> Failed to get build-id from i915.
> Cache open error: -1
> Open Debuginfo file: /lib/modules/4.9.0+/kernel/drivers/gpu/drm/i915/i915.ko
> Try to find probe point from debuginfo.
> Matched function: chv_prepare_pll [6ce853]
> found inline addr: 0x883a0
> Probe point found: chv_prepare_pll+0
> Found 1 probe_trace_events.
> Opening /sys/kernel/debug/tracing//kprobe_events write=1
> Writing event: p:probe/chv_prepare_pll i915:chv_prepare_pll+0
> Added new event:
>   probe:chv_prepare_pll (on chv_prepare_pll in i915)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe:chv_prepare_pll -aR sleep 1
> 
> [root@jouet ~]#
> 
> - Arnaldo
>  
> > E.g. without this fix, events on module seems wrong,
> > but other cases (kernel and user space) looks good.
> > 
> >   # perf probe -l
> >     probe:SyS_remap_file_pages (on SyS_remap_file_pages@mm/mmap.c)
> >     probe:chv_prepare_pll (on intel_plane_atomic_get_property+16@drm/i915/intel_atomic_plane.c in i915)
> >     probe_perf:alias_lookup (on alias_lookup@util/alias.c in /home/mhiramat/ksrc/linux/tools/perf/perf)
> > 
> > With this fix, all cases are OK now.
> > 
> >   # perf probe -l
> >     probe:SyS_remap_file_pages (on SyS_remap_file_pages@mm/mmap.c)
> >     probe:chv_prepare_pll (on chv_prepare_pll@gpu/drm/i915/intel_display.c in i915)
> >     probe_perf:alias_lookup (on alias_lookup@util/alias.c in /home/mhiramat/ksrc/linux/tools/perf/perf)
> > 
> > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> > ---
> >  tools/perf/util/probe-finder.c |   10 +++-------
> >  1 file changed, 3 insertions(+), 7 deletions(-)
> > 
> > diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
> > index df4debe..0278fe1 100644
> > --- a/tools/perf/util/probe-finder.c
> > +++ b/tools/perf/util/probe-finder.c
> > @@ -1543,16 +1543,12 @@ int debuginfo__find_probe_point(struct debuginfo *dbg, unsigned long addr,
> >  	Dwarf_Addr _addr = 0, baseaddr = 0;
> >  	const char *fname = NULL, *func = NULL, *basefunc = NULL, *tmp;
> >  	int baseline = 0, lineno = 0, ret = 0;
> > -	bool reloc = false;
> >  
> > -retry:
> > +	/* We always need to relocate the address for aranges */
> > +	if (debuginfo__get_text_offset(dbg, &baseaddr) == 0)
> > +		addr += baseaddr;
> >  	/* Find cu die */
> >  	if (!dwarf_addrdie(dbg->dbg, (Dwarf_Addr)addr, &cudie)) {
> > -		if (!reloc && debuginfo__get_text_offset(dbg, &baseaddr) == 0) {
> > -			addr += baseaddr;
> > -			reloc = true;
> > -			goto retry;
> > -		}
> >  		pr_warning("Failed to find debug information for address %lx\n",
> >  			   addr);
> >  		ret = -EINVAL;


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH perf/core 4/4] perf-probe: Find probe events without target module

[Masami Hiramatsu]

On Sat,  7 Jan 2017 14:28:42 +0900
Masami Hiramatsu <mhiramat@kernel.org> wrote:

> Find probe events without -m "module" option. If perf-probe
> failed to find given function in kernel image, it tries to
> find same symbol and module in kallsyms, and retry search
> in the found module. E.g.
> 
>   # perf probe -D i915_capabilities
>   p:probe/i915_capabilities i915:i915_capabilities+0
> 
> Note: without -m option, perf probe can not find inlined
> function since there is no symbol information in kallsyms.
> 
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> Suggested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
> ---
>  tools/perf/util/probe-event.c |   74 ++++++++++++++++++++++++++++++-----------
>  1 file changed, 55 insertions(+), 19 deletions(-)
> 
> diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
> index 6a6f44d..09bd093 100644
> --- a/tools/perf/util/probe-event.c
> +++ b/tools/perf/util/probe-event.c
> @@ -858,11 +858,7 @@ static int try_to_find_probe_trace_events(struct perf_probe_event *pev,
>  
>  	debuginfo__delete(dinfo);
>  
> -	if (ntevs == 0)	{	/* No error but failed to find probe point. */
> -		pr_warning("Probe point '%s' not found.\n",
> -			   synthesize_perf_probe_point(&pev->point));
> -		return -ENOENT;
> -	} else if (ntevs < 0) {
> +	if (ntevs < 0) {
>  		/* Error path : ntevs < 0 */
>  		pr_debug("An error occurred in debuginfo analysis (%d).\n", ntevs);
>  		if (ntevs == -EBADF)
> @@ -2073,8 +2069,10 @@ static int find_perf_probe_point_from_map(struct probe_trace_point *tp,
>  	} else {
>  		if (tp->symbol && !addr) {
>  			if (kernel_get_symbol_address_by_name(tp->symbol,
> -						&addr, true, false) < 0)
> +						&addr, true, false) < 0) {
> +				ret = 0;
>  				goto out;

Oops, I've found that this is not needed and breaks --list result.
I'll update it.

Thanks.


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH perf/core 1/4] perf-probe: Fix to show correct locations for events on modules

[Masami Hiramatsu]

On Tue, 10 Jan 2017 10:18:35 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Sat, Jan 07, 2017 at 02:25:09PM +0900, Masami Hiramatsu escreveu:
> > Fix to show correct locations for events on modules by
> > relocating given address. Currently the relocation is
> > done when we failed to find the address in debuginfo,
> > but for modules it always makes a mistakes.
> 
> Try to provide precise instructions on how to reproduce, for instance,
> here I'm not being able to reproduce:
> 
> [root@jouet ~]# perf probe -m i915 chv_prepare_pll
> Added new event:
>   probe:chv_prepare_pll (on chv_prepare_pll in i915)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe:chv_prepare_pll -aR sleep 1
> 
> [root@jouet ~]# perf probe -l
>   probe:chv_prepare_pll (on chv_prepare_pll in i915)
>   probe:e1000_xmit_frame (on e1000_get_link_up_info_80003es2lan:7@intel/e1000e/80003es2lan.c in e1000e)
> [root@jouet ~]#
> 
> So it doesn't seem to "always make mistakes", what are the precise
> conditions to reproduce this problem?

OK, I found mymistakes. chv_prepare_pll in my i915 module is optimized
and have isra.X suffix, so perf ends up with searching it in map.
(That issue is fixed in [3/4] in this series as you may know)


This happens when the module text size is enough big, bigger than
sh_addr, because original code retries with given address + sh_addr
if it failed to find CU DIE at the given address. Any address smaller
than sh_addr always fails and it retries.

On my environment, the sh_addr of ".text" section is 0x10030. Since
i915 is a huge kernel module, we can see this issue as below.

$ grep "[Tt] .*\[i915\]" /proc/kallsyms | sort | head -n1
ffffffffc0270000 t i915_switcheroo_can_switch	[i915]

ffffffffc0270000 + 0x10030 = ffffffffc0280030, so we'll check
symbols cross this boundary.

$ grep "[Tt] .*\[i915\]" /proc/kallsyms | grep -B1 ^ffffffffc028  | head -n 2
ffffffffc027ff80 t haswell_init_clock_gating	[i915]
ffffffffc0280110 t valleyview_init_clock_gating	[i915]

So setup probes on both function and see what happen.

$ sudo ./perf probe -m i915 -a haswell_init_clock_gating -a valleyview_init_clock_gating
Added new events:
  probe:haswell_init_clock_gating (on haswell_init_clock_gating in i915)
  probe:valleyview_init_clock_gating (on valleyview_init_clock_gating in i915)

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

	perf record -e probe:valleyview_init_clock_gating -aR sleep 1

$ sudo ./perf probe -l
  probe:haswell_init_clock_gating (on haswell_init_clock_gating@gpu/drm/i915/intel_pm.c in i915)
  probe:valleyview_init_clock_gating (on i915_vga_set_decode:4@gpu/drm/i915/i915_drv.c in i915)

As you can see, haswell_init_clock_gating is correctly shown, but
valleyview_init_clock_gating is not.

With this patch, both events shown correctly.

$ sudo ./perf probe -l
  probe:haswell_init_clock_gating (on haswell_init_clock_gating@gpu/drm/i915/intel_pm.c in i915)
  probe:valleyview_init_clock_gating (on valleyview_init_clock_gating@gpu/drm/i915/intel_pm.c in i915)

I'll update patch description and resend with fix of [4/4].

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>