[Bug tree-optimization/108705] New: Unexpected CPU time usage with LTO in ranger propagation

[Bug tree-optimization/108705] New: Unexpected CPU time usage with LTO in ranger propagation

[rimvydas.jas at gmail dot com]

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

            Bug ID: 108705
           Summary: Unexpected CPU time usage with LTO in ranger
                    propagation
           Product: gcc
           Version: 13.0
            Status: UNCONFIRMED
          Severity: normal
          Priority: P3
         Component: tree-optimization
          Assignee: unassigned at gcc dot gnu.org
          Reporter: rimvydas.jas at gmail dot com
  Target Milestone: ---

Very trivialized reduced testcase that still works with
--enable-checking=release configured trunk.

$ cat hog.f90  # foo() and bar() are in separate units in original case
subroutine bar(n,m,p,s) ! in bar.f90
implicit none
integer :: n,m
real,intent(inout) :: p(n),s(*)
!real,intent(inout) :: p(:),s(:) ! gives slower growth
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
call foo(n,m,p,s)
! ...
!call foo(n,m,p,s)
end subroutine bar

subroutine foo(n,m,p,b) ! in foo.f90
implicit none
integer :: n,m,j
real,intent(inout) :: p(n),b(*)
do j=1,n
  b(m+j-1)=p(j)
enddo
m=m+n ! <---- problematic part
end subroutine foo

$ gfortran -Wall -Wextra -O2 -flto -c hog.f90 # mimic ccBemfcW.ltrans23.o
$ lto1 -ftime-report -fchecking=0 hog.o # -fltrans /tmp/ccBemfcW.ltrans23.o
Reading object files: hog.o {GC 2518k}  {heap 1028k}
Reading the symbol table:
Merging declarations: {GC 2520k}  {heap 1028k}
Reading summaries: <odr> {GC 2520k}  {heap 1028k} <profile_estimate> {GC 2520k}
 {heap 1028k} <icf> {GC 2520k}  {heap 1028k} <fnsummary> {GC 2530k}  {heap
1168k} <pure-const> {GC 2530k}  {heap 1168k} <modref> {GC 2532k}  {heap 1168k}
{GC 2532k} 
Merging symbols: {heap 1168k}Reading function bodies:
Performing interprocedural optimizations
 <odr> {heap 1168k} <whole-program> {heap 1168k} <profile_estimate> {heap
1168k} <icf> {heap 1360k} <devirt> {heap 1360k} <cp> {heap 1360k} <cdtor> {heap
1360k} <fnsummary> {heap 1360k} <inline> {heap 1360k} <pure-const> {heap 1360k}
<modref> {heap 1360k} <free-fnsummary> {heap 1360k} <static-var> {heap 1360k}
<single-use> {heap 1360k} <comdats> {heap 1360k}Assembling functions:
 <simdclone> {heap 1360k} foo in:foo_ bar in:bar_
Time variable                                   usr           sys          wall
          GGC
 phase setup                        :   0.00 (  0%)   0.00 (  0%)   0.00 (  0%)
 2583k ( 67%)
 phase opt and generate             :1490.95 (100%)   0.00 (  0%)1491.02 (100%)
 1230k ( 32%)
 callgraph functions expansion      :1490.95 (100%)   0.00 (  0%)1491.02 (100%)
 1201k ( 31%)
 tree VRP                           :   5.08 (  0%)   0.00 (  0%)   5.07 (  0%)
   84k (  2%)
 dominator optimization             :1485.85 (100%)   0.00 (  0%)1485.92 (100%)
   16k (  0%)
 tree canonical iv                  :   0.01 (  0%)   0.00 (  0%)   0.00 (  0%)
   71k (  2%)
 tree loop distribution             :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
  115k (  3%)
 dead store elim1                   :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
 2304  (  0%)
 combiner                           :   0.01 (  0%)   0.00 (  0%)   0.00 (  0%)
   42k (  1%)
 initialize rtl                     :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
   12k (  0%)
 TOTAL                              :1490.95          0.00       1491.02       
 3846k

For 10+ calls adding extra new call adds to total time: 0.21, 1.07, 6.29,
38.74, 238.24, 1490.95, 9424.12, ... seconds of CPU time.

This is not a problem for non-LTO builds since objects need to be compiled only
once for all executables in the project.  However with LTO it means that for
any executable having problematic subroutines in call graph *and* having such
unit pairs in the same ltrans partition would need to be compiled from scratch
over and over.  In original case final LTO link of a first executable with
-flto=20 was still compiling last 3 ltrans partitions after 25h+ (gcc-12 is
fine).

