On Sunday 01 June 2014 10:36:09 Arun Sharma wrote:
> On Fri, May 30, 2014 at 3:42 PM, Milian Wolff <[email protected]> wrote:
> > So... yes? But what does that have to do with the 0-IP I encounter at
the
> > end of a backtrace?
>
> Only RBP=0 can indicate the end of call chain. We used to treat RIP=0
> as an indication to stop the unwinding, but it broke a bunch of legit
> use cases.
>
> d04dc94 dwarf: ip == 0 should't terminate unwind
>
> The problem here may be that various caches in the fast path (Gtrace.c
> and src/dwarf/Gparser.c:rs_new()) ignore the RIP==0 case. This is
> exacerbated by the calls to block signals.
>
> We do have a --enable_block_signals config option. More info about it
here:
>
> 9aa0d6d Allow caller to block signals.
> 84d4150 Allow caller to block signals.
>
> If you can guarantee that signals are blocked on entry to libunwind,
> we can optimize away the sigprocmask calls.
>
> A longer term solution may be to teach the libunwind caches about
> negative caching in general or the RIP==0 case in particular.
Hello Arun,
thanks for the input. The negative caching sounds like a good idea to me.
But somehow I think there is something else going on as well:
I tried out the supposedly fast unw_backtrace() and it seems to have the
same issue. At the end of every backtrace it finds some garbage it is not
expecting and then triggers a fallback to the slow-path based on
unw_step. Debug output contains lines like this for every call to
unw_backtrace:
...
>_ULx86_64_tdep_trace: depth 9 cfa 0x7fffb98a3820 rip 0x400d28 rsp
0x7fffb98a3820 rbp 0x0
>trace_lookup: updating slot 1832 after 0 steps, replacing 0x0
>_ULx86_64_step: (cursor=0x7fffb98a29f0, ip=0x0000000000400d29,
cfa=0x00007fffb98a3820)
>_ULx86_64_dwarf_find_proc_info: looking for IP=0x400d28
>_ULx86_64_dwarf_search_unwind_table: e->fde_offset = ffffffffffffff9c,
segbase = 4013fc, debug_frame_base = 0, fde_addr = 401398
>_ULx86_64_dwarf_extract_proc_info_from_fde: FDE @ 0x401398
>_ULx86_64_fetch_frame: fetch frame ip=0x400d29
cfa=0x7fffb98a3820 format=0
>_ULx86_64_cache_frame: cache frame ip=0x400d29
cfa=0x7fffb98a3820 format=0
>_ULx86_64_reuse_frame: reuse frame ip=0x400d29
cfa=0x7fffb98a3820 format=0 addr=0x0 offset=+0
>_ULx86_64_stash_frame: ip=0x0 cfa=0x7fffb98a3828 type 0 cfa
[where=3 val=7] cfaoff=8 ra=0x0 rbp [where=1 val=0 @0x7fffb98a26b8]
rsp [where=1 val=0 @0x7fffb98a26e0]
>_ULx86_64_stash_frame: unusual frame
>_ULx86_64_step: returning 1
>trace_init_addr: frame va 400d28 type 0 last 0 cfa rsp+0 rbp @ cfa-1
rsp @ cfa-1
>_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
...
>trace_init_addr: frame va 400e59 type -2 last 0 cfa rbp+16 rbp @
cfa-16 rsp @ cfa-1
>_ULx86_64_tdep_trace: frame va 400e59 type -2 last 0 cfa rbp+16 rbp
@ cfa-16 rsp @ cfa-1
>_ULx86_64_tdep_trace: new cfa 0x7fffb98a3760 rip 0x7f0b689a1000
rsp 0x7fffb98a3760 rbp 0x4010d0
>_ULx86_64_tdep_trace: depth 6 cfa 0x7fffb98a3760 rip 0x7f0b689a0fff
rsp 0x7fffb98a3760 rbp 0x4010d0
>trace_lookup: found address after 0 steps
>_ULx86_64_tdep_trace: frame va 7f0b689a0fff type -2 last 0 cfa
rsp+192 rbp @ cfa-40 rsp @ cfa-1
>_ULx86_64_tdep_trace: new cfa 0x7fffb98a3820 rip 0x400d29 rsp
0x7fffb98a3820 rbp 0x0
>_ULx86_64_tdep_trace: depth 7 cfa 0x7fffb98a3820 rip 0x400d28 rsp
0x7fffb98a3820 rbp 0x0
>trace_lookup: found address after 0 steps
>_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
>_ULx86_64_tdep_trace: returning -5, depth 7
>_ULx86_64_init_local: (cursor=0x7fffb98a2e20)
>_ULx86_64_step: (cursor=0x7fffb98a2e20, ip=0x00007f0b6990dc68,
cfa=0x00007fffb98a2660)
>_ULx86_64_reuse_frame: reuse frame ip=0x7f0b6990dc68
cfa=0x7fffb98a2660 format=0 addr=0x0 offset=+0
>_ULx86_64_step: returning 1
...
>_ULx86_64_step: (cursor=0x7fffb98a2e20, ip=0x0000000000400d29,
cfa=0x00007fffb98a3820)
>_ULx86_64_reuse_frame: reuse frame ip=0x400d29
cfa=0x7fffb98a3820 format=0 addr=0x0 offset=+0
>_ULx86_64_step: returning 1
>_ULx86_64_step: (cursor=0x7fffb98a2e20, ip=0x0000000000000000,
cfa=0x00007fffb98a3828)
>_ULx86_64_dwarf_find_proc_info: looking for IP=0xffffffffffffffff
>_ULx86_64_dwarf_find_proc_info: IP=0xffffffffffffffff not found
>_ULx86_64_step: dwarf_step() failed (ret=-10), trying frame-chain
>_ULx86_64_step: NULL %rbp loc, returning 0
Looking at the backtrace for the return values I go
...
0x400fff main in /home/milian/projects/kde4/mallocinfo/tests/test.cpp:66
/home/milian/projects/.build/kde4/mallocinfo/tests/test_cpp
0x7f0b689a1000 __libc_start_main /usr/lib/libc.so.6
0x400d29 ? /home/milian/projects/.build/kde4/mallocinfo/tests/test_cpp
0x0 <unknown module>
...
So I wonder what is going on here. Considering that the fast
unw_backtrace always fails for me, is there maybe something going on on
my machine / platform / setup which is currently not supported by
libunwind? Is there a bug somewhere?
--
Milian Wolff
[email protected]
http://milianw.de
_______________________________________________
Libunwind-devel mailing list
[email protected]
https://lists.nongnu.org/mailman/listinfo/libunwind-devel
