Re: bfd_find_inliner_info reports different (wrong) information compared to GDB - off-by-one?

Re: bfd_find_inliner_info reports different (wrong) information compared to GDB - off-by-one?

[Mark Wielaard]

[-- Attachment #1: Type: text/plain, Size: 3656 bytes --]

Hi Milian,

On Wed, 2016-10-05 at 17:45 +0200, Milian Wolff wrote:
> I'm trying to improve Linux perf report by adding inliner information to the 
> callstacks it reports, to make the output more easily interpretable when 
> looking at complicated C++ applications.

You might want to take a look at eu-stack (src/stack.c) in elfutils
which does this too. If you are using the elfutils libraries (libdw.so).

> I have a proof of concept locally using bfd_find_inliner_info

I don't know what bfd_find_inliner_info is.
It sound like something from binutils?

> , but have 
> noticed the following seemingly broken behavior:
> 
> Input file:
> ~~~~~~~~~test.cpp~~~~~~~
> #include <cstdlib>
> #include <iostream>
> #include <complex>
> 
> int main(int argc, char** argv)
> {
>     double a = 0;
>     double b = 0;
>     if (argc > 1)
>         a = atof(argv[1]);
>     if (argc > 2)
>         b = atof(argv[2]);
>     auto c = std::complex<double>(a, b);
>     std::cout << std::abs(c) << std::endl;
> }
> ~~~~~~~~~~~~~~~~~~~~~~~~
> 
> I build it with:
> 
> ~~~~~~~~~building~~~~~~~
> $ g++ -g -O2 -o test test.cpp
> ~~~~~~~~~~~~~~~~~~~~~~~~
> 
> Then I get a "good" backtrace using GDB:
> 
> ~~~~~~~~~gdb~~~~~~~~~~~~
> $ gdb ./test
> (gdb) break hypot
> Function "hypot" not defined.
> Make breakpoint pending on future shared library load? (y or [n]) y
> Breakpoint 1 (hypot) pending.
> (gdb) run
> Starting program: /tmp/test 
> 
> Breakpoint 1, 0x00007ffff776e910 in hypot () from /usr/lib/libm.so.6
> (gdb) bt
> #0  0x00007ffff776e910 in hypot () from /usr/lib/libm.so.6
> #1  0x00000000004007f4 in std::__complex_abs (__z=<optimized out>) at /usr/
> include/c++/6.2.1/complex:589
> #2  std::abs<double> (__z=<synthetic pointer>) at /usr/include/c++/6.2.1/
> complex:597
> #3  main (argc=<optimized out>, argv=<optimized out>) at test.cpp:14
> ~~~~~~~~~~~~~~~~~~~~~~~~
> 
> Note what inliners it reports for the address 0x00000000004007f4. Let's try 
> bfd_find_inliner_info via eu-addr2line -i:
> 
> ~~~~~~~~~eu-addr2line~~~
> eu-addr2line -i -a 0x00000000004007f4 -e ./test
> 0x00000000004007f4
> /usr/include/c++/6.2.1/ostream:221
> /tmp/test.cpp:14
> ~~~~~~~~~~~~~~~~~~~~~~~~
> 
> This is wrong and seems to be off-by-one:
> 
> ~~~~~~~~~eu-addr2line~~~
> eu-addr2line -i -a 0x00000000004007f3 -e ./test
> 0x00000000004007f3
> /usr/include/c++/6.2.1/complex:589
> /usr/include/c++/6.2.1/complex:597
> /tmp/test.cpp:14
> ~~~~~~~~~~~~~~~~~~~~~~~~
> 
> Can someone with more knowledge in this area sched some light on what is going 
> on here please? Is it a bug, or is this fuzzy behavior and GDB happens to be 
> better at guessing the "right" thing?

I don't know what gdb exactly displays as address in that backtrace.
It might display the return address, in which case subtracting 1 is the
right thing to do on x86_64 (that would be an approximation of the call
address, which is what you want).

And in fact that is what eu-stack does:

(gdb) gcore test.core
Saved corefile test.core

$ eu-stack -v --core test.core --exec test
PID 32623 - core
TID 32623:
#0  0x00007ffff77f8cf0     __hypot - libm.so.6
    /usr/src/debug/glibc-2.17-c758a686/math/w_hypot.c:23
#1  0x0000000000400824 - 1 __complex_abs - test
    /usr/include/c++/4.8.2/complex:587
#2  0x0000000000400824 - 1 abs<double> - test
    /usr/include/c++/4.8.2/complex:595
#3  0x0000000000400824 - 1 main - test
    /tmp/test.cpp:14
#4  0x00007ffff721db35 - 1 __libc_start_main - libc.so.6
    ../csu/libc-start.c:274
#5  0x000000000040088f - 1 _start - test

Cheers,

Mark

Re: bfd_find_inliner_info reports different (wrong) information compared to GDB - off-by-one?

[Milian Wolff]

[-- Attachment #1: Type: text/plain, Size: 2263 bytes --]

On Mittwoch, 5. Oktober 2016 22:22:34 CEST Mark Wielaard wrote:
> Hi Milian,
> 
> On Wed, 2016-10-05 at 17:45 +0200, Milian Wolff wrote:
> > I'm trying to improve Linux perf report by adding inliner information to
> > the callstacks it reports, to make the output more easily interpretable
> > when looking at complicated C++ applications.
> 
> You might want to take a look at eu-stack (src/stack.c) in elfutils
> which does this too. If you are using the elfutils libraries (libdw.so).

<snip, and reordered>

> I don't know what gdb exactly displays as address in that backtrace.
> It might display the return address, in which case subtracting 1 is the
> right thing to do on x86_64 (that would be an approximation of the call
> address, which is what you want).
> 
> And in fact that is what eu-stack does:
> 
> (gdb) gcore test.core
> Saved corefile test.core
> 
> $ eu-stack -v --core test.core --exec test
> PID 32623 - core
> TID 32623:
> #0  0x00007ffff77f8cf0     __hypot - libm.so.6
>     /usr/src/debug/glibc-2.17-c758a686/math/w_hypot.c:23
> #1  0x0000000000400824 - 1 __complex_abs - test
>     /usr/include/c++/4.8.2/complex:587
> #2  0x0000000000400824 - 1 abs<double> - test
>     /usr/include/c++/4.8.2/complex:595
> #3  0x0000000000400824 - 1 main - test
>     /tmp/test.cpp:14
> #4  0x00007ffff721db35 - 1 __libc_start_main - libc.so.6
>     ../csu/libc-start.c:274
> #5  0x000000000040088f - 1 _start - test

Thanks, I have had a look at the sources and found the code for the adjustion:

      Dwarf_Addr pc = frames->frame[nr].pc;
      bool isactivation = frames->frame[nr].isactivation;
      Dwarf_Addr pc_adjusted = pc - (isactivation ? 0 : 1);

The isactivation information comes from dwfl_frame_pc, so that should be all I 
need to use this properly in Linux perf - thanks!

> > I have a proof of concept locally using bfd_find_inliner_info
> 
> I don't know what bfd_find_inliner_info is.
> It sound like something from binutils?

Oh, indeed - I mixed up the two. Sorry for that, and thanks a lot for still 
helping me out. I will check whether using dwfl instead of bfd for this 
purpose may be advantageous.

Cheers

-- 
Milian Wolff
mail@milianw.de
http://milianw.de

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 163 bytes --]

bfd_find_inliner_info reports different (wrong) information compared to GDB - off-by-one?

[Milian Wolff]

[-- Attachment #1: Type: text/plain, Size: 2444 bytes --]

Hello,

I'm trying to improve Linux perf report by adding inliner information to the 
callstacks it reports, to make the output more easily interpretable when 
looking at complicated C++ applications.

I have a proof of concept locally using bfd_find_inliner_info, but have 
noticed the following seemingly broken behavior:

Input file:
~~~~~~~~~test.cpp~~~~~~~
#include <cstdlib>
#include <iostream>
#include <complex>

int main(int argc, char** argv)
{
    double a = 0;
    double b = 0;
    if (argc > 1)
        a = atof(argv[1]);
    if (argc > 2)
        b = atof(argv[2]);
    auto c = std::complex<double>(a, b);
    std::cout << std::abs(c) << std::endl;
}
~~~~~~~~~~~~~~~~~~~~~~~~

I build it with:

~~~~~~~~~building~~~~~~~
$ g++ -g -O2 -o test test.cpp
~~~~~~~~~~~~~~~~~~~~~~~~

Then I get a "good" backtrace using GDB:

~~~~~~~~~gdb~~~~~~~~~~~~
$ gdb ./test
(gdb) break hypot
Function "hypot" not defined.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (hypot) pending.
(gdb) run
Starting program: /tmp/test 

Breakpoint 1, 0x00007ffff776e910 in hypot () from /usr/lib/libm.so.6
(gdb) bt
#0  0x00007ffff776e910 in hypot () from /usr/lib/libm.so.6
#1  0x00000000004007f4 in std::__complex_abs (__z=<optimized out>) at /usr/
include/c++/6.2.1/complex:589
#2  std::abs<double> (__z=<synthetic pointer>) at /usr/include/c++/6.2.1/
complex:597
#3  main (argc=<optimized out>, argv=<optimized out>) at test.cpp:14
~~~~~~~~~~~~~~~~~~~~~~~~

Note what inliners it reports for the address 0x00000000004007f4. Let's try 
bfd_find_inliner_info via eu-addr2line -i:

~~~~~~~~~eu-addr2line~~~
eu-addr2line -i -a 0x00000000004007f4 -e ./test
0x00000000004007f4
/usr/include/c++/6.2.1/ostream:221
/tmp/test.cpp:14
~~~~~~~~~~~~~~~~~~~~~~~~

This is wrong and seems to be off-by-one:

~~~~~~~~~eu-addr2line~~~
eu-addr2line -i -a 0x00000000004007f3 -e ./test
0x00000000004007f3
/usr/include/c++/6.2.1/complex:589
/usr/include/c++/6.2.1/complex:597
/tmp/test.cpp:14
~~~~~~~~~~~~~~~~~~~~~~~~

Can someone with more knowledge in this area sched some light on what is going 
on here please? Is it a bug, or is this fuzzy behavior and GDB happens to be 
better at guessing the "right" thing?

Some system info:
linux 4.7.2-1-ARCH
eu-addr2line 0.167
g++ 6.2.1
gdb 7.11.1

Thanks

-- 
Milian Wolff
mail@milianw.de
http://milianw.de