perf/probe: Fix available line bugs

Hi,

Here are some bugfixes related to showing available line (--line/-L) option. I found that gcc generated some subprogram DIE with only range attribute but no entry_pc or low_pc attributes.
In that case, perf probe failed to show the available lines in that subprogram (function). To fix that, I introduced some bugfixes to handle such cases correctly.

Thank you,

---

Masami Hiramatsu (3):
perf/probe: Fix to find range-only function instance perf/probe: Walk function lines in lexical blocks perf/probe: Fix to show function entry line as probe-able

 tools/perf/util/dwarf-aux.c |   44 ++++++++++++++++++++++++++++++++++++-------
 tools/perf/util/dwarf-aux.h |    3 +++
 2 files changed, 40 insertions(+), 7 deletions(-)

--
Masami Hiramatsu (Linaro) <[email protected]>

Fix die_is_func_instance() to find range-only function instance.

In some case, a function instance can be made without any low PC or entry PC, but only with address ranges by optimization. (e.g. cold text partially in "text.unlikely" section) To find such function instance, we have to check the range attribute too.

---
 tools/perf/util/dwarf-aux.c |    6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

index df6cee5c071f..2ec24c3bed44 100644
@@ -318,10 +318,14 @@ bool die_is_func_def(Dwarf_Die *dw_die)
 bool die_is_func_instance(Dwarf_Die *dw_die)
 {
 	Dwarf_Addr tmp;
+	Dwarf_Attribute attr_mem;
 
 	/* Actually gcc optimizes non-inline as like as inlined */
-	return !dwarf_func_inline(dw_die) && dwarf_entrypc(dw_die, &tmp) == 0;
+	return !dwarf_func_inline(dw_die) &&
+	       (dwarf_entrypc(dw_die, &tmp) == 0 ||
+		dwarf_attr(dw_die, DW_AT_ranges, &attr_mem) != NULL);
 }
