Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1641790 > unrolled thread

[PATCH] perf report: fix off-by-one for non-activation frames

Started byMilian Wolff <milian.wolff@kdab.com>
First post2017-05-15 17:10 +0200
Last post2017-05-16 11:10 +0200
Articles 4 — 2 participants

Back to article view | Back to linux.kernel


Contents

  [PATCH] perf report: fix off-by-one for non-activation frames Milian Wolff <milian.wolff@kdab.com> - 2017-05-15 17:10 +0200
    Re: [PATCH] perf report: fix off-by-one for non-activation frames Milian Wolff <milian.wolff@kdab.com> - 2017-05-15 17:20 +0200
      Re: [PATCH] perf report: fix off-by-one for non-activation frames Namhyung Kim <namhyung@kernel.org> - 2017-05-16 04:00 +0200
        Re: [PATCH] perf report: fix off-by-one for non-activation frames Milian Wolff <milian.wolff@kdab.com> - 2017-05-16 11:10 +0200

#1641790 — [PATCH] perf report: fix off-by-one for non-activation frames

FromMilian Wolff <milian.wolff@kdab.com>
Date2017-05-15 17:10 +0200
Subject[PATCH] perf report: fix off-by-one for non-activation frames
Message-ID<tHpNg-1m3-21@gated-at.bofh.it>
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
~~~~~~~~~~~~~~~

When compiling perf using libdwfl for unwinding instead of libunwind
and having 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
~~~~~~~~~~~~~~~

Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Yao Jin <yao.jin@linux.intel.com>
Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
---
 tools/perf/util/unwind-libdw.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c
index f90e11a555b2..943a06291587 100644
--- a/tools/perf/util/unwind-libdw.c
+++ b/tools/perf/util/unwind-libdw.c
@@ -168,12 +168,16 @@ frame_callback(Dwfl_Frame *state, void *arg)
 {
 	struct unwind_info *ui = arg;
 	Dwarf_Addr pc;
+	bool isactivation;
 
-	if (!dwfl_frame_pc(state, &pc, NULL)) {
+	if (!dwfl_frame_pc(state, &pc, &isactivation)) {
 		pr_err("%s", dwfl_errmsg(-1));
 		return DWARF_CB_ABORT;
 	}
 
+	if (!isactivation)
+		--pc;
+
 	return entry(pc, ui) || !(--ui->max_stack) ?
 	       DWARF_CB_ABORT : DWARF_CB_OK;
 }
-- 
2.13.0

[toc] | [next] | [standalone]


#1641803

FromMilian Wolff <milian.wolff@kdab.com>
Date2017-05-15 17:20 +0200
Message-ID<tHpWW-1pB-29@gated-at.bofh.it>
In reply to#1641790

[Multipart message — attachments visible in raw view] — view raw

On Monday, May 15, 2017 5:04:44 PM CEST Milian Wolff wrote:
> 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.

Note that this leaves the perf build against libunwind in the current, broken 
state. I do not know how to detect the activation property there. Does anyone 
else? See elfutils source code for what it is doing:

https://sourceware.org/git/?p=elfutils.git;a=blob;f=libdwfl/
dwfl_frame_pc.c;h=296c815b9c73f42d79ac1778d2a0c420b89ee4eb;hb=HEAD

Cheers
-- 
Milian Wolff | milian.wolff@kdab.com | Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts

[toc] | [prev] | [next] | [standalone]


#1642182

FromNamhyung Kim <namhyung@kernel.org>
Date2017-05-16 04:00 +0200
Message-ID<tHzWh-7wv-5@gated-at.bofh.it>
In reply to#1641803
On Mon, May 15, 2017 at 05:13:06PM +0200, Milian Wolff wrote:
> On Monday, May 15, 2017 5:04:44 PM CEST Milian Wolff wrote:
> > 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.
> 
> Note that this leaves the perf build against libunwind in the current, broken 
> state. I do not know how to detect the activation property there. Does anyone 
> else? See elfutils source code for what it is doing:
> 
> https://sourceware.org/git/?p=elfutils.git;a=blob;f=libdwfl/
> dwfl_frame_pc.c;h=296c815b9c73f42d79ac1778d2a0c420b89ee4eb;hb=HEAD

It seems that you can use unw_is_signal_frame().

Thanks,
Namhyung

[toc] | [prev] | [next] | [standalone]


#1642324

FromMilian Wolff <milian.wolff@kdab.com>
Date2017-05-16 11:10 +0200
Message-ID<tHGEp-3GY-7@gated-at.bofh.it>
In reply to#1642182

[Multipart message — attachments visible in raw view] — view raw

On Dienstag, 16. Mai 2017 03:57:53 CEST Namhyung Kim wrote:
> On Mon, May 15, 2017 at 05:13:06PM +0200, Milian Wolff wrote:
> > On Monday, May 15, 2017 5:04:44 PM CEST Milian Wolff wrote:
> > > 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.
> > 
> > Note that this leaves the perf build against libunwind in the current,
> > broken state. I do not know how to detect the activation property there.
> > Does anyone else? See elfutils source code for what it is doing:
> > 
> > https://sourceware.org/git/?p=elfutils.git;a=blob;f=libdwfl/
> > dwfl_frame_pc.c;h=296c815b9c73f42d79ac1778d2a0c420b89ee4eb;hb=HEAD
> 
> It seems that you can use unw_is_signal_frame().

Thank you! The v2 patch I just sent now uses that and it seems to work 
reliably in my quick test.

Cheers

-- 
Milian Wolff | milian.wolff@kdab.com | Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web