Commit Graph

11 Commits

Author SHA1 Message Date
Milian Wolff
5ea0416f51 perf report: Include partial stacks unwound with libdw
So far the whole stack was thrown away when any error occurred before
the maximum stack depth was unwound. This is actually a very common
scenario though. The stacks that got unwound so far are still
interesting. This removes a large chunk of differences when comparing
perf script output for libunwind and libdw perf unwinding.

E.g. with libunwind:

~~~~~
heaptrack_gui  2228 135073.388524:     479408 cycles:
        ffffffff811749ed perf_iterate_ctx ([kernel.kallsyms])
        ffffffff81181662 perf_event_mmap ([kernel.kallsyms])
        ffffffff811cf5ed mmap_region ([kernel.kallsyms])
        ffffffff811cfe6b do_mmap ([kernel.kallsyms])
        ffffffff811b0dca vm_mmap_pgoff ([kernel.kallsyms])
        ffffffff811cdb0c sys_mmap_pgoff ([kernel.kallsyms])
        ffffffff81033acb sys_mmap ([kernel.kallsyms])
        ffffffff81631d37 entry_SYSCALL_64_fastpath ([kernel.kallsyms])
                   192ca mmap64 (/usr/lib/ld-2.25.so)
                    59a9 _dl_map_object_from_fd (/usr/lib/ld-2.25.so)
                    83d0 _dl_map_object (/usr/lib/ld-2.25.so)
                    cda1 openaux (/usr/lib/ld-2.25.so)
                   1834f _dl_catch_error (/usr/lib/ld-2.25.so)
                    cfe2 _dl_map_object_deps (/usr/lib/ld-2.25.so)
                    3481 dl_main (/usr/lib/ld-2.25.so)
                   17387 _dl_sysdep_start (/usr/lib/ld-2.25.so)
                    4d37 _dl_start (/usr/lib/ld-2.25.so)
                     d87 _start (/usr/lib/ld-2.25.so)

heaptrack_gui  2228 135073.388677:     611329 cycles:
                   1a3e0 strcmp (/usr/lib/ld-2.25.so)
                    82b2 _dl_map_object (/usr/lib/ld-2.25.so)
                    cda1 openaux (/usr/lib/ld-2.25.so)
                   1834f _dl_catch_error (/usr/lib/ld-2.25.so)
                    cfe2 _dl_map_object_deps (/usr/lib/ld-2.25.so)
                    3481 dl_main (/usr/lib/ld-2.25.so)
                   17387 _dl_sysdep_start (/usr/lib/ld-2.25.so)
                    4d37 _dl_start (/usr/lib/ld-2.25.so)
                     d87 _start (/usr/lib/ld-2.25.so)
~~~~~

With libdw without this patch:

~~~~~
heaptrack_gui  2228 135073.388524:     479408 cycles:
        ffffffff811749ed perf_iterate_ctx ([kernel.kallsyms])
        ffffffff81181662 perf_event_mmap ([kernel.kallsyms])
        ffffffff811cf5ed mmap_region ([kernel.kallsyms])
        ffffffff811cfe6b do_mmap ([kernel.kallsyms])
        ffffffff811b0dca vm_mmap_pgoff ([kernel.kallsyms])
        ffffffff811cdb0c sys_mmap_pgoff ([kernel.kallsyms])
        ffffffff81033acb sys_mmap ([kernel.kallsyms])
        ffffffff81631d37 entry_SYSCALL_64_fastpath ([kernel.kallsyms])

heaptrack_gui  2228 135073.388677:     611329 cycles:
~~~~~

With this patch applied, the libdw unwinder will produce the same
output as the libunwind unwinder.

Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/20170601210021.20046-1-milian.wolff@kdab.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-06-05 14:18:03 -03:00
Milian Wolff
1982ad48fc perf report: Fix off-by-one for non-activation frames
As the documentation for dwfl_frame_pc says, frames that
are no activation frames need to have their program counter
decremented by one to properly find the function of the caller.

