Bug 55585 - compile time hog at -O1 -fboundscheck -g
Summary: compile time hog at -O1 -fboundscheck -g
Status: RESOLVED FIXED
Alias: None
Product: gcc
Classification: Unclassified
Component: debug (show other bugs)
Version: 4.7.3
: P3 normal
Target Milestone: ---
Assignee: Not yet assigned to anyone
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-12-04 08:22 UTC by Joost VandeVondele
Modified: 2019-04-04 22:16 UTC (History)
1 user (show)

See Also:
Host:
Target:
Build:
Known to work:
Known to fail:
Last reconfirmed: 2014-05-28 00:00:00


Attachments
gzipped testcase (109.44 KB, application/x-gzip)
2012-12-04 08:22 UTC, Joost VandeVondele
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Joost VandeVondele 2012-12-04 08:22:05 UTC
Created attachment 28870 [details]
gzipped testcase

With 4.4.6 the following timings are seen:

time /usr/bin/gfortran -c -O0 slow.f90 
real	0m2.299s
time /usr/bin/gfortran -c -O1 -fbounds-check slow.f90 
real	0m16.560s
time /usr/bin/gfortran -c -g -O2 -fbounds-check slow.f90 
real	0m32.841s


With 4.7 I see significant slowdowns at -O1 -fbounds-check, being extreme with -g

time gfortran -c -O0 slow.f90 
real	0m3.355s
time gfortran -c -O1 -fbounds-check slow.f90 
real	0m43.057s
time gfortran -c -g -O1 -fbounds-check slow.f90 
real	3m42.117s
time gfortran -c -g -O2 -fbounds-check  slow.f90 
real	0m20.102s


I wonder if whatever pass makes -O2 so fast should not be implied at -O1 -fbounds-check.
Comment 1 Joost VandeVondele 2012-12-04 09:09:59 UTC
After building with checking release, the issue seems to be purely a vartracking one:

 variable tracking       :   1.91 ( 1%) usr   0.00 ( 0%) sys   1.98 ( 1%) wall   28861 kB ( 4%) ggc
 var-tracking dataflow   : 112.89 (60%) usr   0.14 (16%) sys 113.01 (59%) wall       0 kB ( 0%) ggc
 var-tracking emit       :  52.93 (28%) usr   0.01 ( 1%) sys  52.95 (28%) wall   14480 kB ( 2%) ggc
Comment 2 Richard Biener 2012-12-04 09:35:21 UTC
It's probably the very many calls.  At -O2 VRP runs and eventually removes
most of them.

Eventually the frontend should try to avoid emitting useless bound checks.
Comment 3 Joost VandeVondele 2012-12-04 09:39:12 UTC
(In reply to comment #2)
> It's probably the very many calls.  At -O2 VRP runs and eventually removes
> most of them.

Unfortunately, 

gfortran -c -ftime-report -O1 -fbounds-check -g -ftree-vrp slow.f90

is still equally slow.
Comment 4 Joost VandeVondele 2012-12-04 10:43:10 UTC
Interestingly, the magic switch is -fstrict-aliasing... 20x speedup. for a Fortran code quite a surprise.

> time gfortran -c -O1 -fbounds-check -g -fstrict-aliasing slow.f90 
real	0m11.483s

I think for Fortran -fstrict-aliasing could well be the default at -O1, but maybe there is an underlying reason why this flag is needed ?
Comment 5 Richard Biener 2012-12-04 11:00:39 UTC
(In reply to comment #4)
> Interestingly, the magic switch is -fstrict-aliasing... 20x speedup. for a
> Fortran code quite a surprise.
> 
> > time gfortran -c -O1 -fbounds-check -g -fstrict-aliasing slow.f90 
> real    0m11.483s
> 
> I think for Fortran -fstrict-aliasing could well be the default at -O1, but
> maybe there is an underlying reason why this flag is needed ?

Well, it probably enables CSE that removes some of the bounds-checking calls.
Not sure why exactly without investigating.

GFortran could enable strict-aliasing unconditionally if it likes (even
at -O0).
Comment 6 Joost VandeVondele 2012-12-04 11:56:59 UTC
(In reply to comment #5)
> GFortran could enable strict-aliasing unconditionally if it likes (even
> at -O0).

I have now opened PR55591 for this.
Comment 7 Dominique d'Humieres 2014-05-28 22:07:57 UTC
On trunk (4.10) r211028, I get

[Book15] f90/bug% time gfc pr55585.f90 -fbounds-check -O1 -g -fstrict-aliasing
12.597u 0.169s 0:13.02 97.9%	0+0k 89+40io 2600pf+0w
[Book15] f90/bug% time gfc pr55585.f90 -fbounds-check -O1 -g
91.778u 0.739s 1:32.54 99.9%	0+0k 20+29io 402pf+0w
[Book15] f90/bug% time gfc pr55585.f90 -fbounds-check -O1
31.269u 0.320s 0:31.60 99.9%	0+0k 3+10io 400pf+0w
[Book15] f90/bug% time gfc pr55585.f90 -fbounds-check -O2
13.154u 0.117s 0:13.28 99.8%	0+0k 2+14io 250pf+0w
[Book15] f90/bug% time gfc pr55585.f90 -fbounds-check
15.805u 0.329s 0:16.14 99.8%	0+0k 3+14io 597pf+0w
[Book15] f90/bug% time gfc pr55585.f90
3.030u 0.063s 0:03.10 99.6%	0+0k 0+5io 110pf+0w
Comment 8 Dominique d'Humieres 2019-04-04 22:16:27 UTC
% time gfortran-fsf-5 -c -g -O1 -fbounds-check pr55585.f90
74.868u 1.625s 1:16.58 99.8%	0+0k 0+0io 26pf+0w
% time gfortran-fsf-6 -c -g -O1 -fbounds-check pr55585.f90
4.470u 0.159s 0:04.64 99.5%	0+0k 0+0io 5pf+0w
% time gfortran-fsf-7 -c -g -O1 -fbounds-check pr55585.f90
4.344u 0.167s 0:04.53 99.3%	0+0k 0+0io 4pf+0w
% time gfortran -c -g -O1 -fbounds-check pr55585.f90

gfortran-fsf-6 is gcc version 6.5.0. So the "significant slowdowns at -O1 -fbounds-check" seems to have been fixed since at least 6.5. Closing.