It is quite hard to say where lto1 gets "stuck" (as in infinite loop, no new
output gets added to assembly outputs either).  One has to ps(1) the full
command line, grab /tmp/ccBemfcW.ltrans23.o and manually invoke lto1 to see
where problematic code units could be.  Also there are no support for
attributes to deal with such problems e.g.:
!GCC$ ATTRIBUTES noclone,noinline :: foo
while LTO is getting better at detecting "strategically placed debug write()
statements".

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[pinskia at gcc dot gnu.org]

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

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

           What    |Removed                     |Added
----------------------------------------------------------------------------
           Keywords|                            |compile-time-hog
   Target Milestone|---                         |13.0
            Summary|Unexpected CPU time usage   |[13 Regression] Unexpected
                   |with LTO in ranger          |CPU time usage with LTO in
                   |propagation                 |ranger propagation

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[rimvydas.jas at gmail dot com]

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

--- Comment #1 from Rimvydas (RJ) <rimvydas.jas at gmail dot com> ---
Using assumed shape arrays "p(:),s(:)" in bar() requires longer chain of calls
to foo() and all time spent moves to "tree VRP", but produced assembly is more
cluttered than with assumed size array declarations.  Original code trips on
both variants in different ltrans partitions during LTO link.

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[rguenth at gcc dot gnu.org]

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

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

           What    |Removed                     |Added
----------------------------------------------------------------------------
     Ever confirmed|0                           |1
                 CC|                            |rguenth at gcc dot gnu.org
             Status|UNCONFIRMED                 |WAITING
   Last reconfirmed|                            |2023-02-09

--- Comment #2 from Richard Biener <rguenth at gcc dot gnu.org> ---
Hmm, so how's this supposed to be reproduced?  Even with separate TUs for the
two functions I can't get a slow compile?

How many 'call foo ...' stmts am I supposed to have?

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[amacleod at redhat dot com]

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

Andrew Macleod <amacleod at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |amacleod at redhat dot com

--- Comment #3 from Andrew Macleod <amacleod at redhat dot com> ---
I have been unable to reproduce it as well

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[rimvydas.jas at gmail dot com]

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

--- Comment #4 from Rimvydas (RJ) <rimvydas.jas at gmail dot com> ---
Interesting.  I see failure even on online godbolt compiler x86-64 gfortran
(trunk) with -O2: "Killed - processing time exceeded"

Just rechecked on fresh arch linux with gcc 12.2.1 host:

$ ./gcc/gfortran -Bgcc/ -v -O2 -ftime-report -c hog.f90
Reading specs from gcc/specs
COLLECT_GCC=./gcc/gfortran
Target: x86_64-pc-linux-gnu
Configured with: /zzz/gg/configure --disable-multilib
Thread model: posix
Supported LTO compression algorithms: zlib zstd
gcc version 13.0.1 20230209 (experimental) (GCC)
COLLECT_GCC_OPTIONS='-B' 'gcc/' '-v' '-O2' '-ftime-report' '-c'
'-mtune=generic' '-march=x86-64'
 gcc/f951 hog.f90 -quiet -dumpbase hog.f90 -dumpbase-ext .f90 -mtune=generic
-march=x86-64 -O2 -version -ftime-report -fintrinsic-modules-path finclude
-fpre-include=/usr/include/finclude/math-vector-fortran.h -o /tmp/ccnSnvQ4.s
GNU Fortran (GCC) version 13.0.1 20230209 (experimental) (x86_64-pc-linux-gnu)
        compiled by GNU C version 13.0.1 20230209 (experimental), GMP version
6.2.1, MPFR version 4.2.0, MPC version 1.3.1, isl version isl-0.24-GMP

GGC heuristics: --param ggc-min-expand=30 --param ggc-min-heapsize=4096

Time variable                                   usr           sys          wall
          GGC
 phase parsing                      :   0.01 (  0%)   0.00 (  0%)   0.01 (  0%)
 1884k ( 55%)
 phase opt and generate             :2039.11 (100%)   0.02 (100%)2039.15 (100%)
 1319k ( 39%)
 callgraph functions expansion      :2039.11 (100%)   0.01 ( 50%)2039.13 (100%)
 1145k ( 34%)
 callgraph ipa passes               :   0.00 (  0%)   0.01 ( 50%)   0.02 (  0%)
  151k (  4%)
 df live regs                       :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
    0  (  0%)
 parser (global)                    :   0.01 (  0%)   0.00 (  0%)   0.01 (  0%)
 1884k ( 55%)
 integration                        :   0.00 (  0%)   0.01 ( 50%)   0.00 (  0%)
  124k (  4%)
 tree VRP                           :   6.88 (  0%)   0.00 (  0%)   6.88 (  0%)
   78k (  2%)
 tree SSA rewrite                   :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
 4488  (  0%)
 tree SSA incremental               :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
   26k (  1%)
 dominator optimization             :2032.19 (100%)   0.00 (  0%)2032.20 (100%)
   16k (  0%)
 tree PRE                           :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
   16k (  0%)
 tree conservative DCE              :   0.01 (  0%)   0.00 (  0%)   0.00 (  0%)
 2360  (  0%)
 tree SSA verifier                  :   0.00 (  0%)   0.00 (  0%)   0.01 (  0%)
    0  (  0%)
 tree modref                        :   0.00 (  0%)   0.01 ( 50%)   0.00 (  0%)
 6056  (  0%)
 out of ssa                         :   0.01 (  0%)   0.00 (  0%)   0.00 (  0%)
    0  (  0%)
 CSE 2                              :   0.01 (  0%)   0.00 (  0%)   0.00 (  0%)
   48  (  0%)
 initialize rtl                     :   0.01 (  0%)   0.00 (  0%)   0.00 (  0%)
   12k (  0%)
 rest of compilation                :   0.00 (  0%)   0.00 (  0%)   0.02 (  0%)
   14k (  0%)
 TOTAL                              :2039.12          0.02       2039.16       
 3404k