+
 /**
  * die_get_data_member_location - Get the data-member offset
  * @mb_die: a DIE of a member of a data structure

Since some inlined functions are in lexical blocks of given function, we have to recursively walk through the DIE tree. Without this fix, perf-probe -L can miss the inlined functions which is in a lexcical block (like if (..) { func() } case.)

However, even though, to walk the lines in a given function, we don't need to follow the children DIE of inlined functions because those do not have any lines in the specified function.

We need to walk though whole trees only if we walk all lines in a given file, because an inlined function can include another inlined function in the same file.

---
 tools/perf/util/dwarf-aux.c |   14 +++++++++-----
 1 file changed, 9 insertions(+), 5 deletions(-)

index 2ec24c3bed44..929b7c0567f4 100644
@@ -678,10 +678,9 @@ static int __die_walk_funclines_cb(Dwarf_Die *in_die, void *data)
 			if (lw->retval != 0)
 				return DIE_FIND_CB_END;
 		}
+		if (!lw->recursive)
+			return DIE_FIND_CB_SIBLING;
 	}
-	if (!lw->recursive)
-		/* Don't need to search recursively */
-		return DIE_FIND_CB_SIBLING;
 
 	if (addr) {
 		fname = dwarf_decl_file(in_die);

@@ -728,6 +727,10 @@ static int __die_walk_culines_cb(Dwarf_Die *sp_die, void *data)
 {
 	struct __line_walk_param *lw = data;
 
+	/*
+	 * Since inlined function can include another inlined function in
+	 * the same file, we need to walk in it recursively.
+	 */
 	lw->retval = __die_walk_funclines(sp_die, true, lw->callback, lw->data);
 	if (lw->retval != 0)
 		return DWARF_CB_ABORT;

@@ -817,8 +820,9 @@ int die_walk_lines(Dwarf_Die *rt_die, line_walk_callback_t callback, void *data)
 	 */
 	if (rt_die != cu_die)
 		/*
-		 * Don't need walk functions recursively, because nested
-		 * inlined functions don't have lines of the specified DIE.
+		 * Don't need walk inlined functions recursively, because
+		 * inner inlined functions don't have the lines of the
+		 * specified function.
 		 */
 		ret = __die_walk_funclines(rt_die, false, callback, data);
 	else {

Fix die_walk_lines() to list the function entry line correctly. Since the dwarf_entrypc() does not return the entry pc if the DIE has only range attribute, __die_walk_funclines() fails to list the declaration line (entry line) in that case.

To solve this issue, this introduces die_entrypc() which correctly returns the entry PC (the first address range) even if the DIE has only range attribute. With this fix die_walk_lines() shows the function entry line is able to probe correctly.

---
 tools/perf/util/dwarf-aux.c |   24 +++++++++++++++++++++++-
 tools/perf/util/dwarf-aux.h |    3 +++
 2 files changed, 26 insertions(+), 1 deletion(-)

index 929b7c0567f4..063f71da6b63 100644
@@ -307,6 +307,28 @@ bool die_is_func_def(Dwarf_Die *dw_die)
 		dwarf_attr(dw_die, DW_AT_declaration, &attr) == NULL);
 }
 
+/**
+ * die_entrypc - Returns entry PC (the lowest address) of a DIE
+ * @dw_die: a DIE
+ * @addr: where to store entry PC
+ *
+ * Since dwarf_entrypc() does not return entry PC if the DIE has only address
+ * range, we have to use this to retrieve the lowest address from the address
+ * range attribute.
+ */
+int die_entrypc(Dwarf_Die *dw_die, Dwarf_Addr *addr)
+{
+	Dwarf_Addr base, end;
+
+	if (!addr)
+		return -EINVAL;
+
+	if (dwarf_entrypc(dw_die, addr) == 0)
+		return 0;
+
+	return dwarf_ranges(dw_die, 0, &base, addr, &end) < 0 ? -ENOENT : 0;
+}
+
 /**
  * die_is_func_instance - Ensure that this DIE is an instance of a subprogram
  * @dw_die: a DIE

@@ -713,7 +735,7 @@ static int __die_walk_funclines(Dwarf_Die *sp_die, bool recursive,
 	/* Handle function declaration line */
 	fname = dwarf_decl_file(sp_die);
 	if (fname && dwarf_decl_line(sp_die, &lineno) == 0 &&
-	    dwarf_entrypc(sp_die, &addr) == 0) {
+	    die_entrypc(sp_die, &addr) == 0) {
 		lw.retval = callback(fname, lineno, addr, data);
 		if (lw.retval != 0)
 			goto done;

index f204e5892403..506006e0cf66 100644
@@ -29,6 +29,9 @@ int cu_walk_functions_at(Dwarf_Die *cu_die, Dwarf_Addr addr,
 /* Get DW_AT_linkage_name (should be NULL for C binary) */
 const char *die_get_linkage_name(Dwarf_Die *dw_die);
 
+/* Get the lowest PC in DIE (including range list) */
+int die_entrypc(Dwarf_Die *dw_die, Dwarf_Addr *addr);
+
 /* Ensure that this DIE is a subprogram and definition (not declaration) */
 bool die_is_func_def(Dwarf_Die *dw_die);
 

Em Thu, Oct 24, 2019 at 06:12:27PM +0900, Masami Hiramatsu escreveu:

Thanks, applied, next time please provide concrete examples for things that don't work before and gets fixed with your patches, this way we can more easily reproduce your steps.

- Arnaldo

- Arnaldo

Hi Arnaldo,

OK, I'll try, but I found that this kind of examples depend on gcc optimization (like build option, gcc version etc.) So even if you can not reproduce, don't be disappointed ;)

Anyway, for this series, I found that clear_tasks_mm_cpumask() caused the (triple) issues.

So, without any patch, I got below error.

$ tools/perf/perf probe -k ../build-x86_64/vmlinux -L clear_tasks_mm_cpumask
Specified source line is not found.
  Error: Failed to show lines.

Hmm, there should be something wrong... so I fixed it with [1/3]. (to find appropriate target function, you can use "eu-readelf -w vmlinux"
and find the subprogram which has no entry_pc nor low_pc but has ranges)

$ tools/perf/perf probe -k ../build-x86_64/vmlinux -L clear_tasks_mm_cpumask
<clear_tasks_mm_cpumask@/home/mhiramat/ksrc/mincs/work/linux/linux/kernel/cpu.c:
         void clear_tasks_mm_cpumask(int cpu)
      1  {
      2         struct task_struct *p;

                /*
                 * This function is called after the cpu is taken down and marke
                 * offline, so its not like new tasks will ever get this cpu set
                 * their mm mask. -- Peter Zijlstra
                 * Thus, we may use rcu_read_lock() here, instead of grabbing
                 * full-fledged tasklist_lock.
                 */
     11         WARN_ON(cpu_online(cpu));
     12         rcu_read_lock();
     13         for_each_process(p) {
     14                 struct task_struct *t;
         
                        /*
                         * Main thread might exit, but other threads may still h
                         * a valid mm. Find one.
                         */
     20                 t = find_lock_task_mm(p);
     21                 if (!t)
                                continue;
                        cpumask_clear_cpu(cpu, mm_cpumask(t->mm));
                        task_unlock(t);
                }
     26         rcu_read_unlock();
     27  }

OK! it looks working... but a bit wired. why line #0, #23 and #24 are not available?
I investigated it and found a wrong logic and fixed it with [2/3]

$ tools/perf/perf probe -k ../build-x86_64/vmlinux -L clear_tasks_mm_cpumask:20
<clear_tasks_mm_cpumask@/home/mhiramat/ksrc/mincs/work/linux/linux/kernel/cpu.c:
     20                 t = find_lock_task_mm(p);
     21                 if (!t)
                                continue;
     23                 cpumask_clear_cpu(cpu, mm_cpumask(t->mm));
     24                 task_unlock(t);
                }
     26         rcu_read_unlock();
     27  }

