[Bug libstdc++/107675] New: [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[Bug libstdc++/107675] New: [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

            Bug ID: 107675
           Summary: [13 Regression] GCC-13 is significantly slower to
                    startup on C++ programs
           Product: gcc
           Version: 13.0
            Status: UNCONFIRMED
          Severity: normal
          Priority: P3
         Component: libstdc++
          Assignee: unassigned at gcc dot gnu.org
          Reporter: tnfchris at gcc dot gnu.org
  Target Milestone: ---
            Target: aarch64*

The following simple testcase:

#include <cstdio>

int main(int argc, char** argv) {
    printf("Hello world\n");
    return 0;
}

is on average twice as slow as GCC 12 during startup:

> perf diff perf.data.gcc.12 perf.data.gcc.13

# Event 'cycles'
#
# Baseline  Delta Abs  Shared Object     Symbol
# ........  .........  ................  ...............................
#
   100.00%    +42.66%  gcc-13.exe        [.] fde_single_encoding_compare

Looking at perf the entirety of of the difference is spent in __libc_start_main
which on GCC 13 calls __libc_csu_init which calls init_object.constprop.0.

This constprop function spends half the time in frame_heapsort and the other
half in fde_single_encoding_compare.  Together these two calls are responsible
for the 2x slower startup.

Is it possible to mitigate this? At startup it's currently executing more than
6.5x the number of instructions as GCC-12 which is quite noticeable on small
devices.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #1 from Tamar Christina <tnfchris at gcc dot gnu.org> ---
Note that to test this, the glibc version stayed the same.

Also when using the default dynamically linked version, pointing to the GCC-12
libstdc++ from the GCC-13 also has no slowdown.  So this seems to be something
in libstdc++.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[jakub at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

Jakub Jelinek <jakub at gcc dot gnu.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |fweimer at redhat dot com,
                   |                            |jakub at gcc dot gnu.org

--- Comment #2 from Jakub Jelinek <jakub at gcc dot gnu.org> ---
Does the binary and libstdc++.so have PT_GNU_EH_FRAME header including binary
search table (readelf -Wl | grep GNU_EH_FRAME)?
During startup I think there just shouldn't be any exceptions thrown or
backtraces computed, so I'd think the FDEs should just be registered and
nothing else.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[fw at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #3 from Florian Weimer <fw at gcc dot gnu.org> ---
Would you please put a breakpoint on fde_single_encoding_compare and report the
backtrace? Which target are you testing?

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #4 from Tamar Christina <tnfchris at gcc dot gnu.org> ---
(In reply to Jakub Jelinek from comment #2)
> Does the binary and libstdc++.so have PT_GNU_EH_FRAME header including
> binary search table (readelf -Wl | grep GNU_EH_FRAME)?
> During startup I think there just shouldn't be any exceptions thrown or
> backtraces computed, so I'd think the FDEs should just be registered and
> nothing else.

Yes both do:

> ~/libstdcpp-test$ readelf -Wl ~/libstdcpp-test/gcc-trunk/lib64/libstdc++.so.6 | grep GNU_EH_FRAME
  GNU_EH_FRAME   0x1c5658 0x00000000001c5658 0x00000000001c5658 0x008e8c
0x008e8c R   0x4

> ~/libstdcpp-test$ readelf -Wl gcc-13-s.exe | grep GNU_EH_FRAME
  GNU_EH_FRAME   0x000724 0x0000000000400724 0x0000000000400724 0x000044
0x000044 R   0x4

also the difference seems more pronounced when statically linked.

(In reply to Florian Weimer from comment #3)
> Would you please put a breakpoint on fde_single_encoding_compare and report

for GCC-13 the trace is:

Reading symbols from ./gcc-13.exe...
(gdb) b fde_single_encoding_compare
Breakpoint 1 at 0x451630: file
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c, line 425.
(gdb) r
Starting program: ~/libstdcpp-test/gcc-13.exe

Breakpoint 1, fde_single_encoding_compare (ob=0x48cfe8 <object>, x=0x46d098,
y=0x46d084) at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:425
425     /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c: No such
file or directory.
(gdb) bt
#0  fde_single_encoding_compare (ob=0x48cfe8 <object>, x=0x46d098, y=0x46d084)
at /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:425
#1  0x0000000000451b8c in fde_split (erratic=<optimized out>, linear=<optimized
out>, fde_compare=<optimized out>, ob=<optimized out>) at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:660
#2  end_fde_sort (count=793, accu=0xfffffffff200, ob=0x48cfe8 <object>) at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:662
#3  init_object (ob=ob@entry=0x48cfe8 <object>) at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:888
#4  0x00000000004520a8 in __register_frame_info_bases (dbase=0x0, tbase=0x0,
ob=0x48cfe8 <object>, begin=<optimized out>) at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:130
#5  __register_frame_info_bases (dbase=0x0, tbase=0x0, ob=0x48cfe8 <object>,
begin=<optimized out>) at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:111
#6  __register_frame_info (begin=<optimized out>, ob=0x48cfe8 <object>) at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:150
#7  0x0000000000400798 in frame_dummy () at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
#8  0x0000000000400f90 in __libc_csu_init () at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
#9  0x0000000000400a78 in __libc_start_main () at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
#10 0x0000000000400688 in _start () at
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361

In GCC-12 it looks like this isn't called at all:

Reading symbols from ./gcc-12.exe...
(gdb) b fde_single_encoding_compare
Breakpoint 1 at 0x4503c0: file
/opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c, line 380.
(gdb) r
Starting program: ~/libstdcpp-test/gcc-12.exe
Hello world
[Inferior 1 (process 1580999) exited normally]

> the backtrace? Which target are you testing?

Testing aarch64-none-linux-gnu

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[pinskia at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

Andrew Pinski <pinskia at gcc dot gnu.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
   Target Milestone|---                         |13.0
   Last reconfirmed|                            |2022-11-14
     Ever confirmed|0                           |1
             Status|UNCONFIRMED                 |NEW

--- Comment #5 from Andrew Pinski <pinskia at gcc dot gnu.org> ---
Can you try right before r13-3707-g4e4e3ffd10f53e and right afterwards?

I would have assumed, the exception would not happen really.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[pinskia at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

Andrew Pinski <pinskia at gcc dot gnu.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |UNCONFIRMED
     Ever confirmed|1                           |0

--- Comment #6 from Andrew Pinski <pinskia at gcc dot gnu.org> ---
Didn't mean to mark this as confirmed.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #7 from Tamar Christina <tnfchris at gcc dot gnu.org> ---
(In reply to Andrew Pinski from comment #5)
> Can you try right before r13-3707-g4e4e3ffd10f53e and right afterwards?
> 
> I would have assumed, the exception would not happen really.

Sadly doesn't seem to be it.  I'll script a bisect.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[fw at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #8 from Florian Weimer <fw at gcc dot gnu.org> ---
(In reply to Tamar Christina from comment #4)
> /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:111
> #6  __register_frame_info (begin=<optimized out>, ob=0x48cfe8 <object>) at
> /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:150
> #7  0x0000000000400798 in frame_dummy () at
> /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
> #8  0x0000000000400f90 in __libc_csu_init () at
> /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
> #9  0x0000000000400a78 in __libc_start_main () at
> /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
> #10 0x0000000000400688 in _start () at
> /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361

Looks like a build with USE_EH_FRAME_REGISTRY. Unless you have configured with
--explicit-exception-frame-registration=yes, it may mean that
USE_PT_GNU_EH_FRAME was not detected correctly.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #9 from Tamar Christina <tnfchris at gcc dot gnu.org> ---
(In reply to Florian Weimer from comment #8)
> (In reply to Tamar Christina from comment #4)
> > /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:111
> > #6  __register_frame_info (begin=<optimized out>, ob=0x48cfe8 <object>) at
> > /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-fde.c:150
> > #7  0x0000000000400798 in frame_dummy () at
> > /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
> > #8  0x0000000000400f90 in __libc_csu_init () at
> > /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
> > #9  0x0000000000400a78 in __libc_start_main () at
> > /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
> > #10 0x0000000000400688 in _start () at
> > /opt/buildAgent/work/5c94c4ced6ebfcd0/libgcc/unwind-dw2-btree.h:361
> 
> Looks like a build with USE_EH_FRAME_REGISTRY. Unless you have configured
> with --explicit-exception-frame-registration=yes, it may mean that
> USE_PT_GNU_EH_FRAME was not detected correctly.

No, it's just made using default configure flags, no extra options.

[Bug libstdc++/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #10 from Tamar Christina <tnfchris at gcc dot gnu.org> ---
I've bisected this to:

commit 6e80a1d164d1f996ad08a512c000025a7c2ca893
Author: Thomas Neumann <tneumann@users.sourceforge.net>
Date:   Tue Mar 1 21:57:35 2022 +0100

    eliminate mutex in fast path of __register_frame

    The __register_frame/__deregister_frame functions are used to register
    unwinding frames from JITed code in a sorted list. That list itself
    is protected by object_mutex, which leads to terrible performance
    in multi-threaded code and is somewhat expensive even if single-threaded.
    There was already a fast-path that avoided taking the mutex if no
    frame was registered at all.

    This commit eliminates both the mutex and the sorted list from
    the atomic fast path, and replaces it with a btree that uses
    optimistic lock coupling during lookup. This allows for fully parallel
    unwinding and is essential to scale exception handling to large
    core counts.

    libgcc/ChangeLog:

            * unwind-dw2-fde.c (release_registered_frames): Cleanup at
shutdown.
            (__register_frame_info_table_bases): Use btree in atomic fast path.
            (__deregister_frame_info_bases): Likewise.
            (_Unwind_Find_FDE): Likewise.
            (base_from_object): Make parameter const.
            (classify_object_over_fdes): Add query-only mode.
            (get_pc_range): Compute PC range for lookup.
            * unwind-dw2-fde.h (last_fde): Make parameter const.
            * unwind-dw2-btree.h: New file.

 libgcc/unwind-dw2-btree.h | 953 ++++++++++++++++++++++++++++++++++++++++++++++
 libgcc/unwind-dw2-fde.c   | 194 +++++++---
 libgcc/unwind-dw2-fde.h   |   2 +-
 3 files changed, 1098 insertions(+), 51 deletions(-)
 create mode 100644 libgcc/unwind-dw2-btree.h

Looking at the patch it looks like it now forces an eager registration of
objects during frame registration vs a lazy initialization that was there
before.

[Bug libgcc/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

Tamar Christina <tnfchris at gcc dot gnu.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
          Component|libstdc++                   |libgcc

--- Comment #11 from Tamar Christina <tnfchris at gcc dot gnu.org> ---
So seems to be a libgcc issue rather than libstdc++.

[Bug libgcc/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ programs

[tnfchris at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

Thomas Neumann <tneumann at users dot sourceforge.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |tneumann at users dot sourceforge.
                   |                            |net

Tamar Christina <tnfchris at gcc dot gnu.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
     Ever confirmed|0                           |1
   Last reconfirmed|2022-11-14 00:00:00         |2022-11-22
             Status|UNCONFIRMED                 |NEW
             Target|aarch64*                    |

--- Comment #12 from Thomas Neumann <tneumann at users dot sourceforge.net> ---
That is probably highly platform dependent. Can you please tell me exactly
where you run this (on how to setup such a machine in a VM if not
Linux/x86_64)? I will then debug this.

--- Comment #13 from Tamar Christina <tnfchris at gcc dot gnu.org> ---
Thomas managed to reproduce it, so confirmed.

[Bug libgcc/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ statically linked programs

[m.cencora at gmail dot com]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

m.cencora at gmail dot com changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |m.cencora at gmail dot com

--- Comment #14 from m.cencora at gmail dot com ---
A comment to Thomas proposed patch "[PATCH] initialize fde objects lazily"

You cannot use 'relaxed' atomic load in is_object_initialized - as thread
performing such load will not observe/synchronize with any modifications (other
than atomic variable itself) performed by other threads.

Excerpt from cppreference:
Relaxed operation: there are no synchronization or ordering constraints imposed
on other reads or writes, only this operation's atomicity is guaranteed.

[Bug libgcc/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ statically linked programs

[tneumann at users dot sourceforge.net]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #15 from Thomas Neumann <tneumann at users dot sourceforge.net> ---
> You cannot use 'relaxed' atomic load in is_object_initialized - as thread
> performing such load will not observe/synchronize with any modifications
> (other than atomic variable itself) performed by other threads.

you are right, this has to be acquire. Very unfortunate. I thought we would get
away with relaxed because we double-check anyway, but with relaxed we might
miss the writes to the other fields of object.

On systems with strong memory order it does not matter, but on ARM this will
make the check slower.

[Bug libgcc/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ statically linked programs

[tneumann at users dot sourceforge.net]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

--- Comment #16 from Thomas Neumann <tneumann at users dot sourceforge.net> ---
I have committed a fix:

commit 6e56633daae79f514b0e71f4d9849bcd8d9ce71f
Author: Thomas Neumann
Date:   Fri Dec 9 18:23:44 2022 +0100

    initialize fde objects lazily

    When registering an unwind frame with __register_frame_info_bases
    we currently initialize that fde object eagerly. This has the
    advantage that it is immutable afterwards and we can safely
    access it from multiple threads, but it has the disadvantage
    that we pay the initialization cost even if the application
    never throws an exception.

    This commit changes the logic to initialize the objects lazily.
    The objects themselves are inserted into the b-tree when
    registering the frame, but the sorted fde_vector is
    not constructed yet. Only on the first time that an
    exception tries to pass through the registered code the
    object is initialized. We notice that with a double checking,
    first doing a relaxed load of the sorted bit and then re-checking
    under a mutex when the object was not initialized yet.

    Note that the check must implicitly be safe concering a concurrent
    frame deregistration, as trying the deregister a frame that is
    on the unwinding path of a concurrent exception is inherently racy.

    libgcc/ChangeLog:
            * unwind-dw2-fde.c: Initialize fde object lazily when
            the first exception tries to pass through.

[Bug libgcc/107675] [13 Regression] GCC-13 is significantly slower to startup on C++ statically linked programs

[rguenth at gcc dot gnu.org]

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=107675

Richard Biener <rguenth at gcc dot gnu.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|---                         |FIXED

--- Comment #17 from Richard Biener <rguenth at gcc dot gnu.org> ---
Thus fixed.