Noted slowness in profile loading with binutils 2.37

Noted slowness in profile loading with binutils 2.37

[Alexander Lindsay]

Hi all,

I recently experienced a slow-down in profile loading by the tool pprof,
and I believe I've boiled it down to changing from previous versions of
binutils to binutils version 2.37. Timings of profile loading are
documented on the pprof ticket I originally opened here:
https://github.com/google/pprof/issues/680#issuecomment-1032174210. I
reproduce them below:

- binutils version 2.29.1: 1.1 seconds
- binutils version 2.33.1: 1.1 seconds
- binutils version 2.35.2: 6.8 seconds
- binutils version 2.36.1: 6.5 seconds
- binutils version 2.37: Still not loaded at 6 minutes

I think the relevant binutil tool here is addr2line. Does anyone have a
quick idea for what may have caused the slow-down? I was thinking about
doing a git bisect, but I figured it is probably way more efficient to
contact the experts!

Alex

Re: Noted slowness in profile loading with binutils 2.37

[H.J. Lu]

On Tue, Feb 8, 2022 at 9:45 AM Alexander Lindsay via Binutils
<binutils@sourceware.org> wrote:
>
> Hi all,
>
> I recently experienced a slow-down in profile loading by the tool pprof,
> and I believe I've boiled it down to changing from previous versions of
> binutils to binutils version 2.37. Timings of profile loading are
> documented on the pprof ticket I originally opened here:
> https://github.com/google/pprof/issues/680#issuecomment-1032174210. I
> reproduce them below:
>
> - binutils version 2.29.1: 1.1 seconds
> - binutils version 2.33.1: 1.1 seconds
> - binutils version 2.35.2: 6.8 seconds
> - binutils version 2.36.1: 6.5 seconds
> - binutils version 2.37: Still not loaded at 6 minutes
>
> I think the relevant binutil tool here is addr2line. Does anyone have a
> quick idea for what may have caused the slow-down? I was thinking about
> doing a git bisect, but I figured it is probably way more efficient to
> contact the experts!
>

This may be related to:

https://sourceware.org/bugzilla/show_bug.cgi?id=28843

-- 
H.J.

Re: Noted slowness in profile loading with binutils 2.37

[Alexander Lindsay]

Hmm, I'm trying with master and I still see the slowness. I'll note that I
also saw the slowness when I configured a 2.37 build with
`--enable-follow-debug-links=no` when I was wondering if that was the
relevant change.

On Tue, Feb 8, 2022 at 9:58 AM H.J. Lu <hjl.tools@gmail.com> wrote:

> On Tue, Feb 8, 2022 at 9:45 AM Alexander Lindsay via Binutils
> <binutils@sourceware.org> wrote:
> >
> > Hi all,
> >
> > I recently experienced a slow-down in profile loading by the tool pprof,
> > and I believe I've boiled it down to changing from previous versions of
> > binutils to binutils version 2.37. Timings of profile loading are
> > documented on the pprof ticket I originally opened here:
> > https://github.com/google/pprof/issues/680#issuecomment-1032174210. I
> > reproduce them below:
> >
> > - binutils version 2.29.1: 1.1 seconds
> > - binutils version 2.33.1: 1.1 seconds
> > - binutils version 2.35.2: 6.8 seconds
> > - binutils version 2.36.1: 6.5 seconds
> > - binutils version 2.37: Still not loaded at 6 minutes
> >
> > I think the relevant binutil tool here is addr2line. Does anyone have a
> > quick idea for what may have caused the slow-down? I was thinking about
> > doing a git bisect, but I figured it is probably way more efficient to
> > contact the experts!
> >
>
> This may be related to:
>
> https://sourceware.org/bugzilla/show_bug.cgi?id=28843
>
> --
> H.J.
>

Re: Noted slowness in profile loading with binutils 2.37

[Alan Modra]

On Tue, Feb 08, 2022 at 09:44:58AM -0800, Alexander Lindsay via Binutils wrote:
> Hi all,
> 
> I recently experienced a slow-down in profile loading by the tool pprof,
> and I believe I've boiled it down to changing from previous versions of
> binutils to binutils version 2.37. Timings of profile loading are
> documented on the pprof ticket I originally opened here:
> https://github.com/google/pprof/issues/680#issuecomment-1032174210. I
> reproduce them below:
> 
> - binutils version 2.29.1: 1.1 seconds
> - binutils version 2.33.1: 1.1 seconds
> - binutils version 2.35.2: 6.8 seconds
> - binutils version 2.36.1: 6.5 seconds
> - binutils version 2.37: Still not loaded at 6 minutes
> 
> I think the relevant binutil tool here is addr2line. Does anyone have a
> quick idea for what may have caused the slow-down? I was thinking about
> doing a git bisect, but I figured it is probably way more efficient to
> contact the experts!

