Re: usability issues with inlining and backtraces

[Milian Wolff <milian.wolff@kdab.com>]

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

On Monday, May 23, 2016 7:59:54 AM CEST Andi Kleen wrote:
> Milian Wolff <milian.wolff@kdab.com> writes:
> > Here, the cost of inlined functions (random.tcc:3332,random.h:143) is
> > attributed to the main function. This is of course correct, but very
> > unhelpful to me as a programmer. I'm much more interested in the line
> > inside test.cpp which triggered the call to random.tcc:3332 etc. Is there
> > a way to get that data? Note how you can a way better backtrace when
> > using GDB on the same
> > binary as above:
>
> Yes this works using --call-graph ...,address
> 
> If you use srcfile it can resolve inlines. it is currently not supported
> for other backtraces, but yes expanding them in the normal history
> would be useful.

Can you expand on this part a bit please? It's the first time I realize that I 
can add a sort key to `--call-graph`, so at the very least this shows that the 
defaults are bad.

For the example I'm now trying this:

    $ perf report -g graph,address -s sym,srcline --no-children --stdio

# Overhead  Symbol                       Source:Line       
# ........  ...........................  ..................
#
    21.82%  [.] main                     random.tcc:3332
            |          
            |--3.84%--main +8388740
            |          __libc_start_main +140389813309681
            |          _start +8388649
            | ...
     6.29%  [.] __hypot_finite           __hypot_finite+152
            |
            ---hypot +140389819301908
               main +8388987
               __libc_start_main +140389813309681
               _start +8388649

-> much better, but still unusable backtraces. And my `perf report` only 
allows this:

    sort_key:       call graph sort key (function|address)

So we need to add support for "|srcline" here as well?

> > On one hand, we have the same issue as above, namely inlined functions
> > being attributed directly to the parent function. See how the backtrace
> > shows main calling hypot? Look at the source, I'm not calling hypot
> > anywhere - it's std::norm calling it internally eventually. And GDB does
> > know about that and can give me a proper backtrace.
> 
> Use srcfile then.

See above, can you please extend this answer a bit? How would you use srcfile, 
and where, to get the full backtrace? Is that maybe a patch that is not yet 
included in acme's perf/core branch?

> > But, differently to above, the major gripe I have with this output is
> > exemplified by this part:
> > 
> > ~~~~~~~~~
> > 
> >      3.63%  [.] __hypot_finite         __hypot_finite+257
> >      
> >             ---hypot
> >             
> >                main
> >                __libc_start_main
> >                _start
> > 
> > ~~~~~~~~~
> > 
> > I added `srcline` to the report, but the backtrace still only contains the
> > symbol name. I hope, that we can simply honor srcline there as well, to at
> 
> > least print something like this instead:
> --call-graph ....,address
> 
> (or --branch-history)


Both produce output like I've shown above, i.e. they always put down

  <symbol> +<offset>

insetead of using the much more useable

  <symbol> <file>:<line>

format. What am I missing?

> > ########## symbol cost aggregation
> > 
> > Once we have that implemented, can we maybe account for the following: I
> > told `perf report` to aggregate by symbol first, then srcline, i.e. `-s
> > sym,srcline`. But the report seems to aggregate by `srcline`, because I
> > see some symbols (__hypot_finite) multiple times, for different code
> > points. Can we merge those and start the backtrace then at the different
> > code points?
> > Something like this would be my desirable output:
>
> perf sorts by address, but the compiler can generate the same symbol
> in multiple versions or in may inlines instances. That's probably
> more work to fix.
> 
> > As such, I propose a "simplified" `perf annotate` output, which gets
> > closer to what you'll see in other profilers, e.g. VTune or also
> > Microsoft Visual studio's sampling profilers: Use the source files and
> > annotate those with inclusive cost. Only show the cost of individual
> > binary instructions (status quo) when explicitly asked. I.e. I want the
> > output to look something like that
> > (I made up the actual percentages):
>
> Sounds like the fallacy of abstracted performance analysis.

Can you please elaborate that some more as well? For me, as a user-space 
application developer, getting an aggregated inclusive cost for the source 
code I actually write is extremely useful. Of course, when it's not directly 
clear from that view why something is slow I still need to dig deeper and get 
to the current in-depth assembly view. But why is having a simplified overview 
a fallacy? Why is this abstracted performance analysis?

Thanks a lot for your input!
-- 
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

[-- Attachment #2: smime.p7s --]
[-- Type: application/pkcs7-signature, Size: 5903 bytes --]