[PATCH v2 0/4] perf/probe: Support multiprobe and immediates

[PATCH v2 0/4] perf/probe: Support multiprobe and immediates

[Masami Hiramatsu]

Hi,

This is the 2nd version of the multiprobe support on perf probe.

This can be applied on top of perf/core.

Inlined functions or the lines which have multiple statements can
be compiled in multiple addresses. Current perf probe generates
different events for each address, but this is not useful for
users.

Since ftrace multiprobe per event support is on upstream kernel,
it is a time to push this series. In this version, I have updated
the [1/4] not to add suffix _L* if user doesn't specify the line
number for the function or the line number is 0. And also,
[4/4] is updated according to [1/4] change.

The previous version is here.

https://lkml.kernel.org/r/157291299825.19771.5190465639558208592.stgit@devnote2

Thank you,

---

Masami Hiramatsu (4):
      perf probe: Generate event name with line number
      perf probe: Support multiprobe event
      perf probe: Support DW_AT_const_value constant value
      perf probe: Trace a magic number if variable is not found


 tools/perf/util/probe-event.c  |   19 +++++++++-
 tools/perf/util/probe-event.h  |    3 ++
 tools/perf/util/probe-file.c   |   14 ++++++++
 tools/perf/util/probe-file.h   |    2 +
 tools/perf/util/probe-finder.c |   73 ++++++++++++++++++++++++++++++++++++++--
 tools/perf/util/probe-finder.h |    1 +
 6 files changed, 105 insertions(+), 7 deletions(-)

--
Masami Hiramatsu (Linaro) <mhiramat@kernel.org>

[PATCH v2 1/4] perf probe: Generate event name with line number

[Masami Hiramatsu]

Generate event name from function name with line number
as <function>_L<line_number>. Note that this is only for
the new event which is defined by the line number of
function (except for line 0).

If there is another event on same line, you have to use
"-f" option. In that case, the new event has "_1" suffix.

 e.g.
  # perf probe -a kernel_read:1
  Added new events:
    probe:kernel_read_L1 (on kernel_read:1)

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

  	perf record -e probe:kernel_read_L1 -aR sleep 1

But if we omit the line number or 0th line, it will
have no suffix.

  # perf probe -a kernel_read
  Added new event:
    probe:kernel_read (on kernel_read)

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

  	perf record -e probe:kernel_read -aR sleep 1

  # perf probe -l
    probe:kernel_read    (on kernel_read@linux-5.0.0/fs/read_write.c)
    probe:kernel_read_L1 (on kernel_read@linux-5.0.0/fs/read_write.c)

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 Changes in v2:
  - Do not add _L* suffix for the event which has no line
    number or line #0.
---
 tools/perf/util/probe-event.c |    8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index e29948b8fcab..5c86d2cf6338 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -1679,6 +1679,14 @@ int parse_perf_probe_command(const char *cmd, struct perf_probe_event *pev)
 	if (ret < 0)
 		goto out;
 
+	/* Generate event name if needed */
+	if (!pev->event && pev->point.function && pev->point.line
+			&& !pev->point.lazy_line && !pev->point.offset) {
+		if (asprintf(&pev->event, "%s_L%d", pev->point.function,
+			pev->point.line) < 0)
+			return -ENOMEM;
+	}
+
 	/* Copy arguments and ensure return probe has no C argument */
 	pev->nargs = argc - 1;
 	pev->args = zalloc(sizeof(struct perf_probe_arg) * pev->nargs);

[PATCH v2 2/4] perf probe: Support multiprobe event

[Masami Hiramatsu]

Support multiprobe event if the event is based on function
and lines and kernel supports it. In this case, perf probe
creates the first probe with an event, and tries to append
following probes on that event, since those probes must be
on the same source code line.

Before this patch;
  # perf probe -a vfs_read:18
  Added new events:
    probe:vfs_read_L18   (on vfs_read:18)
    probe:vfs_read_L18_1 (on vfs_read:18)

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

  	perf record -e probe:vfs_read_L18_1 -aR sleep 1

  #

