[Bug c/111241] New: Extraordinary amount of time spent in "callgraph functions expansion"

[Bug c/111241] New: Extraordinary amount of time spent in "callgraph functions expansion"

[dcb314 at hotmail dot com]

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

            Bug ID: 111241
           Summary: Extraordinary amount of time spent in "callgraph
                    functions expansion"
           Product: gcc
           Version: unknown
            Status: UNCONFIRMED
          Severity: normal
          Priority: P3
         Component: c
          Assignee: unassigned at gcc dot gnu.org
          Reporter: dcb314 at hotmail dot com
  Target Milestone: ---

Created attachment 55818
  --> https://gcc.gnu.org/bugzilla/attachment.cgi?id=55818&action=edit
gzipped C source code

foundBugs $ time ~/gcc/results/bin/gcc -c -w  -O1 -fno-var-tracking  bug951.c

real    0m52.441s
user    0m51.038s
sys     0m0.498s
foundBugs $ (ulimit -t 300; time ~/gcc/results/bin/gcc -c -w  -O2
-fno-var-tracking  bug951.c)

real    2m18.781s
user    2m15.957s
sys     0m1.205s
foundBugs $ 

From -ftime-report on the second compile:

Time variable                                   usr           sys          wall
          GGC
 phase setup                        :   0.00 (  0%)   0.01 (  0%)   0.00 (  0%)
 1832k (  0%)
 phase parsing                      :   1.78 (  1%)   2.83 ( 56%)   4.66 (  3%)
   55M ( 12%)
 phase opt and generate             : 136.07 ( 99%)   2.18 ( 43%) 139.81 ( 97%)
  411M ( 88%)
 garbage collection                 :   0.95 (  1%)   0.02 (  0%)   0.91 (  1%)
    0  (  0%)
 callgraph construction             :   0.16 (  0%)   0.02 (  0%)   0.16 (  0%)
   11M (  2%)
 callgraph optimization             :   0.15 (  0%)   0.05 (  1%)   0.22 (  0%)
 3272  (  0%)
 callgraph functions expansion      : 106.59 ( 77%)   1.39 ( 28%) 109.22 ( 76%)
  299M ( 64%)
 callgraph ipa passes               :  28.82 ( 21%)   0.74 ( 15%)  29.88 ( 21%)
   84M ( 18%)

[Bug middle-end/111241] Extraordinary amount of time spent in "callgraph functions expansion"

[pinskia at gcc dot gnu.org]

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

--- Comment #1 from Andrew Pinski <pinskia at gcc dot gnu.org> ---
With -fno-checking but still the default --enable-checking setting for the
trunk:

 alias stmt walking                 :  18.90 ( 21%)   0.20 (  7%)  25.86 ( 24%)
 8960  (  0%)
 df reaching defs                   :   9.96 ( 11%)   0.05 (  2%)   9.90 (  9%)
    0  (  0%)
 tree FRE                           :   9.07 ( 10%)   0.38 ( 13%)   9.49 (  9%)
   14M (  3%)
 tree DSE                           :   9.43 ( 11%)   0.00 (  0%)   9.45 (  9%)
   11k (  0%)


The rest are spread out.

Note "callgraph functions expansion" is a "meta" timevar and includes the above
really.

[Bug middle-end/111241] Extraordinary amount of time spent in "callgraph functions expansion"

[rguenth at gcc dot gnu.org]

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

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

           What    |Removed                     |Added
----------------------------------------------------------------------------
     Ever confirmed|0                           |1
             Status|UNCONFIRMED                 |NEW
      Known to fail|                            |11.4.0, 13.2.0
   Last reconfirmed|                            |2023-08-31
            Version|unknown                     |13.2.0

--- Comment #2 from Richard Biener <rguenth at gcc dot gnu.org> ---
Confirmed.  -ftime-report -ftime-report-details reveals most of the alias stmt
walking time is from FRE (and then PRE).  Lowering --param
sccvn-max-alias-queries-per-access doesn't help much (but we're not running
into the existing limit anyway).

At -O1 FRE doesn't iterate and PRE doesn't run so that helps compile-time.

We possibly run into the VN iteration complexity which scales non-linearily
with loop depth.  Lowering --param=rpo-vn-max-loop-depth to it's minimum
of two doesn't help either though.

Not a recent regression, the testcase doesn't build with GCC 10, GCC 11.4 is
20% slower than 13.2 for me.

[Bug middle-end/111241] Extraordinary amount of time spent in "callgraph functions expansion"

[rguenth at gcc dot gnu.org]

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

--- Comment #3 from Richard Biener <rguenth at gcc dot gnu.org> ---
Samples: 121K of event 'cycles:u', Event count (approx.): 159788164341          
Overhead       Samples  Command  Shared Object       Symbol                     
  21.24%         25791  cc1      cc1                 [.]
get_ref_base_and_exten#
   7.75%          9154  cc1      libc-2.31.so        [.] __memset_avx512_erms 
#
   5.61%          7072  cc1      cc1                 [.] dominated_by_p       
#
   2.43%          2936  cc1      cc1                 [.] bitmap_set_bit       
#
   2.38%          3000  cc1      cc1                 [.] dominated_by_p_w_unex
#
   1.76%          2154  cc1      cc1                 [.] find_base_term       
#
   1.75%          2148  cc1      cc1                 [.] ix86_find_base_term  
#
   1.41%          1656  cc1      cc1                 [.]
df_reorganize_refs_by_#

all usual suspects are present ... :/

The memset and df_reorganize_refs_by_defs are the known bug that RTL invariant
motion does work O(function-size) * O(number-of-loops) through df_analyze_loop
because reorganize-refs processes all function refs, not only loop refs
(difficult to fix).

For get_ref_base_and_extent we have ~2 array-refs per call and array-ref
processing is expensive (array_ref_element_size, but also
wi::lshift_large).  The most expensive calls are from vn_reference_lookup done
during elimination looking for redundant stores (that's odd), possibly
because it enables VN_WALKREWRITE unconditionally, for -O2 that's also
the default though.