perf report: Print al_addr when symbol is not found
authorJin Yao <yao.jin@linux.intel.com>
Thu, 27 Feb 2020 04:39:37 +0000 (12:39 +0800)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Mon, 23 Mar 2020 14:08:29 +0000 (11:08 -0300)
For branch mode, if the symbol is not found, it prints
the address.

For example, 0x0000555eee0365a0 in below output.

  Overhead  Command  Source Shared Object  Source Symbol                            Target Symbol
    17.55%  div      libc-2.27.so          [.] __random                             [.] __random
     6.11%  div      div                   [.] 0x0000555eee0365a0                   [.] rand
     6.10%  div      libc-2.27.so          [.] rand                                 [.] 0x0000555eee036769
     5.80%  div      libc-2.27.so          [.] __random_r                           [.] __random
     5.72%  div      libc-2.27.so          [.] __random                             [.] __random_r
     5.62%  div      libc-2.27.so          [.] __random_r                           [.] __random_r
     5.38%  div      libc-2.27.so          [.] __random                             [.] rand
     4.56%  div      libc-2.27.so          [.] __random                             [.] __random
     4.49%  div      div                   [.] 0x0000555eee036779                   [.] 0x0000555eee0365ff
     4.25%  div      div                   [.] 0x0000555eee0365fa                   [.] 0x0000555eee036760

But it's not very easy to understand what the instructions
are in the binary. So this patch uses the al_addr instead.

With this patch, the output is

  Overhead  Command  Source Shared Object  Source Symbol                            Target Symbol
    17.55%  div      libc-2.27.so          [.] __random                             [.] __random
     6.11%  div      div                   [.] 0x00000000000005a0                   [.] rand
     6.10%  div      libc-2.27.so          [.] rand                                 [.] 0x0000000000000769
     5.80%  div      libc-2.27.so          [.] __random_r                           [.] __random
     5.72%  div      libc-2.27.so          [.] __random                             [.] __random_r
     5.62%  div      libc-2.27.so          [.] __random_r                           [.] __random_r
     5.38%  div      libc-2.27.so          [.] __random                             [.] rand
     4.56%  div      libc-2.27.so          [.] __random                             [.] __random
     4.49%  div      div                   [.] 0x0000000000000779                   [.] 0x00000000000005ff
     4.25%  div      div                   [.] 0x00000000000005fa                   [.] 0x0000000000000760

Now we can use objdump to dump the object starting from 0x5a0.

For example,
objdump -d --start-address 0x5a0 div

00000000000005a0 <rand@plt>:
 5a0:   ff 25 2a 0a 20 00       jmpq   *0x200a2a(%rip)        # 200fd0 <__cxa_finalize@plt+0x200a20>
 5a6:   68 02 00 00 00          pushq  $0x2
 5ab:   e9 c0 ff ff ff          jmpq   570 <srand@plt-0x10>
 ...