After this patch (on multiprobe supported kernel)
  # perf probe -a vfs_read:18
  Added new events:
    probe:vfs_read_L18   (on vfs_read:18)
    probe:vfs_read_L18   (on vfs_read:18)

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

  	perf record -e probe:vfs_read_L18 -aR sleep 1

  #

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

diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index 5c86d2cf6338..8f963a193a5d 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -2738,8 +2738,13 @@ static int probe_trace_event__set_name(struct probe_trace_event *tev,
 	if (tev->event == NULL || tev->group == NULL)
 		return -ENOMEM;
 
-	/* Add added event name to namelist */
-	strlist__add(namelist, event);
+	/*
+	 * Add new event name to namelist if multiprobe event is NOT
+	 * supported, since we have to use new event name for following
+	 * probes in that case.
+	 */
+	if (!multiprobe_event_is_supported())
+		strlist__add(namelist, event);
 	return 0;
 }
 
diff --git a/tools/perf/util/probe-file.c b/tools/perf/util/probe-file.c
index b659466ea498..a63f1a19b0e8 100644
--- a/tools/perf/util/probe-file.c
+++ b/tools/perf/util/probe-file.c
@@ -1007,6 +1007,7 @@ enum ftrace_readme {
 	FTRACE_README_KRETPROBE_OFFSET,
 	FTRACE_README_UPROBE_REF_CTR,
 	FTRACE_README_USER_ACCESS,
+	FTRACE_README_MULTIPROBE_EVENT,
 	FTRACE_README_END,
 };
 
@@ -1020,6 +1021,7 @@ static struct {
 	DEFINE_TYPE(FTRACE_README_KRETPROBE_OFFSET, "*place (kretprobe): *"),
 	DEFINE_TYPE(FTRACE_README_UPROBE_REF_CTR, "*ref_ctr_offset*"),
 	DEFINE_TYPE(FTRACE_README_USER_ACCESS, "*[u]<offset>*"),
+	DEFINE_TYPE(FTRACE_README_MULTIPROBE_EVENT, "*Create/append/*"),
 };
 
 static bool scan_ftrace_readme(enum ftrace_readme type)
@@ -1085,3 +1087,8 @@ bool user_access_is_supported(void)
 {
 	return scan_ftrace_readme(FTRACE_README_USER_ACCESS);
 }
+
+bool multiprobe_event_is_supported(void)
+{
+	return scan_ftrace_readme(FTRACE_README_MULTIPROBE_EVENT);
+}
diff --git a/tools/perf/util/probe-file.h b/tools/perf/util/probe-file.h
index 986c1c94f64f..850d1b52d60a 100644
--- a/tools/perf/util/probe-file.h
+++ b/tools/perf/util/probe-file.h
@@ -71,6 +71,7 @@ bool probe_type_is_available(enum probe_type type);
 bool kretprobe_offset_is_supported(void);
 bool uprobe_ref_ctr_is_supported(void);
 bool user_access_is_supported(void);
