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

[Milian Wolff]

On Mittwoch, 17. Mai 2017 07:12:21 CEST Namhyung Kim wrote:
> On Tue, May 16, 2017 at 06:26:47PM +0200, Milian Wolff wrote:
> > On Dienstag, 16. Mai 2017 18:17:26 CEST Milian Wolff wrote:
> > > On Dienstag, 16. Mai 2017 16:38:29 CEST Namhyung Kim wrote:
> > > > On Tue, May 16, 2017 at 10:59:51AM +0200, 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.
> > > > > 
> > > > > 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;
> > > > >   
> > > > >   }
> > > > > 
> > > > > ~~~~~~~~~~~~~~~
> > > > 
> > > > It'd be nice if the test program has a signal frame for verification.
> > > 
> > > I have pretty much zero experience about signals. Would it be enough to
> > > add
> > > a signal handler for, say, SIGUSR1 to my test application and then
> > > trigger
> > > a sleep when that signal is delivered? If that should be enough, I'll
> > > write
> > > and test it out.
> > 
> > ~~~~~~~~~~~~~~~
> > #include <thread>
> > #include <chrono>
> > #include <signal.h>
> > 
> > using namespace std;
> > 
> > volatile bool run_loop = true;
> > 
> > void my_handler(int signum)
> > {
> > 
> >     this_thread::sleep_for(chrono::milliseconds(1000));
> >     this_thread::sleep_for(chrono::milliseconds(100));
> >     this_thread::sleep_for(chrono::milliseconds(10));
> >     run_loop = false;
> > 
> > }
> > 
> > int main()
> > {
> > 
> >     signal(SIGUSR1, my_handler);
> >     
> >     while (run_loop) {}
> >     
> >     return 0;
> > 
> > }
> > ~~~~~~~~~~~~~~~
> > 
> > This does not properly unwind neither before nor after this patch. I only
> > ever> 
> > get:
> >    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
> > 
> > So... should this work? Please tell me how to test this properly.
> 
> How did you send the SIGUSR1 to the process?
> 
> Anyway it does nothing to do with inlining, right?  I just wrote a
> test code below to burn a cpu with or without a signal frame.
> 
>   $ nl -ba frame-addr.c
>      1	#include <stdio.h>
>      2	#include <stdlib.h>
>      3	#include <signal.h>
>      4
>      5	#define __noinline  __attribute__((noinline))
>      6
>      7	__noinline void bar(void)
>      8	{
>      9	  volatile long cnt = 0;
>     10
>     11	  for (cnt = 0; cnt < 100000000; cnt++);
>     12	}
>     13
>     14	__noinline void foo(void)
>     15	{
>     16	  bar();
>     17	}
>     18
>     19	void sig_handler(int sig)
>     20	{
>     21	  foo();
>     22	}
>     23
>     24	int main(void)
>     25	{
>     26	  signal(SIGUSR1, sig_handler);
>     27	  raise(SIGUSR1);
>     28
>     29	  foo();
>     30	  return 0;
>     31	}
> 
>   $ gcc -O2 -g -fno-optimize-sibling-calls -o frame-addr frame-addr.c
> 
>   $ perf record --call-graph dwarf ./frame-addr
> 
>   $ perf report -q -g srcline | head -15
>       99.88%  frame-addr  frame-addr        [.] bar
> 
>               ---bar frame-addr.c:11
>                  foo frame-addr.c:16
> 
>                  |--51.12%--main frame-addr.c:29
>                  |
>                  |          __libc_start_main
>                  |          _start
> 
>                   --48.76%--sig_handler frame-addr.c:21
>                             0x33a8f
>                             raise .:0
>                             main frame-addr.c:29       <--- bad
>                             __libc_start_main
>                             _start
> 
> Note that 'raise' was called at line 27.  It seems that simply
> checking current frame fixes it.

Got it - thanks for your test case. I fixed it and will resend v3 of this 
patch shortly.

Thanks

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

Attachment: smime.p7s
Description: S/MIME cryptographic signature