OK, it found line #23 and #24. And add [3/3]

$ tools/perf/perf probe -k ../build-x86_64/vmlinux -L clear_tasks_mm_cpumask
<clear_tasks_mm_cpumask@/home/mhiramat/ksrc/mincs/work/linux/linux/kernel/cpu.c:
      0  void clear_tasks_mm_cpumask(int cpu)
      1  {
      2         struct task_struct *p;

OK, so now it works well :)

Thank you,

Masami Hiramatsu <[email protected]>

Em Fri, Oct 25, 2019 at 12:36:48AM +0900, Masami Hiramatsu escreveu:

Don't worry about that, even if I don't manage to reproduce I'm convinced that having the set of steps to reproduce the problem, with actual output from tools, and your step-by-step explanations helps whoever feels like reviewing your patch, so thanks a lot for doing what I suggested.

So, lets try to repro...

[root@quaco ~]# perf probe clear_tasks_mm_cpumask
Probe point 'clear_tasks_mm_cpumask' not found.
Error: Failed to add events.
[root@quaco ~]# uname -r
5.2.18-200.fc30.x86_64
[root@quaco ~]# rpm -q kernel-debuginfo
kernel-debuginfo-5.2.15-200.fc30.x86_64
kernel-debuginfo-5.2.17-200.fc30.x86_64
kernel-debuginfo-5.2.18-200.fc30.x86_64
[root@quaco ~]# grep clear_tasks /proc/kallsyms
ffffffffaa0e09a0 T clear_tasks_mm_cpumask
ffffffffaa0e10d3 t clear_tasks_mm_cpumask.cold
[root@quaco ~]#

woah! Seems I'm on the right track :-)

So I don't know where is this vmlinux, lets try to find it:

[root@quaco ~]# perf probe -v clear_tasks_mm_cpumask probe-definition(0): clear_tasks_mm_cpumask symbol:clear_tasks_mm_cpumask file:(null) line:0 offset:0 return:0 lazy:(null) 0 arguments
Looking at the vmlinux_path (8 entries long)
Using /usr/lib/debug/lib/modules/5.2.18-200.fc30.x86_64/vmlinux for symbols Open Debuginfo file: /usr/lib/debug/lib/modules/5.2.18-200.fc30.x86_64/vmlinux Try to find probe point from debuginfo.
Matched function: clear_tasks_mm_cpumask [14d33f6] clear_tasks_mm_cpumask has no entry PC. Skipped
Symbol clear_tasks_mm_cpumask address found : ffffffff810e09a0 Matched function: clear_tasks_mm_cpumask [14d33f6] clear_tasks_mm_cpumask has no entry PC. Skipped
Probe point 'clear_tasks_mm_cpumask' not found.
Error: Failed to add events. Reason: No such file or directory (Code: -2)
[root@quaco ~]#

Ok /usr/lib/debug/lib/modules/5.2.18-200.fc30.x86_64/vmlinux, then:

[root@quaco ~]# eu-readelf -w /usr/lib/debug/lib/modules/5.2.18-200.fc30.x86_64/vmlinux | grep clear_tasks_mm_cpumask -B5 -A30 <go grab some coffee>
[14d3770] inlined_subroutine abbrev: 32

               abstract_origin      (ref4) [14d8d01]
               entry_pc             (addr) 0xffffffff810e09b7 <clear_tasks_mm_cpumask+0x17>
               GNU_entry_view       (data2) 7
               ranges               (sec_offset) range list [11e9d0]
               call_file            (data1) cpu.c (1)
               call_line            (data2) 817
               call_column          (data1) 2
               sibling              (ref4) [14d37b0]
 [14d378b]        inlined_subroutine   abbrev: 176
                 abstract_origin      (ref4) [14d8d16]
                 entry_pc             (addr) 0xffffffff810e09b7 <clear_tasks_mm_cpumask+0x17>
                 GNU_entry_view       (data2) 9
                 low_pc               (addr) 0xffffffff810e09b7 <clear_tasks_mm_cpumask+0x17>
                 high_pc              (data8) 0 (0xffffffff810e09b7 <clear_tasks_mm_cpumask+0x17>)
                 call_file            (data1) rcupdate.h (23)
                 call_line            (data2) 591
                 call_column          (data1) 2
 [14d37b0]      inlined_subroutine   abbrev: 53
               abstract_origin      (ref4) [14d8cf6]
               entry_pc             (addr) 0xffffffff810e0a07 <clear_tasks_mm_cpumask+0x67>
               GNU_entry_view       (data2) 2
               ranges               (sec_offset) range list [11ec40]
               call_file            (data1) cpu.c (1)
               call_line            (data2) 831
               call_column          (data1) 2
 [14d37c7]        inlined_subroutine   abbrev: 176
                 abstract_origin      (ref4) [14d8d0c]
                 entry_pc             (addr) 0xffffffff810e0a07 <clear_tasks_mm_cpumask+0x67>
                 GNU_entry_view       (data2) 8
                 low_pc               (addr) 0xffffffff810e0a07 <clear_tasks_mm_cpumask+0x67>
                 high_pc              (data8) 0 (0xffffffff810e0a07 <clear_tasks_mm_cpumask+0x67>)
                 call_file            (data1) rcupdate.h (23)
                 call_line            (data2) 646
                 call_column          (data1

Ok, so, the above output is with your patches, as well as the following, which, for -L, matches your results:

[root@quaco ~]# perf probe -L clear_tasks_mm_cpumask <clear_tasks_mm_cpumask@/usr/src/debug/kernel-5.2.fc30/linux-5.2.18-200.fc30.x86_64/kernel/cpu.c:0>

      0  void clear_tasks_mm_cpumask(int cpu)
      1  {
      2         struct task_struct *p;

                /*
                 * This function is called after the cpu is taken down and marked
                 * offline, so its not like new tasks will ever get this cpu set in
                 * their mm mask. -- Peter Zijlstra
                 * Thus, we may use rcu_read_lock() here, instead of grabbing
                 * full-fledged tasklist_lock.
                 */
     11         WARN_ON(cpu_online(cpu));
     12         rcu_read_lock();
     13         for_each_process(p) {
     14                 struct task_struct *t;

                        /*
                         * Main thread might exit, but other threads may still have
                         * a valid mm. Find one.
                         */
     20                 t = find_lock_task_mm(p);
     21                 if (!t)
                                continue;
     23                 cpumask_clear_cpu(cpu, mm_cpumask(t->mm));
     24                 task_unlock(t);
                }
     26         rcu_read_unlock();
     27  }

         /* Take this CPU down. */
         static int take_cpu_down(void *_param)

[root@quaco ~]# perf probe clear_tasks_mm_cpumask
Probe point 'clear_tasks_mm_cpumask' not found.
Error: Failed to add events.
[root@quaco ~]#

But why can't I probe this thing again?

[root@quaco ~]# perf probe clear_tasks_mm_cpumask:0 Probe point 'clear_tasks_mm_cpumask' not found.
Error: Failed to add events.
[root@quaco ~]# perf probe clear_tasks_mm_cpumask:1 Failed to get entry address of clear_tasks_mm_cpumask
Error: Failed to add events.
[root@quaco ~]# perf probe clear_tasks_mm_cpumask:2 Failed to get entry address of clear_tasks_mm_cpumask
Error: Failed to add events.
[root@quaco ~]# perf probe clear_tasks_mm_cpumask:11 Failed to get entry address of clear_tasks_mm_cpumask
Error: Failed to add events.
[root@quaco ~]# perf probe clear_tasks_mm_cpumask:12 Failed to get entry address of clear_tasks_mm_cpumask
Error: Failed to add events.
[root@quaco ~]# perf probe clear_tasks_mm_cpumask:13 Failed to get entry address of clear_tasks_mm_cpumask
Error: Failed to add events.
root@quaco ~]#