This fixes many cases where perf report currently attributes
the cost to the next line. I.e. I have code like this:

~~~~~~~~~~~~~~~
  #include <thread>
  #include <chrono>

  using namespace std;

  int main()
  {
    this_thread::sleep_for(chrono::milliseconds(1000));
    this_thread::sleep_for(chrono::milliseconds(100));
    this_thread::sleep_for(chrono::milliseconds(10));

    return 0;
  }
~~~~~~~~~~~~~~~

Now compile and record it:

~~~~~~~~~~~~~~~
  g++ -std=c++11 -g -O2 test.cpp
  echo 1 | sudo tee /proc/sys/kernel/sched_schedstats
  perf record \
    --event sched:sched_stat_sleep \
    --event sched:sched_process_exit \
    --event sched:sched_switch --call-graph=dwarf \
    --output perf.data.raw \
    ./a.out
  echo 0 | sudo tee /proc/sys/kernel/sched_schedstats
  perf inject --sched-stat --input perf.data.raw --output perf.data
~~~~~~~~~~~~~~~

Before this patch, the report clearly shows the off-by-one issue.
Most notably, the last sleep invocation is incorrectly attributed
to the "return 0;" line:

~~~~~~~~~~~~~~~
  Overhead  Source:Line
  ........  ...........

   100.00%  core.c:0
            |
            ---__schedule core.c:0
               schedule
               do_nanosleep hrtimer.c:0
               hrtimer_nanosleep
               sys_nanosleep
               entry_SYSCALL_64_fastpath .tmp_entry_64.o:0
               __nanosleep_nocancel .:0
               std::this_thread::sleep_for<long, std::ratio<1l, 1000l> > thread:323
               |
               |--90.08%--main test.cpp:9
               |          __libc_start_main
               |          _start
               |
               |--9.01%--main test.cpp:10
               |          __libc_start_main
               |          _start
               |
                --0.91%--main test.cpp:13
                          __libc_start_main
                          _start
~~~~~~~~~~~~~~~

With this patch here applied, the issue is fixed. The report becomes
much more usable:

~~~~~~~~~~~~~~~
  Overhead  Source:Line
  ........  ...........

   100.00%  core.c:0
            |
            ---__schedule core.c:0
               schedule
               do_nanosleep hrtimer.c:0
               hrtimer_nanosleep
               sys_nanosleep
               entry_SYSCALL_64_fastpath .tmp_entry_64.o:0
               __nanosleep_nocancel .:0
               std::this_thread::sleep_for<long, std::ratio<1l, 1000l> > thread:323
               |
               |--90.08%--main test.cpp:8
               |          __libc_start_main
               |          _start
               |
               |--9.01%--main test.cpp:9
               |          __libc_start_main
               |          _start
               |
                --0.91%--main test.cpp:10
                          __libc_start_main
                          _start
~~~~~~~~~~~~~~~

Similarly it works for signal frames:

~~~~~~~~~~~~~~~
  __noinline void bar(void)
  {
    volatile long cnt = 0;

    for (cnt = 0; cnt < 100000000; cnt++);
  }

  __noinline void foo(void)
  {
    bar();
  }

  void sig_handler(int sig)
  {
    foo();
  }

  int main(void)
  {
    signal(SIGUSR1, sig_handler);
    raise(SIGUSR1);

    foo();
    return 0;
  }
~~~~~~~~~~~~~~~~

Before, the report wrongly points to `signal.c:29` after raise():

~~~~~~~~~~~~~~~~
  $ perf report --stdio --no-children -g srcline -s srcline
  ...
   100.00%  signal.c:11
            |
            ---bar signal.c:11
               |
               |--50.49%--main signal.c:29
               |          __libc_start_main
               |          _start
               |
                --49.51%--0x33a8f
                          raise .:0
                          main signal.c:29
                          __libc_start_main
                          _start