Committer testing:

  [root@seventh ~]# perf record -a -b sleep 1
  [root@seventh ~]# perf report --header-only | grep cpudesc
  # cpudesc : Intel(R) Core(TM) i5-7500 CPU @ 3.40GHz
  [root@seventh ~]# perf evlist -v
  cycles: size: 120, { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|CPU|PERIOD|BRANCH_STACK, read_format: ID, disabled: 1, inherit: 1, mmap: 1, comm: 1, freq: 1, task: 1, precise_ip: 3, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1, ksymbol: 1, bpf_event: 1, branch_sample_type: ANY
  [root@seventh ~]#

Before:

  [root@seventh ~]# perf report --stdio --dso libsystemd-shared-241.so | head -20
  # To display the perf.data header info, please use --header/--header-only options.
  #
  #
  # Total Lost Samples: 0
  #
  # Samples: 2K of event 'cycles'
  # Event count (approx.): 2240
  #
  # Overhead  Command          Source Shared Object      Source Symbol           Target Symbol           Basic Block Cycles
  # ........  ...............  ........................  ......................  ......................  ..................
  #
       0.13%  systemd-journal  libc-2.29.so              [.] cfree@GLIBC_2.2.5   [.] _int_free           1
       0.09%  systemd          libsystemd-shared-241.so  [.] 0x00007fe406465c82  [.] 0x00007fe406465d80  1
       0.09%  systemd          libsystemd-shared-241.so  [.] 0x00007fe406465ded  [.] 0x00007fe406465c30  1
       0.09%  systemd          libsystemd-shared-241.so  [.] 0x00007fe406465e4e  [.] 0x00007fe406465de0  1
       0.09%  systemd-journal  systemd-journald          [.] free@plt            [.] cfree@GLIBC_2.2.5   1
       0.09%  systemd-journal  libc-2.29.so              [.] _int_free           [.] _int_free           18
       0.09%  systemd-journal  libc-2.29.so              [.] _int_free           [.] _int_free           2
       0.04%  systemd          libsystemd-shared-241.so  [.] bus_resolve@plt     [.] bus_resolve         204
       0.04%  systemd          libsystemd-shared-241.so  [.] getpid_cached@plt   [.] getpid_cached       7
  [root@seventh ~]#

After:

  [root@seventh ~]# perf report --stdio --dso libsystemd-shared-241.so | head -20
  # To display the perf.data header info, please use --header/--header-only options.
  #
  #
  # Total Lost Samples: 0
  #
  # Samples: 2K of event 'cycles'
  # Event count (approx.): 2240
  #
  # Overhead  Command          Source Shared Object      Source Symbol           Target Symbol           Basic Block Cycles
  # ........  ...............  ........................  ......................  ......................  ..................
  #
       0.13%  systemd-journal  libc-2.29.so              [.] cfree@GLIBC_2.2.5   [.] _int_free           1
       0.09%  systemd          libsystemd-shared-241.so  [.] 0x00000000000f7c82  [.] 0x00000000000f7d80  1
       0.09%  systemd          libsystemd-shared-241.so  [.] 0x00000000000f7ded  [.] 0x00000000000f7c30  1
       0.09%  systemd          libsystemd-shared-241.so  [.] 0x00000000000f7e4e  [.] 0x00000000000f7de0  1
       0.09%  systemd-journal  systemd-journald          [.] free@plt            [.] cfree@GLIBC_2.2.5   1
       0.09%  systemd-journal  libc-2.29.so              [.] _int_free           [.] _int_free           18
       0.09%  systemd-journal  libc-2.29.so              [.] _int_free           [.] _int_free           2
       0.04%  systemd          libsystemd-shared-241.so  [.] bus_resolve@plt     [.] bus_resolve         204
       0.04%  systemd          libsystemd-shared-241.so  [.] getpid_cached@plt   [.] getpid_cached       7
  [root@seventh ~]#

Lets use -v to get full paths and then try objdump on the unresolved address:

  [root@seventh ~]# perf report -v --stdio --dso libsystemd-shared-241.so |& grep libsystemd-shared-241.so | tail -1
     0.04% systemd-journal /usr/lib/systemd/libsystemd-shared-241.so 0x80c1a B [.] 0x0000000000080c1a 0x80a95 B [.] 0x0000000000080a95 61
  [root@seventh ~]#

  [root@seventh ~]# objdump -d --start-address 0x00000000000f7d80 /usr/lib/systemd/libsystemd-shared-241.so | head -20

  /usr/lib/systemd/libsystemd-shared-241.so:     file format elf64-x86-64

  Disassembly of section .text:

  00000000000f7d80 <proc_cmdline_parse_given@@SD_SHARED+0x330>:
     f7d80: 41 39 11              cmp    %edx,(%r9)
     f7d83: 0f 84 ff fe ff ff     je     f7c88 <proc_cmdline_parse_given@@SD_SHARED+0x238>
     f7d89: 4c 8d 05 97 09 0c 00  lea    0xc0997(%rip),%r8        # 1b8727 <utf8_skip_data@@SD_SHARED+0x3147>
     f7d90: b9 49 00 00 00        mov    $0x49,%ecx
     f7d95: 48 8d 15 c9 f5 0b 00  lea    0xbf5c9(%rip),%rdx        # 1b7365 <utf8_skip_data@@SD_SHARED+0x1d85>
     f7d9c: 31 ff                 xor    %edi,%edi
     f7d9e: 48 8d 35 9b ff 0b 00  lea    0xbff9b(%rip),%rsi        # 1b7d40 <utf8_skip_data@@SD_SHARED+0x2760>
     f7da5: e8 a6 d6 f4 ff        callq  45450 <log_assert_failed_realm@plt>
     f7daa: 66 0f 1f 44 00 00     nopw   0x0(%rax,%rax,1)
     f7db0: 41 56                 push   %r14
     f7db2: 41 55                 push   %r13
     f7db4: 41 54                 push   %r12
     f7db6: 55                    push   %rbp
  [root@seventh ~]#

If we tried the the reported address before this patch:

  [root@seventh ~]# objdump -d --start-address 0x00007fe406465d80 /usr/lib/systemd/libsystemd-shared-241.so | head -20

  /usr/lib/systemd/libsystemd-shared-241.so:     file format elf64-x86-64

  [root@seventh ~]#

Signed-off-by: Jin Yao <yao.jin@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Tested-by: Ravi Bangoria <ravi.bangoria@linux.ibm.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lore.kernel.org/lkml/20200227043939.4403-2-yao.jin@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
tools/perf/util/sort.c

index ab0cfd7..e860595 100644 (file)
@@ -869,7 +869,8 @@ static int hist_entry__sym_from_snprintf(struct hist_entry *he, char *bf,
        if (he->branch_info) {
                struct addr_map_symbol *from = &he->branch_info->from;
 
-               return _hist_entry__sym_snprintf(&from->ms, from->addr, he->level, bf, size, width);
+               return _hist_entry__sym_snprintf(&from->ms, from->al_addr,
+                                                he->level, bf, size, width);
        }
 
        return repsep_snprintf(bf, size, "%-*.*s", width, width, "N/A");
@@ -881,7 +882,8 @@ static int hist_entry__sym_to_snprintf(struct hist_entry *he, char *bf,
        if (he->branch_info) {
                struct addr_map_symbol *to = &he->branch_info->to;
 
-               return _hist_entry__sym_snprintf(&to->ms, to->addr, he->level, bf, size, width);
+               return _hist_entry__sym_snprintf(&to->ms, to->al_addr,
+                                                he->level, bf, size, width);
        }
 
        return repsep_snprintf(bf, size, "%-*.*s", width, width, "N/A");