[root@quaco ~]# rpm -qf /usr/lib/debug/lib/modules/5.2.18-200.fc30.x86_64/vmlinux kernel-debuginfo-5.2.18-200.fc30.x86_64
[root@quaco ~]#

[root@quaco ~]# readelf -wi /usr/lib/debug/lib/modules/5.2.18-200.fc30.x86_64/vmlinux | grep "DW_AT_producer.*GNU C" -m1 -A6

    <2e>   DW_AT_producer    : (indirect string, offset: 0xf1c6): GNU C89 9.2.1 20190827 (Red Hat 9.2.1-1) -mno-sse -mno-mmx -mno-sse2 -mno-3dnow -mno-avx -m64 -mno-80387 -mno-fp-ret-in-387 -mpreferred-stack-boundary=3 -mskip-rax-setup -mtune=generic -mno-red-zone -mcmodel=kernel -mindirect-branch=thunk-extern -mindirect-branch-register -mrecord-mcount -mfentry -march=x86-64 -g -O2 -std=gnu90 -fno-strict-aliasing -fno-common -fshort-wchar -fno-PIE -falign-jumps=1 -falign-loops=1 -fno-asynchronous-unwind-tables -fno-jump-tables -fno-delete-null-pointer-checks -fstack-protector-strong -fvar-tracking-assignments -fno-strict-overflow -fno-merge-all-constants -fmerge-constants -fstack-check=no -fconserve-stack --param allow-store-data-races=0
    <32>   DW_AT_language    : 1	(ANSI C)
    <33>   DW_AT_name        : (indirect string, offset: 0xdfe59): arch/x86/kernel/head64.c
    <37>   DW_AT_comp_dir    : (indirect string, offset: 0x4d33f): /usr/src/debug/kernel-5.2.fc30/linux-5.2.18-200.fc30.x86_64
    <3b>   DW_AT_ranges      : 0x5f0
    <3f>   DW_AT_low_pc      : 0x0
    <47>   DW_AT_stmt_list   : 0x165

[root@quaco ~]#

- Arnaldo

Oops, it's a verification error in convert_to_trace_point(). I'll fix it too!

Thank you,

Masami Hiramatsu <[email protected]>