~~~~~~~~~~~~~~~~

With this patch in, the issue is fixed and we instead get:

~~~~~~~~~~~~~~~~
   100.00%  signal   signal            [.] bar
            |
            ---bar signal.c:11
               |
               |--50.49%--main signal.c:29
               |          __libc_start_main
               |          _start
               |
                --49.51%--0x33a8f
                          raise .:0
                          main signal.c:27
                          __libc_start_main
                          _start
~~~~~~~~~~~~~~~~

Note how this patch fixes this issue for both unwinding methods, i.e.
both dwfl and libunwind. The former case is straight-forward thanks
to dwfl_frame_pc(). For libunwind, we replace the functionality via
unw_is_signal_frame() for any but the very first frame.

Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Yao Jin <yao.jin@linux.intel.com>
Cc: kernel-team@lge.com
Link: http://lkml.kernel.org/r/20170524062129.32529-4-namhyung@kernel.org
Signed-off-by: Ingo Molnar <mingo@kernel.org>
2017-05-24 08:41:48 +02:00
Arnaldo Carvalho de Melo
9a3993d408 perf tools: Move path related functions to util/path.h
Disentangling util.h header mess a bit more.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-aj6je8ly377i4upedmjzdsq6@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19 13:01:53 -03:00
Milian Wolff
6754075915 perf unwind: Use addr_location::addr instead of ip for entries
This fixes the srcline translation for call chains of user space
applications.

Before we got:

    perf report --stdio --no-children -s sym,srcline -g address
     8.92%  [.] main                                 mandelbrot.h:41
            |
            |--3.70%--main +8390240
            |          __libc_start_main +139950056726769
            |          _start +8388650
            |
            |--2.74%--main +8390189
            |
             --2.08%--main +8390296
                       __libc_start_main +139950056726769
                       _start +8388650

     7.59%  [.] main                                 complex:1326
            |
            |--4.79%--main +8390203
            |          __libc_start_main +139950056726769
            |          _start +8388650
            |
             --2.80%--main +8390219

     7.12%  [.] __muldc3                             libgcc2.c:1945
            |
            |--3.76%--__muldc3 +139950060519490
            |          main +8390224
            |          __libc_start_main +139950056726769
            |          _start +8388650
            |
             --3.32%--__muldc3 +139950060519512
                       main +8390224

With this patch applied, we instead get:

    perf report --stdio --no-children -s sym,srcline -g address
     8.92%  [.] main                                 mandelbrot.h:41
            |
            |--3.70%--main mandelbrot.h:41
            |          __libc_start_main +241
            |          _start +4194346
            |
            |--2.74%--main mandelbrot.h:41
            |
             --2.08%--main mandelbrot.h:41
                       __libc_start_main +241
                       _start +4194346

     7.59%  [.] main                                 complex:1326
            |
            |--4.79%--main complex:1326
            |          __libc_start_main +241
            |          _start +4194346
            |
             --2.80%--main complex:1326

     7.12%  [.] __muldc3                             libgcc2.c:1945
            |
            |--3.76%--__muldc3 libgcc2.c:1945
            |          main mandelbrot.h:39
            |          __libc_start_main +241
            |          _start +4194346
            |
             --3.32%--__muldc3 libgcc2.c:1945
                       main mandelbrot.h:39

Suggested-and-Acked-by: Namhyung Kim <namhyung@kernel.org>
Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
LPU-Reference: 20160816153926.11288-1-milian.wolff@kdab.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-08-16 15:23:29 -03:00
Jiri Olsa
0ba98149f8 perf libdw: Check for mmaps also in MAP__VARIABLE tree
We've seen cases (softice) where DWARF unwinder went through non
executable mmaps, which we need to lookup in MAP__VARIABLE tree.