+bool multiprobe_event_is_supported(void);
 #else	/* ! HAVE_LIBELF_SUPPORT */
 static inline struct probe_cache *probe_cache__new(const char *tgt __maybe_unused, struct nsinfo *nsi __maybe_unused)
 {

[PATCH v2 3/4] perf probe: Support DW_AT_const_value constant value

[Masami Hiramatsu]

Support DW_AT_const_value for variable assignment instead of location.
Note that this requires ftrace supporting immediate value.

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

diff --git a/tools/perf/util/probe-file.c b/tools/perf/util/probe-file.c
index a63f1a19b0e8..5003ba403345 100644
--- a/tools/perf/util/probe-file.c
+++ b/tools/perf/util/probe-file.c
@@ -1008,6 +1008,7 @@ enum ftrace_readme {
 	FTRACE_README_UPROBE_REF_CTR,
 	FTRACE_README_USER_ACCESS,
 	FTRACE_README_MULTIPROBE_EVENT,
+	FTRACE_README_IMMEDIATE_VALUE,
 	FTRACE_README_END,
 };
 
@@ -1022,6 +1023,7 @@ static struct {
 	DEFINE_TYPE(FTRACE_README_UPROBE_REF_CTR, "*ref_ctr_offset*"),
 	DEFINE_TYPE(FTRACE_README_USER_ACCESS, "*[u]<offset>*"),
 	DEFINE_TYPE(FTRACE_README_MULTIPROBE_EVENT, "*Create/append/*"),
+	DEFINE_TYPE(FTRACE_README_IMMEDIATE_VALUE, "*\\imm-value,*"),
 };
 
 static bool scan_ftrace_readme(enum ftrace_readme type)
@@ -1092,3 +1094,8 @@ bool multiprobe_event_is_supported(void)
 {
 	return scan_ftrace_readme(FTRACE_README_MULTIPROBE_EVENT);
 }
+
+bool immediate_value_is_supported(void)
+{
+	return scan_ftrace_readme(FTRACE_README_IMMEDIATE_VALUE);
+}
diff --git a/tools/perf/util/probe-file.h b/tools/perf/util/probe-file.h
index 850d1b52d60a..0dba88c0f5f0 100644
--- a/tools/perf/util/probe-file.h
+++ b/tools/perf/util/probe-file.h
@@ -72,6 +72,7 @@ bool kretprobe_offset_is_supported(void);
 bool uprobe_ref_ctr_is_supported(void);
 bool user_access_is_supported(void);
 bool multiprobe_event_is_supported(void);
+bool immediate_value_is_supported(void);
 #else	/* ! HAVE_LIBELF_SUPPORT */
 static inline struct probe_cache *probe_cache__new(const char *tgt __maybe_unused, struct nsinfo *nsi __maybe_unused)
 {
diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
index 9ecea45da4ca..2e3a468c8350 100644
--- a/tools/perf/util/probe-finder.c
+++ b/tools/perf/util/probe-finder.c
@@ -177,6 +177,17 @@ static int convert_variable_location(Dwarf_Die *vr_die, Dwarf_Addr addr,
 	if (dwarf_attr(vr_die, DW_AT_external, &attr) != NULL)
 		goto static_var;
 
+	/* Constant value */
+	if (dwarf_attr(vr_die, DW_AT_const_value, &attr) &&
+	    immediate_value_is_supported()) {
+		Dwarf_Sword snum;
+
+		dwarf_formsdata(&attr, &snum);
+		ret = asprintf(&tvar->value, "\\%ld", (long)snum);
+
+		return ret < 0 ? -ENOMEM : 0;
+	}
+
 	/* TODO: handle more than 1 exprs */
 	if (dwarf_attr(vr_die, DW_AT_location, &attr) == NULL)
 		return -EINVAL;	/* Broken DIE ? */

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

[Masami Hiramatsu]

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.

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 _text+23480787 pud=%ax:x64
p:probe/pud_page_vaddr _text+23808453 pud=%bp:x64
p:probe/pud_page_vaddr _text+23558082 pud=%ax:x64
p:probe/pud_page_vaddr _text+328373 pud=%r8:x64
p:probe/pud_page_vaddr _text+348448 pud=%bx:x64
p:probe/pud_page_vaddr _text+23816818 pud=%bx:x64

With this patch,
# perf probe -D "pud_page_vaddr pud" | head
spurious_kernel_fault is blacklisted function, skip it.
vmalloc_fault is blacklisted function, skip it.
p:probe/pud_page_vaddr _text+23480787 pud=%ax:x64
p:probe/pud_page_vaddr _text+149051 pud=\deade12d:x64
p:probe/pud_page_vaddr _text+23808453 pud=%bp:x64
p:probe/pud_page_vaddr _text+315926 pud=\deade12d:x64
p:probe/pud_page_vaddr _text+23807209 pud=\deade12d:x64
p:probe/pud_page_vaddr _text+23557365 pud=%ax:x64
p:probe/pud_page_vaddr _text+314097 pud=%di:x64
p:probe/pud_page_vaddr _text+314015 pud=\deade12d:x64
p:probe/pud_page_vaddr _text+313893 pud=\deade12d:x64
p:probe/pud_page_vaddr _text+324083 pud=\deade12d:x64

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 Changes in v2:
  - Fix not to check event name.
  - Update before/after example.
---
 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 8f963a193a5d..52b2d165453a 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..1bf3e0ccd83d 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->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 {

Re: [PATCH v2 1/4] perf probe: Generate event name with line number

[Arnaldo Carvalho de Melo]

Em Fri, Nov 08, 2019 at 01:27:58AM +0900, Masami Hiramatsu escreveu:
> Generate event name from function name with line number
> as <function>_L<line_number>. Note that this is only for
> the new event which is defined by the line number of
> function (except for line 0).
> 
> If there is another event on same line, you have to use
> "-f" option. In that case, the new event has "_1" suffix.
> 
>  e.g.
>   # perf probe -a kernel_read:1
>   Added new events:
>     probe:kernel_read_L1 (on kernel_read:1)

While testing this, using the same function (kernel_read), I found it
confusing that it is possible to insert probes in lines seemingly with
no code, for instance:

[root@quaco ~]# perf probe -a kernel_read:1
Added new event:
  probe:kernel_read_L1 (on kernel_read:1)

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

	perf record -e probe:kernel_read_L1 -aR sleep 1

[root@quaco ~]# perf probe -a kernel_read:2
Added new event:
  probe:kernel_read_L2 (on kernel_read:2)

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

	perf record -e probe:kernel_read_L2 -aR sleep 1

[root@quaco ~]#
[root@quaco ~]# perf probe --list
  probe:kernel_read_L1 (on kernel_read@fs/read_write.c)
  probe:kernel_read_L2 (on kernel_read:1@fs/read_write.c)
[root@quaco ~]# perf probe -L kernel_read
<kernel_read@/usr/src/debug/kernel-5.3.fc30/linux-5.3.8-200.fc30.x86_64/fs/read_write.c:0>
      0  ssize_t kernel_read(struct file *file, void *buf, size_t count, loff_t *pos)
      1  {
      2         mm_segment_t old_fs;
      3         ssize_t result;

      5         old_fs = get_fs();
      6         set_fs(KERNEL_DS);
                /* The cast to a user pointer is valid due to the set_fs() */
      8         result = vfs_read(file, (void __user *)buf, count, pos);
      9         set_fs(old_fs);
     10         return result;
         }
         EXPORT_SYMBOL(kernel_read);


[root@quaco ~]#


What is the point of putting a probe on line 2? I is not initializing,
etc, 1 as well, notthing there and we already have 0 (or not specifying
a line number) to put a probe at the start of a function, can you
clarify?

I'll apply this patch, the problem above isn't strictly related to it.

- Arnaldo

Re: [PATCH v2 1/4] perf probe: Generate event name with line number

[Arnaldo Carvalho de Melo]

Em Mon, Nov 11, 2019 at 11:04:50AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Nov 08, 2019 at 01:27:58AM +0900, Masami Hiramatsu escreveu:
> > Generate event name from function name with line number
> > as <function>_L<line_number>. Note that this is only for
> > the new event which is defined by the line number of
> > function (except for line 0).
> > 
> > If there is another event on same line, you have to use
> > "-f" option. In that case, the new event has "_1" suffix.
> > 
> >  e.g.
> >   # perf probe -a kernel_read:1
> >   Added new events:
> >     probe:kernel_read_L1 (on kernel_read:1)
> 
> While testing this, using the same function (kernel_read), I found it
> confusing that it is possible to insert probes in lines seemingly with
> no code, for instance:
> 
> [root@quaco ~]# perf probe -a kernel_read:1
> Added new event:
>   probe:kernel_read_L1 (on kernel_read:1)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe:kernel_read_L1 -aR sleep 1
> 
> [root@quaco ~]# perf probe -a kernel_read:2
> Added new event:
>   probe:kernel_read_L2 (on kernel_read:2)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe:kernel_read_L2 -aR sleep 1
> 
> #
> # perf probe --list
>   probe:kernel_read_l1 (on kernel_read@fs/read_write.c)
>   probe:kernel_read_l2 (on kernel_read:1@fs/read_write.c)


Also look above at the listing, I would expect this instead:

# perf probe --list
  probe:kernel_read_l1 (on kernel_read:1@fs/read_write.c)
  probe:kernel_read_l2 (on kernel_read:2@fs/read_write.c)

Right?

- Arnaldo

> [root@quaco ~]# perf probe -L kernel_read
> <kernel_read@/usr/src/debug/kernel-5.3.fc30/linux-5.3.8-200.fc30.x86_64/fs/read_write.c:0>
>       0  ssize_t kernel_read(struct file *file, void *buf, size_t count, loff_t *pos)
>       1  {
>       2         mm_segment_t old_fs;
>       3         ssize_t result;
> 
>       5         old_fs = get_fs();
>       6         set_fs(KERNEL_DS);
>                 /* The cast to a user pointer is valid due to the set_fs() */
>       8         result = vfs_read(file, (void __user *)buf, count, pos);
>       9         set_fs(old_fs);
>      10         return result;
>          }
>          EXPORT_SYMBOL(kernel_read);
> 
> 
> [root@quaco ~]#
> 
> 
> What is the point of putting a probe on line 2? I is not initializing,
> etc, 1 as well, notthing there and we already have 0 (or not specifying
> a line number) to put a probe at the start of a function, can you
> clarify?
> 
> I'll apply this patch, the problem above isn't strictly related to it.
> 
> - Arnaldo

-- 

- Arnaldo

Re: [PATCH v2 1/4] perf probe: Generate event name with line number

[Arnaldo Carvalho de Melo]

Em Mon, Nov 11, 2019 at 11:06:25AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Mon, Nov 11, 2019 at 11:04:50AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Fri, Nov 08, 2019 at 01:27:58AM +0900, Masami Hiramatsu escreveu:
> > > Generate event name from function name with line number
> > > as <function>_L<line_number>. Note that this is only for
> > > the new event which is defined by the line number of
> > > function (except for line 0).
> > > 
> > > If there is another event on same line, you have to use
> > > "-f" option. In that case, the new event has "_1" suffix.
> > > 
> > >  e.g.
> > >   # perf probe -a kernel_read:1
> > >   Added new events:
> > >     probe:kernel_read_L1 (on kernel_read:1)
> > 
> > While testing this, using the same function (kernel_read), I found it
> > confusing that it is possible to insert probes in lines seemingly with
> > no code, for instance:
> > 
> > [root@quaco ~]# perf probe -a kernel_read:1
> > Added new event:
> >   probe:kernel_read_L1 (on kernel_read:1)
> > 
> > You can now use it in all perf tools, such as:
> > 
> > 	perf record -e probe:kernel_read_L1 -aR sleep 1
> > 
> > [root@quaco ~]# perf probe -a kernel_read:2
> > Added new event:
> >   probe:kernel_read_L2 (on kernel_read:2)
> > 
> > You can now use it in all perf tools, such as:
> > 
> > 	perf record -e probe:kernel_read_L2 -aR sleep 1
> > 
> > #
> > # perf probe --list
> >   probe:kernel_read_l1 (on kernel_read@fs/read_write.c)
> >   probe:kernel_read_l2 (on kernel_read:1@fs/read_write.c)
> 
> 
> Also look above at the listing, I would expect this instead:
> 
> # perf probe --list
>   probe:kernel_read_l1 (on kernel_read:1@fs/read_write.c)
>   probe:kernel_read_l2 (on kernel_read:2@fs/read_write.c)
> 
> Right?

And this one may be a problem with this specific patch, so I'll hold off
processing this series till you have a chance to look at these problems
and reply,

Thanks,

- Arnaldo

Re: [PATCH v2 1/4] perf probe: Generate event name with line number

[Masami Hiramatsu]

Hi Arnaldo,

On Mon, 11 Nov 2019 11:07:33 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Mon, Nov 11, 2019 at 11:06:25AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Mon, Nov 11, 2019 at 11:04:50AM -0300, Arnaldo Carvalho de Melo escreveu:
> > > Em Fri, Nov 08, 2019 at 01:27:58AM +0900, Masami Hiramatsu escreveu:
> > > > Generate event name from function name with line number
> > > > as <function>_L<line_number>. Note that this is only for
> > > > the new event which is defined by the line number of
> > > > function (except for line 0).
> > > > 
> > > > If there is another event on same line, you have to use
> > > > "-f" option. In that case, the new event has "_1" suffix.
> > > > 
> > > >  e.g.
> > > >   # perf probe -a kernel_read:1
> > > >   Added new events:
> > > >     probe:kernel_read_L1 (on kernel_read:1)
> > > 
> > > While testing this, using the same function (kernel_read), I found it
> > > confusing that it is possible to insert probes in lines seemingly with
> > > no code, for instance:
> > > 
> > > [root@quaco ~]# perf probe -a kernel_read:1
> > > Added new event:
> > >   probe:kernel_read_L1 (on kernel_read:1)
> > > 
> > > You can now use it in all perf tools, such as:
> > > 
> > > 	perf record -e probe:kernel_read_L1 -aR sleep 1
> > > 
> > > [root@quaco ~]# perf probe -a kernel_read:2
> > > Added new event:
> > >   probe:kernel_read_L2 (on kernel_read:2)
> > > 
> > > You can now use it in all perf tools, such as:
> > > 
> > > 	perf record -e probe:kernel_read_L2 -aR sleep 1
> > > 
> > > #
> > > # perf probe --list
> > >   probe:kernel_read_l1 (on kernel_read@fs/read_write.c)
> > >   probe:kernel_read_l2 (on kernel_read:1@fs/read_write.c)
> > 
> > 
> > Also look above at the listing, I would expect this instead:
> > 
> > # perf probe --list
> >   probe:kernel_read_l1 (on kernel_read:1@fs/read_write.c)
> >   probe:kernel_read_l2 (on kernel_read:2@fs/read_write.c)
> > 
> > Right?

Yes, it should be so.

> 
> And this one may be a problem with this specific patch, so I'll hold off
> processing this series till you have a chance to look at these problems
> and reply,

OK, let me check the reason why.

Thank you!

> 
> Thanks,
> 
> - Arnaldo


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH v2 1/4] perf probe: Generate event name with line number

[Masami Hiramatsu]

Hi Arnaldo,

On Tue, 12 Nov 2019 17:31:31 +0700
Masami Hiramatsu <mhiramat@kernel.org> wrote:
> > > > # perf probe --list
> > > >   probe:kernel_read_l1 (on kernel_read@fs/read_write.c)
> > > >   probe:kernel_read_l2 (on kernel_read:1@fs/read_write.c)
> > > 
> > > 
> > > Also look above at the listing, I would expect this instead:
> > > 
> > > # perf probe --list
> > >   probe:kernel_read_l1 (on kernel_read:1@fs/read_write.c)
> > >   probe:kernel_read_l2 (on kernel_read:2@fs/read_write.c)
> > > 
> > > Right?
> 
> Yes, it should be so.

Hmm, this looks the limiation of debuginfo generated by gcc.
Let me explain what happens. So, here is the decoded Line info in
debuginfo for kernel_read (is defined in fs/read_write.c:423)

---
$ readelf -wL /usr/lib/debug/boot/vmlinux-5.0.0-32-generic 
...
read_write.c                                 444  0xffffffff812b435d        
read_write.c                                 424  0xffffffff812b4370               x
read_write.c                                 425  0xffffffff812b4375               x
read_write.c                                 426  0xffffffff812b4375       1       x
read_write.c                                 428  0xffffffff812b4375       2       x

---
This shows the line number info points the kernel_read entry address is
on #424, this means we can not distinguish kernel_read:0 and kernel_read:1
from only the address information. (maybe huristically we can distinguish
it by the "_L1" suffix. But if user gives another event name, it doesn't
work.)
---

/build/linux-pvZVvI/linux-5.0.0/arch/x86/include/asm/current.h:
current.h                                     13  0xffffffff812b4375       3       x
current.h                                     15  0xffffffff812b4375       4       x
current.h                                     15  0xffffffff812b4375       5       x
current.h                                     15  0xffffffff812b4375       6       x
current.h                                     15  0xffffffff812b4375       7       x

/build/linux-pvZVvI/linux-5.0.0/fs/read_write.c:
read_write.c                                 424  0xffffffff812b4375       8

---
And it seems that the dwarf_getsrc_die() returns the last line info
correspoinding to given address (0xffffffff812b4375) even if it is
not a stetement line. This is why probe:kernel_read_l2 is 
on kernel_read:1. I will fix that.

However, again, as long as the different lines are encoded in same
address, we can not distinguish them except for checking "_L*"
suffix.

Possible solutions are
 - Do not allow user to put probes on lines which shares the address
   with other lines (user can put a probe only on the earliest line)
 - Warn user that the line shares address with other lines and put
   the probe with the earliest line number suffix.
 - Just warn user. 

THank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH v2 1/4] perf probe: Generate event name with line number

[Arnaldo Carvalho de Melo]

Em Wed, Nov 13, 2019 at 08:01:57AM +0700, Masami Hiramatsu escreveu:
> Hi Arnaldo,
> 
> On Tue, 12 Nov 2019 17:31:31 +0700
> Masami Hiramatsu <mhiramat@kernel.org> wrote:
> > > > > # perf probe --list
> > > > >   probe:kernel_read_l1 (on kernel_read@fs/read_write.c)
> > > > >   probe:kernel_read_l2 (on kernel_read:1@fs/read_write.c)
> > > > 
> > > > 
> > > > Also look above at the listing, I would expect this instead:
> > > > 
> > > > # perf probe --list
> > > >   probe:kernel_read_l1 (on kernel_read:1@fs/read_write.c)
> > > >   probe:kernel_read_l2 (on kernel_read:2@fs/read_write.c)
> > > > 
> > > > Right?
> > 
> > Yes, it should be so.
> 
> Hmm, this looks the limiation of debuginfo generated by gcc.
> Let me explain what happens. So, here is the decoded Line info in
> debuginfo for kernel_read (is defined in fs/read_write.c:423)
> 
> ---
> $ readelf -wL /usr/lib/debug/boot/vmlinux-5.0.0-32-generic 
> ...
> read_write.c                                 444  0xffffffff812b435d        
                                               ^^^
					       424, right?
> read_write.c                                 424  0xffffffff812b4370               x
> read_write.c                                 425  0xffffffff812b4375               x
> read_write.c                                 426  0xffffffff812b4375       1       x
> read_write.c                                 428  0xffffffff812b4375       2       x
> 
> ---
> This shows the line number info points the kernel_read entry address is
> on #424, this means we can not distinguish kernel_read:0 and kernel_read:1
> from only the address information.cw

If both 0xffffffff812b435d and 0xffffffff812b4370 are associated with
line 424, then we should present on 'perf probe -L' just the first one
and do the same when converting from address to name when presenting
with 'perf probe -l'?

> (maybe huristically we can distinguish it by the "_L1" suffix. But if
> user gives another event name, it doesn't work.)

> ---
> 
> /build/linux-pvZVvI/linux-5.0.0/arch/x86/include/asm/current.h:
> current.h                                     13  0xffffffff812b4375       3       x
> current.h                                     15  0xffffffff812b4375       4       x
> current.h                                     15  0xffffffff812b4375       5       x
> current.h                                     15  0xffffffff812b4375       6       x
> current.h                                     15  0xffffffff812b4375       7       x
> 
> /build/linux-pvZVvI/linux-5.0.0/fs/read_write.c:
> read_write.c                                 424  0xffffffff812b4375       8
> 
> ---
> And it seems that the dwarf_getsrc_die() returns the last line info
> correspoinding to given address (0xffffffff812b4375) even if it is
> not a stetement line. This is why probe:kernel_read_l2 is 
> on kernel_read:1. I will fix that.

by going backwards from what dwarf_getsrc_die() returns till it finds a
statement line?
 
> However, again, as long as the different lines are encoded in same

It is possible as well to have different addresses associated with the
same source code line.

> address, we can not distinguish them except for checking "_L*"
> suffix.
> 
> Possible solutions are
>  - Do not allow user to put probes on lines which shares the address
>    with other lines (user can put a probe only on the earliest line)


>  - Warn user that the line shares address with other lines and put
>    the probe with the earliest line number suffix.
>  - Just warn user. 
> 
> THank you,
> 
> -- 
> Masami Hiramatsu <mhiramat@kernel.org>

-- 

- Arnaldo

Re: [PATCH v2 1/4] perf probe: Generate event name with line number

[Masami Hiramatsu]

On Wed, 13 Nov 2019 09:09:27 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Wed, Nov 13, 2019 at 08:01:57AM +0700, Masami Hiramatsu escreveu:
> > Hi Arnaldo,
> > 
> > On Tue, 12 Nov 2019 17:31:31 +0700
> > Masami Hiramatsu <mhiramat@kernel.org> wrote:
> > > > > > # perf probe --list
> > > > > >   probe:kernel_read_l1 (on kernel_read@fs/read_write.c)
> > > > > >   probe:kernel_read_l2 (on kernel_read:1@fs/read_write.c)
> > > > > 
> > > > > 
> > > > > Also look above at the listing, I would expect this instead:
> > > > > 
> > > > > # perf probe --list
> > > > >   probe:kernel_read_l1 (on kernel_read:1@fs/read_write.c)
> > > > >   probe:kernel_read_l2 (on kernel_read:2@fs/read_write.c)
> > > > > 
> > > > > Right?
> > > 
> > > Yes, it should be so.
> > 
> > Hmm, this looks the limiation of debuginfo generated by gcc.
> > Let me explain what happens. So, here is the decoded Line info in
> > debuginfo for kernel_read (is defined in fs/read_write.c:423)
> > 
> > ---
> > $ readelf -wL /usr/lib/debug/boot/vmlinux-5.0.0-32-generic 
> > ...
> > read_write.c                                 444  0xffffffff812b435d        
>                                                ^^^
> 					       424, right?

No, the line info is sorted by address. This seems strange, but happens sometimes :)

> > read_write.c                                 424  0xffffffff812b4370               x
> > read_write.c                                 425  0xffffffff812b4375               x
> > read_write.c                                 426  0xffffffff812b4375       1       x
> > read_write.c                                 428  0xffffffff812b4375       2       x
> > 
> > ---
> > This shows the line number info points the kernel_read entry address is
> > on #424, this means we can not distinguish kernel_read:0 and kernel_read:1
> > from only the address information.cw
> 
> If both 0xffffffff812b435d and 0xffffffff812b4370 are associated with
> line 424, then we should present on 'perf probe -L' just the first one
> and do the same when converting from address to name when presenting
> with 'perf probe -l'?

OK, so we can pick only one of them (the first "statement" line among
several lines which shares same address), and show only that line can
be probed by perf probe -L.

> 
> > (maybe huristically we can distinguish it by the "_L1" suffix. But if
> > user gives another event name, it doesn't work.)
> 
> > ---
> > 
> > /build/linux-pvZVvI/linux-5.0.0/arch/x86/include/asm/current.h:
> > current.h                                     13  0xffffffff812b4375       3       x
> > current.h                                     15  0xffffffff812b4375       4       x
> > current.h                                     15  0xffffffff812b4375       5       x
> > current.h                                     15  0xffffffff812b4375       6       x
> > current.h                                     15  0xffffffff812b4375       7       x
> > 
> > /build/linux-pvZVvI/linux-5.0.0/fs/read_write.c:
> > read_write.c                                 424  0xffffffff812b4375       8
> > 
> > ---
> > And it seems that the dwarf_getsrc_die() returns the last line info
> > correspoinding to given address (0xffffffff812b4375) even if it is
> > not a stetement line. This is why probe:kernel_read_l2 is 
> > on kernel_read:1. I will fix that.
> 
> by going backwards from what dwarf_getsrc_die() returns till it finds a
> statement line?

Moreover, going backward and forward until it finds the smallest line
number which is a statement. Because it uses a binary search, it can
find non-statement lines.

>  
> > However, again, as long as the different lines are encoded in same
> 
> It is possible as well to have different addresses associated with the
> same source code line.

That is OK, since we now support multiprobes. We can put probes on
different addresses on same line (but different column).

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>