The "experts" here have made lots of changes in the time between 2.33
and 2.37.  It's hard to say which one might have caused the extreme
slowdown.  Bisection is the way to go.  I hope it doesn't turn out to
be one of the many patches made for fuzzed object files, which may
help security a tiny bit but in general don't result in a better
binutils.

-- 
Alan Modra
Australia Development Lab, IBM

Re: Noted slowness in profile loading with binutils 2.37

[Nick Clifton]

Hi Alexander,

> - binutils version 2.36.1: 6.5 seconds
> - binutils version 2.37: Still not loaded at 6 minutes
> 
> I think the relevant binutil tool here is addr2line. Does anyone have a
> quick idea for what may have caused the slow-down? 

It will be a change in the BFD library.  More specifically it
is likely to be a change to bfd/dwarf2.c.  Have a look at the
ChangeLog in the bfd/ directory for the 2.37 release for more
hints.

I suspect, but do not know for sure, that it could be the patch
for PR 27484 ....

Cheers
   Nick

Re: Noted slowness in profile loading with binutils 2.37

[Alexander Lindsay]

Hi Nick,

This was the result of my bisect:

ca8f6bc629cb27792ce449e7253c74a3f6f75fda is the first bad commit
Date:   Tue Mar 2 16:08:23 2021 +0000

    Fix the BFD library's parsing of DIEs where specification attributes
can refer to variables that are defined later on.

            PR 27484
            * dwarf2.c (scan_unit_for_symbols): Scan twice, once to
accumulate
            function and variable tags and a second time to resolve their
            attributes.

 bfd/ChangeLog |   7 ++++
 bfd/dwarf2.c  | 133
++++++++++++++++++++++++++++++++++++++++++++++------------
 2 files changed, 114 insertions(+), 26 deletions(-)

On Thu, Feb 10, 2022 at 3:00 AM Nick Clifton <nickc@redhat.com> wrote:

> Hi Alexander,
>
> > - binutils version 2.36.1: 6.5 seconds
> > - binutils version 2.37: Still not loaded at 6 minutes
> >
> > I think the relevant binutil tool here is addr2line. Does anyone have a
> > quick idea for what may have caused the slow-down?
>
> It will be a change in the BFD library.  More specifically it
> is likely to be a change to bfd/dwarf2.c.  Have a look at the
> ChangeLog in the bfd/ directory for the 2.37 release for more
> hints.
>
> I suspect, but do not know for sure, that it could be the patch
> for PR 27484 ....
>
> Cheers
>    Nick
>
>
>

Re: Noted slowness in profile loading with binutils 2.37

[Alexander Lindsay]

So it looks like you were spot-on

On Fri, Feb 11, 2022 at 10:16 AM Alexander Lindsay <alexlindsay239@gmail.com>
wrote:

> Hi Nick,
>
> This was the result of my bisect:
>
> ca8f6bc629cb27792ce449e7253c74a3f6f75fda is the first bad commit
> Date:   Tue Mar 2 16:08:23 2021 +0000
>
>     Fix the BFD library's parsing of DIEs where specification attributes
> can refer to variables that are defined later on.
>
>             PR 27484
>             * dwarf2.c (scan_unit_for_symbols): Scan twice, once to
> accumulate
>             function and variable tags and a second time to resolve their
>             attributes.
>
>  bfd/ChangeLog |   7 ++++
>  bfd/dwarf2.c  | 133
> ++++++++++++++++++++++++++++++++++++++++++++++------------
>  2 files changed, 114 insertions(+), 26 deletions(-)
>
> On Thu, Feb 10, 2022 at 3:00 AM Nick Clifton <nickc@redhat.com> wrote:
>
>> Hi Alexander,
>>
>> > - binutils version 2.36.1: 6.5 seconds
>> > - binutils version 2.37: Still not loaded at 6 minutes
>> >
>> > I think the relevant binutil tool here is addr2line. Does anyone have a
>> > quick idea for what may have caused the slow-down?
>>
>> It will be a change in the BFD library.  More specifically it
>> is likely to be a change to bfd/dwarf2.c.  Have a look at the
>> ChangeLog in the bfd/ directory for the 2.37 release for more
>> hints.
>>
>> I suspect, but do not know for sure, that it could be the patch
>> for PR 27484 ....
>>
>> Cheers
>>    Nick
>>
>>
>>

Re: Noted slowness in profile loading with binutils 2.37

[Nick Clifton]

Hi Alexander,

> So it looks like you were spot-on

Yay!

The sad news is that the patch is needed for correct functionality.

>                  PR 27484
>                  * dwarf2.c (scan_unit_for_symbols): Scan twice, once to accumulate
>                  function and variable tags and a second time to resolve their
>                  attributes.

It is a "feature" of the DWARF spec that the debug info can refer
to functions and variables before their definitions are provided,
so a two pass scan is needed.

If you are feeling brave, please feel free to investigate the code
in dwarf2.c and see if there is a faster way to solve the problem.
Maybe by implementing a lazy evaluation of attributes where a function
tag is only searched for when it is referenced ?  Just an idea...

Cheers
   Nick