Extra diagnostic checks enabled; compiler may run slowly.
Configure with --enable-checking=release to disable checks.
COLLECT_GCC_OPTIONS='-B' 'gcc/' '-v' '-O2' '-ftime-report' '-c'
'-mtune=generic' '-march=x86-64'
 gcc/as -v --64 -o hog.o /tmp/ccnSnvQ4.s
GNU assembler version 2.40 (x86_64-pc-linux-gnu) using BFD version (GNU
Binutils) 2.40
COMPILER_PATH=gcc/
LIBRARY_PATH=gcc/:/lib/../lib64/:/usr/lib/../lib64/:/lib/:/usr/lib/
COLLECT_GCC_OPTIONS='-B' 'gcc/' '-v' '-O2' '-ftime-report' '-c'
'-mtune=generic' '-march=x86-64'

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[amacleod at redhat dot com]

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

--- Comment #5 from Andrew Macleod <amacleod at redhat dot com> ---
Whats even odder...  https://gcc.gnu.org/bugzilla/show_bug.cgi?id=108687
Thats a s390 bug that is spending forever in one of the DOM passes as well...
and I cannot seem to reproduce it either.

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[rimvydas.jas at gmail dot com]

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

--- Comment #6 from Rimvydas (RJ) <rimvydas.jas at gmail dot com> ---
Created attachment 54442
  --> https://gcc.gnu.org/bugzilla/attachment.cgi?id=54442&action=edit
compressed output of gprof lto1 gmon.out

profiled lto1 backend took 3829s to optimize 16 foo_() calls

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[rimvydas.jas at gmail dot com]

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

--- Comment #7 from Rimvydas (RJ) <rimvydas.jas at gmail dot com> ---
The original cases have over 65 long call cascades that take different small
arrays to be packed.  Because of geometric time growth for every next repeated
call, the -flto -O2 is unusable in these specific cases.
I think I found a workaround after investigating f951 internals to add support
for NOINLINE attribute in form of:
!GCC$ ATTRIBUTES noinline :: foo
It works with LTO and might be useful for other issues.  I'll post a patch with
feature request in gfortran mailing list after some testing.

If the pr is not reproducible it can be closed as INVALID, since it might be a
host software configuration specific issue.

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[amacleod at redhat dot com]

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

--- Comment #8 from Andrew Macleod <amacleod at redhat dot com> ---
This fix I just checked in for 108687 exhibited similar performance
characteristics, also in the same pass.. Perhaps it will fix your problem.

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[rimvydas.jas at gmail dot com]

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

--- Comment #9 from Rimvydas (RJ) <rimvydas.jas at gmail dot com> ---
(In reply to Andrew Macleod from comment #8)
> This fix I just checked in for 108687 exhibited similar performance
> characteristics, also in the same pass.. Perhaps it will fix your problem.

Thank you!  Will have to check original cases still, but for testcase variants
even bumping calls count from 16 to 222 now takes only:
 assumed size:   ~6s dominator optimization 4.97 ( 85%)
 assumed shape: ~20s callgraph functions expansion 16.47 ( 79%)
  mainly callgraph ipa passes (22%)+alias stmt walk (11%)+tree ssa inc (14%)

[Bug tree-optimization/108705] [13 Regression] Unexpected CPU time usage with LTO in ranger propagation

[rimvydas.jas at gmail dot com]

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

Rimvydas (RJ) <rimvydas.jas at gmail dot com> changed:

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

--- Comment #10 from Rimvydas (RJ) <rimvydas.jas at gmail dot com> ---
Fixed by g:6493b7af37e473a89c67afab474330f931dd8447 no more issues in ltrans
partitions