Re: [Libunwind-devel] Backtrace performance on x86-64 based on Dwarf info

[Milian Wolff]

On Monday 02 June 2014 13:38:21 Arun Sharma wrote:
> That's expected. For eg these unit tests do it too:
> 
> ./tests/Ltest-bt v
> ./tests/Ltest-trace v

OK. Could we get this patch applied to master then? But I just saw that it 
fails the Ltest-trace v test in a strange way:

:~/projects/libunwind/tests|master *=$ ./Ltest-trace v
Normal backtrace:
        normal trace:
         #0   ip=0x400f08
         #1   ip=0x400bf9
         #2   ip=0x7f93753fa000
         #3   ip=0x400e04

        via backtrace():
         #0   ip=0x400f95
         #1   ip=0x400bf8
         #2   ip=0x7f93753f9fff
         #3   ip=0x400e03

        via unw_backtrace():
         #0   ip=0x400ffa
         #1   ip=0x400bf8
         #2   ip=0x7f93753f9fff
         #3   ip=0x400e03
FAILURE: unw_step() loop and unw_backtrace() depths differ: 4 vs. 4
FAILURE: unw_step() loop and backtrace() depths differ: 4 vs. 4

Backtrace across signal handler:
sighandler: got signal 15, sp=0x7fff98a4ca6c @ 7f937540e097
        normal trace:
         #0   ip=0x400f08
         #1   ip=0x4012d7
         #2   ip=0x7f937540ddf0
         #3   ip=0x7f937540e097
         #4   ip=0x400c50
         #5   ip=0x7f93753fa000
         #6   ip=0x400e04

        via backtrace():
         #0   ip=0x400f95
         #1   ip=0x4012d6
         #2   ip=0x7f937540ddef
         #3   ip=0x7f937540e097
         #4   ip=0x400c4f
         #5   ip=0x7f93753f9fff
         #6   ip=0x400e03

        via unw_backtrace():
         #0   ip=0x400ffa
         #1   ip=0x4012d6
         #2   ip=0x7f937540ddef
         #3   ip=0x7f937540e097
         #4   ip=0x400c4f
         #5   ip=0x7f93753f9fff
         #6   ip=0x400e03
FAILURE: unw_step() loop and unw_backtrace() depths differ: 7 vs. 7
FAILURE: unw_step() loop and backtrace() depths differ: 7 vs. 7

Backtrace across signal handler on alternate stack:
sighandler: got signal 15, sp=0x7f9375902bec @ 7f937540e097
        normal trace:
         #0   ip=0x400f08
         #1   ip=0x4012d7
         #2   ip=0x7f937540ddf0
         #3   ip=0x7f937540e097
         #4   ip=0x400ce1
         #5   ip=0x7f93753fa000
         #6   ip=0x400e04

        via backtrace():
         #0   ip=0x400f95
         #1   ip=0x4012d6
         #2   ip=0x7f937540ddef
         #3   ip=0x7f937540e097
         #4   ip=0x400ce0
         #5   ip=0x7f93753f9fff
         #6   ip=0x400e03

        via unw_backtrace():
         #0   ip=0x400ffa
         #1   ip=0x4012d6
         #2   ip=0x7f937540ddef
         #3   ip=0x7f937540e097
         #4   ip=0x400ce0
         #5   ip=0x7f93753f9fff
         #6   ip=0x400e03
FAILURE: unw_step() loop and unw_backtrace() depths differ: 7 vs. 7
FAILURE: unw_step() loop and backtrace() depths differ: 7 vs. 7
FAILURE: detected 6 errors

To me that does not look like a failure :)

Furthermore, while this patch fixes the unw_backtrace usage for me, shouldn't 
the same be done for the unw_step case? There, the last call to unw_step still 
triggers the slow-path which I mentioned in my original thread. How could we 
fix this? Where is the analogous check for last frame based on rbp in the 
code? And, if we'd fix it there, wouldn't then the patch to Gtrace.c be 
obsolete, as then we'd get ret == 0 already, no?

> On Mon, Jun 2, 2014 at 11:41 AM, Milian Wolff <address@hidden> wrote:
> > On Monday 02 June 2014 10:01:02 Arun Sharma wrote:
> >> On Mon, Jun 2, 2014 at 9:40 AM, Milian Wolff <address@hidden> wrote:
> >> > So... what now?
> >> >
> >> >_ULx86_64_tdep_trace: frame va 400d28 type 0 last 0 cfa rsp+0 rbp @
> >> >cfa-1
> >> >rsp @ cfa-1
> >> >
> >> >_ULx86_64_tdep_trace: new cfa 0x7fffb98a3820 rip 0x400d28 rsp
> >> >0x7fffb98a3820 rbp 0x0
> >> 
> >> It looks like the fast unwind path found RBP=0, but f->last_frame is
> >> computed based on the return value of unw_step().
> >> Does this improve the situation?
> >> 
> >> --- a/src/x86_64/Gtrace.c
> >> +++ b/src/x86_64/Gtrace.c
> >> @@ -254,7 +254,7 @@ trace_init_addr (unw_tdep_frame_t *f,
> >> 
> >>       common for the outermost frame (CRT stuff) on many systems.
> >>       This avoids failing trace in very common circumstances; failing
> >>       to unw_step() loop wouldn't produce any better result. */
> >> 
> >> -  if (ret == 0)
> >> +  if ((ret == 0) || !rbp)
> >> 
> >>      f->last_frame = -1;
> > 
> > Yes, that helps indeed. But I still have the frame above __libc_start_main
> > in my backtraces. Is that "OK"?
> > 
> > --
> > Milian Wolff
> > address@hidden
> > http://milianw.de

-- 
Milian Wolff
address@hidden
http://milianw.de