Re: PROBLEM: The --call-graph=fp data does do not agree with the --call-graph=dwarf results

[Jiri Olsa <olsajiri@gmail.com>]

On Tue, Aug 30, 2022 at 10:21:28AM -0400, William Cohen wrote:
> With a perf Fedora 36 perf-tools-5.18.13-200.fc36 I was examining
> where perf-report was spending its time when generating its report and
> found there was an efficiency issue in Fedora 36's binutils-2.37.  The
> efficient issue been addressed in Fedora rawhide and will be
> backported to Fedora 36
> (https://bugzilla.redhat.com/show_bug.cgi?id=2120752).  This was

nice :)

> initially discovered when processing perf.data files created with
> --call-graph=dwarf.  The output of the perf-report call-graph for
> dwarf information notes inlined functions in the report. The excessive
> time spent in binutils bfd's lookup_func_by_offset was caused by perf-report
> building up a red-black tree mapping IP addresses to functions
> including inlined functions.
> 
> I ran a similar experiment with --call-graph=fp to see if it triggered
> the same execessive overhead in building the red-black tree for
> inlined functions.  It did not.  The resulting output of the perf-report
> for --call-graph=fp does not include information about inlined functions.
> 
> I have a small reproducer in the attached perf_inlined.tar.gz that
> demonstrates the difference between the two methods of storing
> call-chain information. Compile and collect data with:
> 
> tar xvfz perf_inlined.tar.gz
> cd perf_inlined
> make all
> perf report --input=perf_fp.data > fp.log
> perf report --input=perf_dwarf.data > dwarf.log
> 
> The dwarf.log has the expected call structure for main:
> 
> 
>                main
>                |          
>                 --85.72%--fill_array (inlined)
>                           |          
>                           |--78.09%--rand
>                           |          |          
>                           |           --75.10%--__random
>                           |                     |          
>                           |                      --9.14%--__random_r
>                           |          
>                           |--1.58%--compute_sqrt (inlined)
>                           |          
>                            --1.32%--_init
> 
> The fp.log looks odd given program:

what's odd about that? perhaps the confusion is that you are
in children mode? you could try --no-children

> 
>    99.99%     0.00%  time_waste  libc.so.6             [.] __libc_start_call_main
>             |
>             ---__libc_start_call_main
>                |          
>                |--66.07%--__random
>                |          
>                |--21.28%--main
>                |          
>                |--8.42%--__random_r
>                |          
>                |--2.91%--rand
>                |          
>                 --1.31%--_init
> 
> Given how common that functions are inlined in optimized code it seems
> like perf-report of --call-graph=fp should include information about
> time spent in inlined functions.

hum, so 'fp' call graph is tracersing frame pointers which I would
not expect for inlined functions

jirka