Reported-and-Tested-by: Noel Grandin <noelgrandin@gmail.com>
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1452158050-28061-6-git-send-email-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-01-08 14:16:57 -03:00
Jiri Olsa
8bd508b001 perf callchain: Add order support for libdw DWARF unwinder
As reported by Milian, currently for DWARF unwind (both libdw and
libunwind) we display callchain in callee order only.

Adding the support to follow callchain order setup to libdw DWARF
unwinder, so we could get following output for report:

  $ perf record --call-graph dwarf ls
  ...

  $ perf report --no-children --stdio

    21.12%  ls       libc-2.21.so      [.] __strcoll_l
                 |
                 ---__strcoll_l
                    mpsort_with_tmp
                    mpsort_with_tmp
                    mpsort_with_tmp
                    sort_files
                    main
                    __libc_start_main
                    _start

  $ perf report --stdio --no-children -g caller

    21.12%  ls       libc-2.21.so      [.] __strcoll_l
                 |
                 ---_start
                    __libc_start_main
                    main
                    sort_files
                    mpsort_with_tmp
                    mpsort_with_tmp
                    mpsort_with_tmp
                    __strcoll_l

Reported-and-Tested-by: Milian Wolff <milian.wolff@kdab.com>
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Wang Nan <wangnan0@huawei.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jan Kratochvil <jkratoch@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20151119130119.GA26617@krava.brq.redhat.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-11-23 18:31:13 -03:00
Arnaldo Carvalho de Melo
dd8c17a5fe perf callchains: Use thread->mg->machine
The unwind__get_entries() already receives the thread parameter, from where it can
obtain the matching machine structure, shorten the signature.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Don Zickus <dzickus@redhat.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jean Pihet <jean.pihet@linaro.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-isjc6bm8mv4612mhi6af64go@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2014-10-29 10:32:46 -02:00
Arnaldo Carvalho de Melo
bb871a9c8d perf tools: A thread's machine can be found via thread->mg->machine
So stop passing both machine and thread to several thread methods,
reducing function signature length.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Don Zickus <dzickus@redhat.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jean Pihet <jean.pihet@linaro.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-ckcy19dcp1jfkmdihdjcqdn1@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2014-10-29 10:32:46 -02:00
Jiri Olsa
84f5d36f48 perf tools: Move pr_* debug macros into debug object
Moving pr_* debug macros to have it with in same object as debug
variables, becase we will change them to use verbose variable in next
patch.

Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Cc: Corey Ashford <cjashfor@linux.vnet.ibm.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1405374411-29012-3-git-send-email-jolsa@kernel.org
[ Add missing debug.h include in python scripting glue and in the libdw unwind lib ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2014-07-17 12:58:39 -03:00
Borislav Petkov
d944c4eebc tools: Consolidate types.h
Combine all definitions into a common tools/include/linux/types.h and
kill the wild growth elsewhere. Move DECLARE_BITMAP to its proper
bitmap.h header.

Signed-off-by: Borislav Petkov <bp@suse.de>
Acked-by: Rusty Russell <rusty@rustcorp.com.au>
Link: http://lkml.kernel.org/n/tip-azczs7qcv6h9xek9od10hiv2@git.kernel.org
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
2014-05-01 21:22:39 +02:00
Jiri Olsa
5ea8415407 perf tools: Add libdw DWARF post unwind support
Adding libdw DWARF post unwind support, which is part of
elfutils-devel/libdw-dev package from version 0.158.

The new code is contained in unwin-libdw.c object, and implements
unwind__get_entries unwind interface function.

New Makefile variable NO_LIBDW_DWARF_UNWIND was added to control its
compilation, and is marked as disabled now.  It's factored with the rest
of the Makefile unwind build code in the next patch.

Arch specific code was added for x86.

Signed-off-by: Jiri Olsa <jolsa@redhat.com>
Cc: Corey Ashford <cjashfor@linux.vnet.ibm.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jean Pihet <jean.pihet@linaro.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1392825179-5228-5-git-send-email-jolsa@redhat.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2014-02-24 09:29:36 -03:00