* very different compilation times [no optimisation]
@ 2009-11-06 15:04 Basile STARYNKEVITCH
2009-11-06 15:16 ` Dave Korn
2009-11-06 15:35 ` Ian Lance Taylor
0 siblings, 2 replies; 9+ messages in thread
From: Basile STARYNKEVITCH @ 2009-11-06 15:04 UTC (permalink / raw)
To: GCC Mailing List
Hello All,
While working on the MELT branch (or plugin), I noticed something
strange regarding compilation time without any optimisations.
MELT is made of auto-generated C files, which are actually monster
files. One of the biggest file is warmelt-normal-0.c from
svn cat -r 153969 \
svn://gcc.gnu.org/svn/gcc/branches/melt-branch/gcc/melt/warmelt-normal-0.c
or you could download it using
http://gcc.gnu.org/viewcvs/branches/melt-branch/gcc/melt/warmelt-normal-0.c?revision=153969&view=co
It is a file of 114882 lines [many of them blanks or comments or #line]
or 5818723 bytes. There are about 157 routines inside.
The biggest routine in this file is probably an initialization (ie
mostly sequential) routine start_module_melt. This routine has 30712
lines. It calls the initialize_module_cdata routine, which has 11926
lines and is filling a local struct cdata_st of 1589 members (each being
a structure of a few words long).
I am running a shell script -called gcc/built-melt-cc-script in MELT
build directory and similar to the gcc/melt-cc-script.proto in MELT
subversion repository. The compiler run by that script is from the
GCCMELT_CC environment variable or else gcc.
This script first generate a tiny C file like
% cat /tmp/bdat7oohwd.c
const char melt_compiled_timestamp[]="Fri Nov 6 15:36:20 2009\
warmelt-normal-1.c";
const char melt_md5[]="32fc8c51c3439811d7c840fff7f0f588\
warmelt-normal-1.c";
const char melt_csource[]="warmelt-normal-1.c";
You imagine that generating that (using date & md5sum commands) don't
take long, and compiling that is quick also.
Then script compiles the big warmelt-normal-0.c file
gcc-4.3 -Wall -fPIC -g -DIN_GCC -DHAVE_CONFIG_H -I
/usr/src/Lang/_Obj_Gcc_Melt/gcc/melt-private-build-include
warmelt-normal-0.c -c -o /tmp/dobjCZd6Ag.o
This takes most of the time, as you could guess.
At last, the script links together the two files.
gcc-4.3 -Wall -fPIC -shared -g -DIN_GCC -DHAVE_CONFIG_H -I
/usr/src/Lang/_Obj_Gcc_Melt/gcc/melt-private-build-include
/tmp/bdat7oohwd.c /tmp/dobjCZd6Ag.o -o warmelt-normal-0-gcc4.3.so
Now the compilation timing, that is the total time for running the
script (as given by the time internal utility of zsh) Almost all of the
time is spent in compiling the warmelt-normal-0.c file. Notice that
there is no optimisation flag.
My system is a Debian/Sid/AMD64.
With the system's gcc-4.2
% gcc-4.2 -v
Using built-in specs.
Target: x86_64-linux-gnu
Configured with: ../src/configure -v
--enable-languages=c,c++,fortran,objc,obj-c++ --prefix=/usr
--enable-shared --with-system-zlib --libexecdir=/usr/lib
--without-included-gettext --enable-threads=posix --enable-nls
--with-gxx-include-dir=/usr/include/c++/4.2 --program-suffix=-4.2
--enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc
--enable-mpfr --with-tune=generic --enable-checking=release
--build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 4.2.4 (Debian 4.2.4-6)
GCC 4.2 time:::: 63.64s user 3.46s system 98% cpu 1:07.80 total
With the system's gcc-4.3
% gcc-4.3 -v
Using built-in specs.
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Debian 4.3.4-6'
--with-bugurl=file:///usr/share/doc/gcc-4.3/README.Bugs
--enable-languages=c,c++,fortran,objc,obj-c++ --prefix=/usr
--enable-shared --enable-multiarch --enable-linker-build-id
--with-system-zlib --libexecdir=/usr/lib --without-included-gettext
--enable-threads=posix --enable-nls
--with-gxx-include-dir=/usr/include/c++/4.3 --program-suffix=-4.3
--enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc
--enable-mpfr --with-tune=generic --enable-checking=release
--build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 4.3.4 (Debian 4.3.4-6)
GCC 4.3 time:::: 22.20s user 1.38s system 95% cpu 24.806 total
With the system's gcc-4.4
% gcc-4.4 -v
Using built-in specs.
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Debian 4.4.2-2'
--with-bugurl=file:///usr/share/doc/gcc-4.4/README.Bugs
--enable-languages=c,c++,fortran,objc,obj-c++ --prefix=/usr
--enable-shared --enable-multiarch --enable-linker-build-id
--with-system-zlib --libexecdir=/usr/lib --without-included-gettext
--enable-threads=posix --with-gxx-include-dir=/usr/include/c++/4.4
--program-suffix=-4.4 --enable-nls --enable-clocale=gnu
--enable-libstdcxx-debug --enable-objc-gc --with-arch-32=i486
--with-tune=generic --enable-checking=release --build=x86_64-linux-gnu
--host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 4.4.2 (Debian 4.4.2-2)
GCC 4.4 time:::: 98.79s user 4.16s system 98% cpu 1:44.92 total
Notice that gcc 4.4 is running four times slower that gcc-4.3!
With a recent gcc-trunk, with checking enabled, so the timing is not
very significant.
% gcc-trunk -v
Using built-in specs.
COLLECT_GCC=gcc-trunk
COLLECT_LTO_WRAPPER=/usr/local/libexec/gcc-trunk/gcc/x86_64-unknown-linux-gnu/4.5.0/lto-wrapper
Target: x86_64-unknown-linux-gnu
Configured with: /usr/src/Lang/gcc-trunk-bstarynk/configure
--program-suffix=-trunk --libdir=/usr/local/lib/gcc-trunk
--libexecdir=/usr/local/libexec/gcc-trunk
--with-gxx-include-dir=/usr/local/lib/gcc-trunk/include/c++/
--disable-multilib --enable-languages=c,c++ --enable-lto
--enable-plugins --enable-maintainer-mode : (reconfigured)
/usr/src/Lang/gcc-trunk-bstarynk/configure --program-suffix=-trunk
--libdir=/usr/local/lib/gcc-trunk
--libexecdir=/usr/local/libexec/gcc-trunk
--with-gxx-include-dir=/usr/local/lib/gcc-trunk/include/c++/
--disable-multilib --enable-languages=c,c++ --enable-lto
--enable-plugins --enable-maintainer-mode : (reconfigured)
/usr/src/Lang/gcc-trunk-bstarynk/configure --program-suffix=-trunk
--libdir=/usr/local/lib/gcc-trunk
--libexecdir=/usr/local/libexec/gcc-trunk
--with-gxx-include-dir=/usr/local/lib/gcc-trunk/include/c++/
--disable-multilib --enable-lto --enable-plugins
--enable-maintainer-mode --enable-languages=c,c++,lto --no-create
--no-recursion : (reconfigured)
/usr/src/Lang/gcc-trunk-bstarynk/configure --program-suffix=-trunk
--libdir=/usr/local/lib/gcc-trunk
--libexecdir=/usr/local/libexec/gcc-trunk
--with-gxx-include-dir=/usr/local/lib/gcc-trunk/include/c++/
--disable-multilib --enable-lto --enable-plugins
--enable-maintainer-mode --enable-languages=c,c++,lto --no-create
--no-recursion : (reconfigured)
/usr/src/Lang/gcc-trunk-bstarynk/configure --program-suffix=-trunk
--libdir=/usr/local/lib/gcc-trunk
--libexecdir=/usr/local/libexec/gcc-trunk
--with-gxx-include-dir=/usr/local/lib/gcc-trunk/include/c++/
--disable-multilib --enable-lto --enable-plugins
--enable-maintainer-mode --enable-languages=c,c++,lto --no-create
--no-recursion : (reconfigured)
/usr/src/Lang/gcc-trunk-bstarynk/configure --program-suffix=-trunk
--libdir=/usr/local/lib/gcc-trunk
--libexecdir=/usr/local/libexec/gcc-trunk
--with-gxx-include-dir=/usr/local/lib/gcc-trunk/include/c++/
--disable-multilib --enable-lto --enable-plugins
--enable-maintainer-mode --enable-languages=c,c++,lto --no-create
--no-recursion : (reconfigured)
/usr/src/Lang/gcc-trunk-bstarynk/configure --program-suffix=-trunk
--libdir=/usr/local/lib/gcc-trunk
--libexecdir=/usr/local/libexec/gcc-trunk
--with-gxx-include-dir=/usr/local/lib/gcc-trunk/include/c++/
--disable-multilib --enable-lto --enable-plugins
--enable-maintainer-mode --enable-languages=c,c++,lto --no-create
--no-recursion
Thread model: posix
gcc version 4.5.0 20091105 (experimental) (GCC)
GCC-TRUNK 4.5.0 20091105 (experimental) time::: 161.37s user 3.84s
system 96% cpu 2:50.64 total
With a recent clang+llvm [gotten by subversion less than a week ago)
% clang -v
clang version 1.1 (trunk 86234)
Target: x86_64-unknown-linux-gnu
Thread model: posix
CLANG time::: 31.27s user 4.31s system 77% cpu 45.641 total
With tinycc 0.9.25 which generates bad code:
5.71s user 0.77s system 99% cpu 6.524 total
To summarize (I actually compiled the generated warmelt-normal-1.c which
is almost the same as warmelt-normal-0.c)
time env GCCMELT_CC=gcc-trunk ./built-melt-cc-script -x
warmelt-normal-1.c
161.37s user 3.84s system 96% cpu 2:50.64 total
time env GCCMELT_CC=gcc-4.4 ./built-melt-cc-script -x
warmelt-normal-1.c
98.79s user 4.16s system 98% cpu 1:44.92 total
time env GCCMELT_CC=gcc-4.3 ./built-melt-cc-script -x
warmelt-normal-1.c
22.20s user 1.38s system 95% cpu 24.806 total
time env GCCMELT_CC=gcc-4.2 ./built-melt-cc-script -x
warmelt-normal-1.c
63.64s user 3.46s system 98% cpu 1:07.80 total
time env GCCMELT_CC=clang ./built-melt-cc-script -x
warmelt-normal-1.c
31.27s user 4.31s system 77% cpu 45.641 total
# tinycc 0.9.25 generates bad code
time env GCCMELT_CC=tcc ./built-melt-cc-script -x warmelt-normal-1.c
5.71s user 0.77s system 99% cpu 6.524 total
The preprocessed warmelt-normal-1.i has 225697 lines or 11470145 bytes.
[Should I make a bugreport with it on GCC/Bugzilla?]
I am very surprised by the difference of compilation time between 4.3 & 4.4.
Regards.
--
Basile STARYNKEVITCH http://starynkevitch.net/Basile/
email: basile<at>starynkevitch<dot>net mobile: +33 6 8501 2359
8, rue de la Faiencerie, 92340 Bourg La Reine, France
*** opinions {are only mines, sont seulement les miennes} ***
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 15:04 very different compilation times [no optimisation] Basile STARYNKEVITCH
@ 2009-11-06 15:16 ` Dave Korn
2009-11-06 15:36 ` Basile STARYNKEVITCH
2009-11-06 15:35 ` Ian Lance Taylor
1 sibling, 1 reply; 9+ messages in thread
From: Dave Korn @ 2009-11-06 15:16 UTC (permalink / raw)
To: Basile STARYNKEVITCH; +Cc: GCC Mailing List
Basile STARYNKEVITCH wrote:
> The preprocessed warmelt-normal-1.i has 225697 lines or 11470145 bytes.
> [Should I make a bugreport with it on GCC/Bugzilla?]
From the sound of it, it should bzip fairly well.
> I am very surprised by the difference of compilation time between 4.3 &
> 4.4.
Me too. I'm particularly surprised if none of the automated checkers have
spotted it, maybe there's something your code triggers that they don't
exercise, so you probably should file a PR.
cheers,
DaveK
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 15:04 very different compilation times [no optimisation] Basile STARYNKEVITCH
2009-11-06 15:16 ` Dave Korn
@ 2009-11-06 15:35 ` Ian Lance Taylor
2009-11-06 15:43 ` Basile STARYNKEVITCH
1 sibling, 1 reply; 9+ messages in thread
From: Ian Lance Taylor @ 2009-11-06 15:35 UTC (permalink / raw)
To: Basile STARYNKEVITCH; +Cc: GCC Mailing List
Basile STARYNKEVITCH <basile@starynkevitch.net> writes:
> Notice that gcc 4.4 is running four times slower that gcc-4.3!
Use the -ftime-report option with both compilers to see where the time
is going.
Ian
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 15:16 ` Dave Korn
@ 2009-11-06 15:36 ` Basile STARYNKEVITCH
0 siblings, 0 replies; 9+ messages in thread
From: Basile STARYNKEVITCH @ 2009-11-06 15:36 UTC (permalink / raw)
To: Dave Korn; +Cc: GCC Mailing List
Dave Korn wrote:
> Basile STARYNKEVITCH wrote:
>
>> The preprocessed warmelt-normal-1.i has 225697 lines or 11470145 bytes.
>> [Should I make a bugreport with it on GCC/Bugzilla?]
>
> From the sound of it, it should bzip fairly well.
>
>> I am very surprised by the difference of compilation time between 4.3 &
>> 4.4.
>
> Me too. I'm particularly surprised if none of the automated checkers have
> spotted it, maybe there's something your code triggers that they don't
> exercise, so you probably should file a PR.
I filled http://gcc.gnu.org/bugzilla/show_bug.cgi?id=41971 with the bzip2-ed preprocessed warmelt-normal-1.i file
Regards.
--
Basile STARYNKEVITCH http://starynkevitch.net/Basile/
email: basile<at>starynkevitch<dot>net mobile: +33 6 8501 2359
8, rue de la Faiencerie, 92340 Bourg La Reine, France
*** opinions {are only mines, sont seulement les miennes} ***
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 15:35 ` Ian Lance Taylor
@ 2009-11-06 15:43 ` Basile STARYNKEVITCH
2009-11-06 15:49 ` Dave Korn
2009-11-06 16:37 ` Basile STARYNKEVITCH
0 siblings, 2 replies; 9+ messages in thread
From: Basile STARYNKEVITCH @ 2009-11-06 15:43 UTC (permalink / raw)
To: Ian Lance Taylor; +Cc: GCC Mailing List
Ian Lance Taylor wrote:
> Basile STARYNKEVITCH <basile@starynkevitch.net> writes:
>
>> Notice that gcc 4.4 is running four times slower that gcc-4.3!
>
> Use the -ftime-report option with both compilers to see where the time
> is going.
I also put the figures in the PR41971
glinka ~/tmp 16:39 % gcc-4.3 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
Execution times (seconds)
garbage collection : 1.02 ( 3%) usr 0.00 ( 0%) sys 1.02 ( 3%) wall 0 kB ( 0%) ggc
cfg cleanup : 0.56 ( 2%) usr 0.00 ( 0%) sys 0.58 ( 2%) wall 19 kB ( 0%) ggc
trivially dead code : 0.24 ( 1%) usr 0.00 ( 0%) sys 0.24 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.47 ( 1%) usr 0.03 ( 1%) sys 0.49 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.52 ( 2%) usr 0.00 ( 0%) sys 0.52 ( 1%) wall 6838 kB ( 2%) ggc
register information : 0.53 ( 2%) usr 0.00 ( 0%) sys 0.54 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.27 ( 1%) usr 0.01 ( 0%) sys 0.29 ( 1%) wall 2315 kB ( 1%) ggc
rebuild jump labels : 0.34 ( 1%) usr 0.00 ( 0%) sys 0.34 ( 1%) wall 0 kB ( 0%) ggc
preprocessing : 0.96 ( 3%) usr 0.53 (16%) sys 1.75 ( 5%) wall 24801 kB ( 7%) ggc
lexical analysis : 0.51 ( 2%) usr 1.28 (38%) sys 1.63 ( 4%) wall 0 kB ( 0%) ggc
parser : 2.72 ( 8%) usr 0.76 (23%) sys 3.54 (10%) wall 100081 kB (28%) ggc
inline heuristics : 1.26 ( 4%) usr 0.00 ( 0%) sys 1.22 ( 3%) wall 70 kB ( 0%) ggc
tree gimplify : 2.23 ( 7%) usr 0.15 ( 5%) sys 2.39 ( 7%) wall 58497 kB (16%) ggc
tree eh : 0.21 ( 1%) usr 0.00 ( 0%) sys 0.20 ( 1%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.65 ( 2%) usr 0.06 ( 2%) sys 0.73 ( 2%) wall 37602 kB (10%) ggc
tree CFG cleanup : 0.42 ( 1%) usr 0.00 ( 0%) sys 0.43 ( 1%) wall 0 kB ( 0%) ggc
dominance computation : 0.21 ( 1%) usr 0.00 ( 0%) sys 0.22 ( 1%) wall 0 kB ( 0%) ggc
expand : 7.09 (21%) usr 0.28 ( 8%) sys 7.36 (20%) wall 89051 kB (24%) ggc
jump : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
local alloc : 2.87 ( 9%) usr 0.02 ( 1%) sys 2.91 ( 8%) wall 3032 kB ( 1%) ggc
global alloc : 7.31 (22%) usr 0.12 ( 4%) sys 7.42 (20%) wall 18079 kB ( 5%) ggc
thread pro- & epilogue: 0.66 ( 2%) usr 0.00 ( 0%) sys 0.68 ( 2%) wall 256 kB ( 0%) ggc
final : 1.95 ( 6%) usr 0.08 ( 2%) sys 2.01 ( 5%) wall 360 kB ( 0%) ggc
symout : 0.10 ( 0%) usr 0.01 ( 0%) sys 0.09 ( 0%) wall 21440 kB ( 6%) ggc
TOTAL : 33.13 3.33 36.64 363506 kB
glinka ~/tmp 16:40 % gcc-4.4 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
Execution times (seconds)
garbage collection : 0.11 ( 1%) usr 0.00 ( 0%) sys 0.11 ( 1%) wall 0 kB ( 0%) ggc
callgraph construction: 0.25 ( 2%) usr 0.01 ( 0%) sys 0.28 ( 2%) wall 13570 kB ( 3%) ggc
callgraph optimization: 0.04 ( 0%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 339 kB ( 0%) ggc
cfg cleanup : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.05 ( 0%) wall 24 kB ( 0%) ggc
trivially dead code : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.10 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 0%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.13 ( 1%) usr 0.00 ( 0%) sys 0.13 ( 1%) wall 6956 kB ( 2%) ggc
register information : 0.09 ( 1%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.04 ( 0%) usr 0.00 ( 0%) sys 0.05 ( 0%) wall 2405 kB ( 1%) ggc
rebuild jump labels : 0.05 ( 0%) usr 0.01 ( 0%) sys 0.06 ( 0%) wall 0 kB ( 0%) ggc
preprocessing : 0.98 ( 9%) usr 0.61 (20%) sys 1.76 (13%) wall 25440 kB ( 6%) ggc
lexical analysis : 0.41 ( 4%) usr 1.15 (38%) sys 1.61 (12%) wall 0 kB ( 0%) ggc
parser : 1.69 (16%) usr 0.83 (27%) sys 2.37 (17%) wall 71977 kB (17%) ggc
inline heuristics : 0.02 ( 0%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 0 kB ( 0%) ggc
tree gimplify : 1.46 (13%) usr 0.14 ( 5%) sys 1.56 (11%) wall 88334 kB (21%) ggc
tree eh : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.01 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.05 ( 0%) usr 0.00 ( 0%) sys 0.05 ( 0%) wall 13199 kB ( 3%) ggc
tree CFG cleanup : 0.05 ( 0%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 0 kB ( 0%) ggc
tree find ref. vars : 0.05 ( 0%) usr 0.01 ( 0%) sys 0.05 ( 0%) wall 9130 kB ( 2%) ggc
tree PHI insertion : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.02 ( 0%) wall 189 kB ( 0%) ggc
tree SSA rewrite : 0.04 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 11835 kB ( 3%) ggc
tree SSA other : 0.06 ( 1%) usr 0.02 ( 1%) sys 0.12 ( 1%) wall 193 kB ( 0%) ggc
tree operand scan : 0.07 ( 1%) usr 0.03 ( 1%) sys 0.05 ( 0%) wall 7012 kB ( 2%) ggc
tree SSA to normal : 0.08 ( 1%) usr 0.00 ( 0%) sys 0.09 ( 1%) wall 448 kB ( 0%) ggc
dominance computation : 0.05 ( 0%) usr 0.01 ( 0%) sys 0.01 ( 0%) wall 0 kB ( 0%) ggc
expand : 1.80 (17%) usr 0.06 ( 2%) sys 1.65 (12%) wall 131397 kB (31%) ggc
varconst : 0.00 ( 0%) usr 0.01 ( 0%) sys 0.00 ( 0%) wall 24 kB ( 0%) ggc
integrated RA : 1.42 (13%) usr 0.01 ( 0%) sys 1.54 (11%) wall 3144 kB ( 1%) ggc
reload : 0.94 ( 9%) usr 0.01 ( 0%) sys 0.93 ( 7%) wall 17800 kB ( 4%) ggc
thread pro- & epilogue: 0.13 ( 1%) usr 0.00 ( 0%) sys 0.15 ( 1%) wall 342 kB ( 0%) ggc
final : 0.40 ( 4%) usr 0.01 ( 0%) sys 0.47 ( 3%) wall 2487 kB ( 1%) ggc
symout : 0.20 ( 2%) usr 0.02 ( 1%) sys 0.22 ( 2%) wall 22415 kB ( 5%) ggc
TOTAL : 10.83 3.03 13.90 429820 kB
glinka ~/tmp 16:41 %
Regards
--
Basile STARYNKEVITCH http://starynkevitch.net/Basile/
email: basile<at>starynkevitch<dot>net mobile: +33 6 8501 2359
8, rue de la Faiencerie, 92340 Bourg La Reine, France
*** opinions {are only mines, sont seulement les miennes} ***
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 15:43 ` Basile STARYNKEVITCH
@ 2009-11-06 15:49 ` Dave Korn
2009-11-06 16:00 ` Ian Lance Taylor
2009-11-06 16:37 ` Basile STARYNKEVITCH
1 sibling, 1 reply; 9+ messages in thread
From: Dave Korn @ 2009-11-06 15:49 UTC (permalink / raw)
To: Basile STARYNKEVITCH; +Cc: Ian Lance Taylor, GCC Mailing List
Basile STARYNKEVITCH wrote:
>>> Notice that gcc 4.4 is running four times slower that gcc-4.3!
> glinka ~/tmp 16:39 % gcc-4.3 -ftime-report -O0 -g -fPIC
> warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
>
> Execution times (seconds)
> TOTAL : 33.13 3.33
> 36.64 363506 kB
> glinka ~/tmp 16:40 % gcc-4.4 -ftime-report -O0 -g -fPIC
> warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
> TOTAL : 10.83 3.03
> 13.90 429820 kB
> glinka ~/tmp 16:41 %
Wait, what? :-P
Assuming you got those results swapped round, I see it's mostly expand and
global alloc. Side effect of IRA on functions with loooong unbroken sequences
of initialisations maybe?
cheers,
DaveK
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 15:49 ` Dave Korn
@ 2009-11-06 16:00 ` Ian Lance Taylor
2009-11-06 16:48 ` Basile STARYNKEVITCH
0 siblings, 1 reply; 9+ messages in thread
From: Ian Lance Taylor @ 2009-11-06 16:00 UTC (permalink / raw)
To: Dave Korn; +Cc: Basile STARYNKEVITCH, GCC Mailing List
Dave Korn <dave.korn.cygwin@googlemail.com> writes:
> Basile STARYNKEVITCH wrote:
>
>>>> Notice that gcc 4.4 is running four times slower that gcc-4.3!
>
>> glinka ~/tmp 16:39 % gcc-4.3 -ftime-report -O0 -g -fPIC
>> warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
>>
>> Execution times (seconds)
>> TOTAL : 33.13 3.33
>> 36.64 363506 kB
>
>> glinka ~/tmp 16:40 % gcc-4.4 -ftime-report -O0 -g -fPIC
>> warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
>> TOTAL : 10.83 3.03
>> 13.90 429820 kB
>> glinka ~/tmp 16:41 %
>
> Wait, what? :-P
>
>
> Assuming you got those results swapped round, I see it's mostly expand and
> global alloc. Side effect of IRA on functions with loooong unbroken sequences
> of initialisations maybe?
He didn't swap them--you can tell by the presence of "integrated RA"
rather than "global".
Basile, you posted the time for the wrong file, or you got something
else wrong.
Ian
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 15:43 ` Basile STARYNKEVITCH
2009-11-06 15:49 ` Dave Korn
@ 2009-11-06 16:37 ` Basile STARYNKEVITCH
1 sibling, 0 replies; 9+ messages in thread
From: Basile STARYNKEVITCH @ 2009-11-06 16:37 UTC (permalink / raw)
To: Ian Lance Taylor; +Cc: GCC Mailing List
Basile STARYNKEVITCH wrote:
> Ian Lance Taylor wrote:
>> Basile STARYNKEVITCH <basile@starynkevitch.net> writes:
>>
>>> Notice that gcc 4.4 is running four times slower that gcc-4.3!
>>
>> Use the -ftime-report option with both compilers to see where the time
>> is going.
>
> I also put the figures in the PR41971
Strangely, the timing varies widely from one run to another with the same compiler.
glinka ~/tmp 16:41 % time gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o 32.44s user 1.75s system 99% cpu 34.472 total
glinka ~/tmp 16:56 % time gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o 14.43s user 0.64s system 99% cpu 15.125 total
glinka ~/tmp 16:56 % time gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o 39.23s user 1.95s system 99% cpu 41.298 total
glinka ~/tmp 16:57 % time gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o 8.69s user 0.32s system 99% cpu 9.046 total
glinka ~/tmp 16:57 % time gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
gcc-4.4 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o 20.98s user 1.18s system 99% cpu 22.282 total
glinka ~/tmp 16:58 % time gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o 44.04s user 2.14s system 99% cpu 46.563 total
glinka ~/tmp 16:59 % time gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o 7.12s user 0.27s system 99% cpu 7.402 total
glinka ~/tmp 17:00 % time gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o 75.16s user 3.32s system 99% cpu 1:18.97 total
glinka ~/tmp 17:01 % time gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o 20.78s user 0.96s system 99% cpu 21.856 total
glinka ~/tmp 17:01 % time gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
gcc-4.3 -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o 7.11s user 0.32s system 99% cpu 7.442 total
I have no idea of what is happenning. (Maybe randomized address & malloc???) My desktop is not loaded (and is quadricore).
Regards.
--
Basile STARYNKEVITCH http://starynkevitch.net/Basile/
email: basile<at>starynkevitch<dot>net mobile: +33 6 8501 2359
8, rue de la Faiencerie, 92340 Bourg La Reine, France
*** opinions {are only mines, sont seulement les miennes} ***
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: very different compilation times [no optimisation]
2009-11-06 16:00 ` Ian Lance Taylor
@ 2009-11-06 16:48 ` Basile STARYNKEVITCH
0 siblings, 0 replies; 9+ messages in thread
From: Basile STARYNKEVITCH @ 2009-11-06 16:48 UTC (permalink / raw)
To: Ian Lance Taylor; +Cc: Dave Korn, GCC Mailing List
Ian Lance Taylor wrote:
> Basile, you posted the time for the wrong file, or you got something
> else wrong.
Here are other runs. The warmelt-normal-1.i is exactly the one uploaded in the bug report. Its md5sum is
944b6e0f8c6da76a7f0698e927fc4a60 warmelt-normal-1.i
And it does not seem to be some excess swapping. The cc1 process seems to eat half a gigabyte, and I have 8 gigabytes
(and mozilla, emacs, thunderbird don't eat all of them).
During a cc1
% free
total used free shared buffers cached
Mem: 8197136 5181216 3015920 0 1435412 1777752
-/+ buffers/cache: 1968052 6229084
Swap: 15141244 0 15141244
I checked on my wristwatch and the real timing is similar to the one reported by the computer (so its hardware clock is
apparently ok).
################ gcc 4.3
glinka ~/tmp 17:05 % time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
# cc1 18.90 0.97
# as 0.74 0.04
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3. 19.64s user 1.02s system 99% cpu 20.839 total
glinka ~/tmp 17:06 % time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
# cc1 6.36 0.28
# as 0.74 0.05
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3. 7.10s user 0.33s system 99% cpu 7.440 total
glinka ~/tmp 17:06 % time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
# cc1 8.78 0.67
# as 0.72 0.05
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3. 9.50s user 0.72s system 98% cpu 10.337 total
glinka ~/tmp 17:06 %
glinka ~/tmp 17:06 % time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
# cc1 6.28 0.34
# as 0.73 0.03
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3. 7.01s user 0.37s system 99% cpu 7.401 total
glinka ~/tmp 17:06 % time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
# cc1 67.33 2.92
# as 7.54 0.49
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3. 74.88s user 3.44s system 99% cpu 1:18.92
total
glinka ~/tmp 17:11 % time gcc-4.3 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
Execution times (seconds)
garbage collection : 0.10 ( 1%) usr 0.00 ( 0%) sys 0.10 ( 1%) wall 0 kB ( 0%) ggc
cfg cleanup : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 19 kB ( 0%) ggc
trivially dead code : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.10 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.07 ( 1%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 6838 kB ( 2%) ggc
register information : 0.10 ( 1%) usr 0.00 ( 0%) sys 0.09 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.04 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 2315 kB ( 1%) ggc
rebuild jump labels : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 0 kB ( 0%) ggc
preprocessing : 0.42 ( 6%) usr 0.22 (17%) sys 0.65 ( 8%) wall 24801 kB ( 7%) ggc
lexical analysis : 0.18 ( 3%) usr 0.57 (44%) sys 0.64 ( 8%) wall 0 kB ( 0%) ggc
parser : 0.86 (13%) usr 0.30 (23%) sys 1.29 (16%) wall 100081 kB (28%) ggc
inline heuristics : 0.21 ( 3%) usr 0.01 ( 1%) sys 0.23 ( 3%) wall 70 kB ( 0%) ggc
tree gimplify : 0.44 ( 7%) usr 0.03 ( 2%) sys 0.44 ( 5%) wall 58497 kB (16%) ggc
tree eh : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.07 ( 1%) usr 0.03 ( 2%) sys 0.10 ( 1%) wall 37602 kB (10%) ggc
tree CFG cleanup : 0.08 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
dominance computation : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 0 kB ( 0%) ggc
expand : 1.39 (21%) usr 0.05 ( 4%) sys 1.41 (18%) wall 89051 kB (24%) ggc
varconst : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.01 ( 0%) wall 92 kB ( 0%) ggc
jump : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.00 ( 0%) wall 0 kB ( 0%) ggc
local alloc : 0.55 ( 8%) usr 0.00 ( 0%) sys 0.61 ( 8%) wall 3032 kB ( 1%) ggc
global alloc : 1.22 (18%) usr 0.05 ( 4%) sys 1.25 (16%) wall 18079 kB ( 5%) ggc
thread pro- & epilogue: 0.11 ( 2%) usr 0.00 ( 0%) sys 0.13 ( 2%) wall 256 kB ( 0%) ggc
final : 0.43 ( 6%) usr 0.03 ( 2%) sys 0.45 ( 6%) wall 360 kB ( 0%) ggc
symout : 0.10 ( 1%) usr 0.01 ( 1%) sys 0.11 ( 1%) wall 21440 kB ( 6%) ggc
TOTAL : 6.73 1.30 8.05 363506 kB
gcc-4.3 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o 7.47s user 1.36s system 99% cpu 8.846 total
glinka ~/tmp 17:12 % time gcc-4.3 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.3.o
Execution times (seconds)
garbage collection : 0.99 ( 2%) usr 0.00 ( 0%) sys 0.99 ( 1%) wall 0 kB ( 0%) ggc
cfg cleanup : 0.58 ( 1%) usr 0.00 ( 0%) sys 0.62 ( 1%) wall 19 kB ( 0%) ggc
trivially dead code : 0.41 ( 1%) usr 0.00 ( 0%) sys 0.40 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.71 ( 1%) usr 0.02 ( 0%) sys 0.73 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.87 ( 1%) usr 0.01 ( 0%) sys 0.78 ( 1%) wall 6838 kB ( 2%) ggc
register information : 0.84 ( 1%) usr 0.00 ( 0%) sys 0.90 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.42 ( 1%) usr 0.00 ( 0%) sys 0.48 ( 1%) wall 2315 kB ( 1%) ggc
rebuild jump labels : 0.59 ( 1%) usr 0.00 ( 0%) sys 0.59 ( 1%) wall 0 kB ( 0%) ggc
preprocessing : 4.16 ( 6%) usr 2.28 (22%) sys 6.49 ( 9%) wall 24801 kB ( 7%) ggc
lexical analysis : 1.59 ( 2%) usr 3.88 (37%) sys 5.62 ( 7%) wall 0 kB ( 0%) ggc
parser : 7.16 (11%) usr 2.70 (26%) sys 9.69 (13%) wall 100081 kB (28%) ggc
inline heuristics : 2.02 ( 3%) usr 0.05 ( 0%) sys 2.12 ( 3%) wall 70 kB ( 0%) ggc
tree gimplify : 4.39 ( 7%) usr 0.33 ( 3%) sys 4.68 ( 6%) wall 58497 kB (16%) ggc
tree eh : 0.23 ( 0%) usr 0.00 ( 0%) sys 0.21 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.85 ( 1%) usr 0.10 ( 1%) sys 1.00 ( 1%) wall 37602 kB (10%) ggc
tree CFG cleanup : 0.55 ( 1%) usr 0.00 ( 0%) sys 0.55 ( 1%) wall 0 kB ( 0%) ggc
dominance computation : 0.21 ( 0%) usr 0.02 ( 0%) sys 0.28 ( 0%) wall 0 kB ( 0%) ggc
expand : 13.40 (21%) usr 0.66 ( 6%) sys 14.22 (19%) wall 89051 kB (24%) ggc
varconst : 0.06 ( 0%) usr 0.02 ( 0%) sys 0.03 ( 0%) wall 92 kB ( 0%) ggc
jump : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 0 kB ( 0%) ggc
local alloc : 6.01 ( 9%) usr 0.06 ( 1%) sys 5.94 ( 8%) wall 3032 kB ( 1%) ggc
global alloc : 12.39 (19%) usr 0.14 ( 1%) sys 12.66 (17%) wall 18079 kB ( 5%) ggc
thread pro- & epilogue: 1.05 ( 2%) usr 0.00 ( 0%) sys 1.16 ( 2%) wall 256 kB ( 0%) ggc
final : 4.01 ( 6%) usr 0.19 ( 2%) sys 4.20 ( 6%) wall 360 kB ( 0%) ggc
symout : 1.05 ( 2%) usr 0.07 ( 1%) sys 1.14 ( 2%) wall 21440 kB ( 6%) ggc
TOTAL : 64.60 10.53 75.56 363506 kB
gcc-4.3 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o 70.82s user 11.11s system 99% cpu 1:22.40 total
################### gcc 4.4
glinka ~/tmp 17:15 % time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
# cc1 14.78 0.84
# as 0.75 0.04
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4. 15.53s user 0.89s system 99% cpu 16.498 total
glinka ~/tmp 17:15 % time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
# cc1 71.20 2.06
# as 7.70 0.51
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4. 78.90s user 2.60s system 99% cpu 1:21.71
total
glinka ~/tmp 17:17 % time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
# cc1 85.06 2.72
# as 7.83 0.47
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4. 92.89s user 3.23s system 99% cpu 1:36.72
total
glinka ~/tmp 17:20 % time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
# cc1 49.80 2.12
# as 0.75 0.03
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4. 50.56s user 2.16s system 99% cpu 52.947 total
glinka ~/tmp 17:20 % time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
# cc1 34.11 1.02
# as 7.68 0.54
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4. 41.79s user 1.59s system 99% cpu 43.733 total
glinka ~/tmp 17:21 % time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
# cc1 84.43 2.72
# as 7.77 0.44
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4. 92.21s user 3.19s system 99% cpu 1:35.87
total
glinka ~/tmp 17:23 % time gcc-4.4 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
Execution times (seconds)
garbage collection : 1.08 ( 1%) usr 0.01 ( 0%) sys 1.09 ( 1%) wall 0 kB ( 0%) ggc
callgraph construction: 2.81 ( 3%) usr 0.12 ( 1%) sys 2.97 ( 3%) wall 13570 kB ( 3%) ggc
callgraph optimization: 0.46 ( 1%) usr 0.00 ( 0%) sys 0.50 ( 0%) wall 339 kB ( 0%) ggc
cfg cleanup : 0.46 ( 1%) usr 0.00 ( 0%) sys 0.48 ( 0%) wall 24 kB ( 0%) ggc
trivially dead code : 0.86 ( 1%) usr 0.00 ( 0%) sys 0.81 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.79 ( 1%) usr 0.02 ( 0%) sys 0.72 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 1.49 ( 2%) usr 0.03 ( 0%) sys 1.64 ( 2%) wall 6956 kB ( 2%) ggc
register information : 0.92 ( 1%) usr 0.01 ( 0%) sys 0.88 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.43 ( 0%) usr 0.00 ( 0%) sys 0.48 ( 0%) wall 2405 kB ( 1%) ggc
rebuild jump labels : 0.58 ( 1%) usr 0.00 ( 0%) sys 0.60 ( 1%) wall 0 kB ( 0%) ggc
preprocessing : 4.75 ( 5%) usr 2.84 (21%) sys 7.58 ( 7%) wall 25440 kB ( 6%) ggc
lexical analysis : 2.06 ( 2%) usr 5.45 (39%) sys 7.28 ( 7%) wall 0 kB ( 0%) ggc
parser : 6.08 ( 7%) usr 3.18 (23%) sys 9.44 ( 9%) wall 71977 kB (17%) ggc
inline heuristics : 0.50 ( 1%) usr 0.02 ( 0%) sys 0.49 ( 0%) wall 0 kB ( 0%) ggc
tree gimplify : 10.00 (11%) usr 0.38 ( 3%) sys 10.58 (10%) wall 88334 kB (21%) ggc
tree eh : 0.18 ( 0%) usr 0.00 ( 0%) sys 0.20 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.54 ( 1%) usr 0.05 ( 0%) sys 0.62 ( 1%) wall 13199 kB ( 3%) ggc
tree CFG cleanup : 0.66 ( 1%) usr 0.00 ( 0%) sys 0.56 ( 1%) wall 0 kB ( 0%) ggc
tree find ref. vars : 0.43 ( 0%) usr 0.05 ( 0%) sys 0.55 ( 1%) wall 9130 kB ( 2%) ggc
tree PHI insertion : 0.12 ( 0%) usr 0.00 ( 0%) sys 0.14 ( 0%) wall 189 kB ( 0%) ggc
tree SSA rewrite : 0.19 ( 0%) usr 0.05 ( 0%) sys 0.24 ( 0%) wall 11835 kB ( 3%) ggc
tree SSA other : 0.76 ( 1%) usr 0.24 ( 2%) sys 1.05 ( 1%) wall 193 kB ( 0%) ggc
tree operand scan : 0.58 ( 1%) usr 0.27 ( 2%) sys 0.77 ( 1%) wall 7012 kB ( 2%) ggc
tree SSA to normal : 1.08 ( 1%) usr 0.00 ( 0%) sys 1.01 ( 1%) wall 448 kB ( 0%) ggc
dominance frontiers : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.01 ( 0%) wall 0 kB ( 0%) ggc
dominance computation : 0.44 ( 0%) usr 0.01 ( 0%) sys 0.41 ( 0%) wall 0 kB ( 0%) ggc
expand : 17.52 (20%) usr 0.39 ( 3%) sys 18.22 (18%) wall 131397 kB (31%) ggc
varconst : 0.00 ( 0%) usr 0.00 ( 0%) sys 0.01 ( 0%) wall 24 kB ( 0%) ggc
jump : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.02 ( 0%) wall 0 kB ( 0%) ggc
integrated RA : 16.00 (18%) usr 0.11 ( 1%) sys 16.10 (16%) wall 3144 kB ( 1%) ggc
reload : 9.56 (11%) usr 0.17 ( 1%) sys 9.74 ( 9%) wall 17800 kB ( 4%) ggc
thread pro- & epilogue: 1.44 ( 2%) usr 0.00 ( 0%) sys 1.51 ( 1%) wall 342 kB ( 0%) ggc
final : 4.81 ( 5%) usr 0.26 ( 2%) sys 5.04 ( 5%) wall 2487 kB ( 1%) ggc
symout : 1.17 ( 1%) usr 0.09 ( 1%) sys 1.29 ( 1%) wall 22415 kB ( 5%) ggc
rest of compilation : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.00 ( 0%) wall 0 kB ( 0%) ggc
TOTAL : 88.87 13.85 103.23 429820 kB
gcc-4.4 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o 96.57s user 14.64s system 99% cpu 1:51.80 total
glinka ~/tmp 17:25 % time gcc-4.4 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
Execution times (seconds)
garbage collection : 1.07 ( 2%) usr 0.00 ( 0%) sys 1.08 ( 1%) wall 0 kB ( 0%) ggc
callgraph construction: 2.78 ( 5%) usr 0.08 ( 1%) sys 2.95 ( 4%) wall 13570 kB ( 3%) ggc
callgraph optimization: 0.44 ( 1%) usr 0.00 ( 0%) sys 0.46 ( 1%) wall 339 kB ( 0%) ggc
cfg cleanup : 0.11 ( 0%) usr 0.00 ( 0%) sys 0.12 ( 0%) wall 24 kB ( 0%) ggc
trivially dead code : 0.56 ( 1%) usr 0.00 ( 0%) sys 0.48 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.30 ( 0%) usr 0.00 ( 0%) sys 0.33 ( 0%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.67 ( 1%) usr 0.00 ( 0%) sys 0.72 ( 1%) wall 6956 kB ( 2%) ggc
register information : 0.44 ( 1%) usr 0.00 ( 0%) sys 0.45 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.31 ( 1%) usr 0.00 ( 0%) sys 0.29 ( 0%) wall 2405 kB ( 1%) ggc
rebuild jump labels : 0.34 ( 1%) usr 0.00 ( 0%) sys 0.33 ( 0%) wall 0 kB ( 0%) ggc
preprocessing : 4.59 ( 7%) usr 2.77 (21%) sys 7.63 (10%) wall 25440 kB ( 6%) ggc
lexical analysis : 2.11 ( 3%) usr 5.31 (40%) sys 7.55 (10%) wall 0 kB ( 0%) ggc
parser : 6.32 (10%) usr 3.19 (24%) sys 9.15 (12%) wall 71977 kB (17%) ggc
inline heuristics : 0.48 ( 1%) usr 0.00 ( 0%) sys 0.49 ( 1%) wall 0 kB ( 0%) ggc
tree gimplify : 9.69 (16%) usr 0.55 ( 4%) sys 10.26 (14%) wall 88334 kB (21%) ggc
tree eh : 0.22 ( 0%) usr 0.01 ( 0%) sys 0.18 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.56 ( 1%) usr 0.06 ( 0%) sys 0.64 ( 1%) wall 13199 kB ( 3%) ggc
tree CFG cleanup : 0.53 ( 1%) usr 0.01 ( 0%) sys 0.56 ( 1%) wall 0 kB ( 0%) ggc
tree find ref. vars : 0.46 ( 1%) usr 0.03 ( 0%) sys 0.51 ( 1%) wall 9130 kB ( 2%) ggc
tree PHI insertion : 0.12 ( 0%) usr 0.01 ( 0%) sys 0.09 ( 0%) wall 189 kB ( 0%) ggc
tree SSA rewrite : 0.21 ( 0%) usr 0.07 ( 1%) sys 0.34 ( 0%) wall 11835 kB ( 3%) ggc
tree SSA other : 0.72 ( 1%) usr 0.19 ( 1%) sys 0.92 ( 1%) wall 193 kB ( 0%) ggc
tree operand scan : 0.65 ( 1%) usr 0.29 ( 2%) sys 0.86 ( 1%) wall 7012 kB ( 2%) ggc
tree SSA to normal : 0.49 ( 1%) usr 0.00 ( 0%) sys 0.43 ( 1%) wall 448 kB ( 0%) ggc
dominance frontiers : 0.02 ( 0%) usr 0.00 ( 0%) sys 0.02 ( 0%) wall 0 kB ( 0%) ggc
dominance computation : 0.35 ( 1%) usr 0.02 ( 0%) sys 0.38 ( 1%) wall 0 kB ( 0%) ggc
expand : 10.54 (17%) usr 0.25 ( 2%) sys 10.81 (14%) wall 131397 kB (31%) ggc
varconst : 0.02 ( 0%) usr 0.02 ( 0%) sys 0.01 ( 0%) wall 24 kB ( 0%) ggc
jump : 0.02 ( 0%) usr 0.00 ( 0%) sys 0.00 ( 0%) wall 0 kB ( 0%) ggc
integrated RA : 8.97 (15%) usr 0.06 ( 0%) sys 9.20 (12%) wall 3144 kB ( 1%) ggc
reload : 4.19 ( 7%) usr 0.05 ( 0%) sys 4.28 ( 6%) wall 17800 kB ( 4%) ggc
thread pro- & epilogue: 0.54 ( 1%) usr 0.00 ( 0%) sys 0.60 ( 1%) wall 342 kB ( 0%) ggc
final : 2.42 ( 4%) usr 0.19 ( 1%) sys 2.48 ( 3%) wall 2487 kB ( 1%) ggc
symout : 0.25 ( 0%) usr 0.02 ( 0%) sys 0.42 ( 1%) wall 22415 kB ( 5%) ggc
TOTAL : 61.55 13.28 75.18 429820 kB
gcc-4.4 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o 62.30s user 13.36s system 99% cpu 1:16.00 total
glinka ~/tmp 17:27 % time gcc-4.4 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-1-gcc-4.4.o
Execution times (seconds)
garbage collection : 1.07 ( 3%) usr 0.00 ( 0%) sys 1.08 ( 2%) wall 0 kB ( 0%) ggc
callgraph construction: 2.75 ( 7%) usr 0.08 ( 2%) sys 2.92 ( 6%) wall 13570 kB ( 3%) ggc
callgraph optimization: 0.45 ( 1%) usr 0.00 ( 0%) sys 0.47 ( 1%) wall 339 kB ( 0%) ggc
cfg cleanup : 0.08 ( 0%) usr 0.00 ( 0%) sys 0.12 ( 0%) wall 24 kB ( 0%) ggc
trivially dead code : 0.42 ( 1%) usr 0.00 ( 0%) sys 0.42 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.35 ( 1%) usr 0.00 ( 0%) sys 0.35 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.57 ( 1%) usr 0.00 ( 0%) sys 0.66 ( 1%) wall 6956 kB ( 2%) ggc
register information : 0.29 ( 1%) usr 0.00 ( 0%) sys 0.28 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.18 ( 0%) usr 0.00 ( 0%) sys 0.18 ( 0%) wall 2405 kB ( 1%) ggc
rebuild jump labels : 0.32 ( 1%) usr 0.00 ( 0%) sys 0.31 ( 1%) wall 0 kB ( 0%) ggc
preprocessing : 0.88 ( 2%) usr 0.64 (16%) sys 1.56 ( 3%) wall 25440 kB ( 6%) ggc
lexical analysis : 0.53 ( 1%) usr 1.14 (29%) sys 1.80 ( 4%) wall 0 kB ( 0%) ggc
parser : 1.45 ( 3%) usr 0.72 (18%) sys 2.04 ( 4%) wall 71977 kB (17%) ggc
inline heuristics : 0.45 ( 1%) usr 0.00 ( 0%) sys 0.45 ( 1%) wall 0 kB ( 0%) ggc
tree gimplify : 2.68 ( 6%) usr 0.22 ( 6%) sys 2.88 ( 6%) wall 88334 kB (21%) ggc
tree eh : 0.18 ( 0%) usr 0.00 ( 0%) sys 0.20 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.68 ( 2%) usr 0.04 ( 1%) sys 0.61 ( 1%) wall 13199 kB ( 3%) ggc
tree CFG cleanup : 0.56 ( 1%) usr 0.00 ( 0%) sys 0.58 ( 1%) wall 0 kB ( 0%) ggc
tree find ref. vars : 0.52 ( 1%) usr 0.02 ( 1%) sys 0.54 ( 1%) wall 9130 kB ( 2%) ggc
tree PHI insertion : 0.09 ( 0%) usr 0.00 ( 0%) sys 0.11 ( 0%) wall 189 kB ( 0%) ggc
tree SSA rewrite : 0.23 ( 1%) usr 0.04 ( 1%) sys 0.27 ( 1%) wall 11835 kB ( 3%) ggc
tree SSA other : 0.57 ( 1%) usr 0.20 ( 5%) sys 1.01 ( 2%) wall 193 kB ( 0%) ggc
tree operand scan : 0.71 ( 2%) usr 0.37 ( 9%) sys 0.81 ( 2%) wall 7012 kB ( 2%) ggc
tree SSA to normal : 0.42 ( 1%) usr 0.00 ( 0%) sys 0.45 ( 1%) wall 448 kB ( 0%) ggc
dominance frontiers : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
dominance computation : 0.25 ( 1%) usr 0.03 ( 1%) sys 0.33 ( 1%) wall 0 kB ( 0%) ggc
expand : 10.54 (25%) usr 0.21 ( 5%) sys 10.63 (23%) wall 131397 kB (31%) ggc
varconst : 0.00 ( 0%) usr 0.01 ( 0%) sys 0.00 ( 0%) wall 24 kB ( 0%) ggc
jump : 0.04 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
integrated RA : 7.38 (18%) usr 0.01 ( 0%) sys 7.45 (16%) wall 3144 kB ( 1%) ggc
reload : 4.11 (10%) usr 0.01 ( 0%) sys 4.06 ( 9%) wall 17800 kB ( 4%) ggc
thread pro- & epilogue: 0.59 ( 1%) usr 0.00 ( 0%) sys 0.58 ( 1%) wall 342 kB ( 0%) ggc
reg stack : 0.00 ( 0%) usr 0.01 ( 0%) sys 0.00 ( 0%) wall 0 kB ( 0%) ggc
final : 2.38 ( 6%) usr 0.15 ( 4%) sys 2.50 ( 5%) wall 2487 kB ( 1%) ggc
symout : 0.25 ( 1%) usr 0.03 ( 1%) sys 0.26 ( 1%) wall 22415 kB ( 5%) ggc
TOTAL : 42.02 3.93 46.03 429820 kB
gcc-4.4 -ftime-report -O0 -g -fPIC warmelt-normal-1.i -c -o 42.77s user 3.99s system 99% cpu 46.832 total
####
The widely different figures from one run to the next are surprising.
Here are the figures on my laptop Ubuntu Karmic AMD64 (dual-core Intel Core 2 P9500 at 2.53Ghz)
time gcc-4.2 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.2.o
# cc1 5.39 0.31
# as 0.74 0.07
gcc-4.2 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.2.o 6.13s user 0.38s system 99% cpu 6.525 total
time gcc-4.2 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.2.o
# cc1 5.35 0.35
# as 0.75 0.05
gcc-4.2 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.2.o 6.10s user 0.41s system 100% cpu 6.508 total
time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o
# cc1 6.79 0.36
# as 0.79 0.03
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o 7.58s user 0.39s system 99% cpu 7.995 total
time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o
# cc1 6.80 0.31
# as 0.77 0.06
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o 7.57s user 0.37s system 99% cpu 7.965 total
time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o -ftime-report
Execution times (seconds)
garbage collection : 0.10 ( 1%) usr 0.00 ( 0%) sys 0.10 ( 1%) wall 0 kB ( 0%) ggc
cfg cleanup : 0.04 ( 1%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 19 kB ( 0%) ggc
trivially dead code : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.09 ( 1%) usr 0.00 ( 0%) sys 0.09 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.07 ( 1%) usr 0.02 ( 2%) sys 0.09 ( 1%) wall 6838 kB ( 2%) ggc
register information : 0.08 ( 1%) usr 0.01 ( 1%) sys 0.09 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.04 ( 1%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 2315 kB ( 1%) ggc
rebuild jump labels : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 1%) wall 0 kB ( 0%) ggc
preprocessing : 0.42 ( 6%) usr 0.17 (15%) sys 0.57 ( 7%) wall 24801 kB ( 7%) ggc
lexical analysis : 0.24 ( 3%) usr 0.39 (35%) sys 0.64 ( 8%) wall 0 kB ( 0%) ggc
parser : 1.00 (14%) usr 0.19 (17%) sys 1.20 (15%) wall 100143 kB (28%) ggc
inline heuristics : 0.21 ( 3%) usr 0.01 ( 1%) sys 0.22 ( 3%) wall 70 kB ( 0%) ggc
tree gimplify : 0.53 ( 7%) usr 0.04 ( 4%) sys 0.57 ( 7%) wall 58497 kB (16%) ggc
tree eh : 0.02 ( 0%) usr 0.00 ( 0%) sys 0.02 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.08 ( 1%) usr 0.03 ( 3%) sys 0.11 ( 1%) wall 37602 kB (10%) ggc
tree CFG cleanup : 0.03 ( 0%) usr 0.02 ( 2%) sys 0.05 ( 1%) wall 0 kB ( 0%) ggc
dominance computation : 0.02 ( 0%) usr 0.00 ( 0%) sys 0.02 ( 0%) wall 0 kB ( 0%) ggc
expand : 1.44 (20%) usr 0.12 (11%) sys 1.56 (19%) wall 89055 kB (24%) ggc
local alloc : 0.62 ( 9%) usr 0.02 ( 2%) sys 0.64 ( 8%) wall 3032 kB ( 1%) ggc
global alloc : 1.31 (18%) usr 0.03 ( 3%) sys 1.34 (16%) wall 18079 kB ( 5%) ggc
thread pro- & epilogue: 0.11 ( 2%) usr 0.00 ( 0%) sys 0.11 ( 1%) wall 256 kB ( 0%) ggc
final : 0.49 ( 7%) usr 0.02 ( 2%) sys 0.51 ( 6%) wall 360 kB ( 0%) ggc
symout : 0.10 ( 1%) usr 0.03 ( 3%) sys 0.13 ( 2%) wall 21440 kB ( 6%) ggc
TOTAL : 7.14 1.12 8.26 363573 kB
# cc1 7.14 1.15
# as 0.79 0.02
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o 7.93s user 1.17s system 99% cpu 9.118 total
time gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o -ftime-report
Execution times (seconds)
garbage collection : 0.10 ( 1%) usr 0.00 ( 0%) sys 0.10 ( 1%) wall 0 kB ( 0%) ggc
cfg cleanup : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 19 kB ( 0%) ggc
trivially dead code : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.08 ( 1%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.08 ( 1%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 6838 kB ( 2%) ggc
register information : 0.09 ( 1%) usr 0.00 ( 0%) sys 0.09 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.04 ( 1%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 2315 kB ( 1%) ggc
rebuild jump labels : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
preprocessing : 0.46 ( 6%) usr 0.24 (22%) sys 0.66 ( 8%) wall 24801 kB ( 7%) ggc
lexical analysis : 0.18 ( 2%) usr 0.38 (36%) sys 0.59 ( 7%) wall 0 kB ( 0%) ggc
parser : 1.00 (14%) usr 0.26 (24%) sys 1.28 (15%) wall 100143 kB (28%) ggc
inline heuristics : 0.28 ( 4%) usr 0.01 ( 1%) sys 0.29 ( 4%) wall 70 kB ( 0%) ggc
tree gimplify : 0.55 ( 8%) usr 0.03 ( 3%) sys 0.58 ( 7%) wall 58497 kB (16%) ggc
tree eh : 0.02 ( 0%) usr 0.01 ( 1%) sys 0.02 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.08 ( 1%) usr 0.01 ( 1%) sys 0.09 ( 1%) wall 37602 kB (10%) ggc
tree CFG cleanup : 0.04 ( 1%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 0 kB ( 0%) ggc
dominance computation : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
expand : 1.44 (20%) usr 0.09 ( 8%) sys 1.53 (18%) wall 89055 kB (24%) ggc
local alloc : 0.64 ( 9%) usr 0.00 ( 0%) sys 0.64 ( 8%) wall 3032 kB ( 1%) ggc
global alloc : 1.30 (18%) usr 0.01 ( 1%) sys 1.31 (16%) wall 18079 kB ( 5%) ggc
thread pro- & epilogue: 0.13 ( 2%) usr 0.00 ( 0%) sys 0.13 ( 2%) wall 256 kB ( 0%) ggc
final : 0.37 ( 5%) usr 0.00 ( 0%) sys 0.37 ( 4%) wall 360 kB ( 0%) ggc
symout : 0.10 ( 1%) usr 0.01 ( 1%) sys 0.11 ( 1%) wall 21440 kB ( 6%) ggc
TOTAL : 7.21 1.07 8.28 363573 kB
# cc1 7.21 1.10
# as 0.76 0.05
gcc-4.3 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.3.o 7.97s user 1.16s system 100% cpu 9.130 total
time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o
# cc1 8.59 0.26
# as 0.77 0.06
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o 9.36s user 0.32s system 99% cpu 9.685 total
time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o
# cc1 8.43 0.45
# as 0.79 0.05
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o 9.22s user 0.50s system 99% cpu 9.731 total
time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o -ftime-report
Execution times (seconds)
garbage collection : 0.10 ( 1%) usr 0.00 ( 0%) sys 0.10 ( 1%) wall 0 kB ( 0%) ggc
callgraph construction: 0.29 ( 3%) usr 0.02 ( 2%) sys 0.31 ( 3%) wall 13570 kB ( 3%) ggc
callgraph optimization: 0.04 ( 0%) usr 0.00 ( 0%) sys 0.04 ( 0%) wall 339 kB ( 0%) ggc
cfg cleanup : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 0%) wall 24 kB ( 0%) ggc
trivially dead code : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.05 ( 1%) usr 0.01 ( 1%) sys 0.06 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.15 ( 2%) usr 0.00 ( 0%) sys 0.15 ( 1%) wall 6957 kB ( 2%) ggc
register information : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 2405 kB ( 1%) ggc
rebuild jump labels : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 0%) wall 0 kB ( 0%) ggc
preprocessing : 0.56 ( 6%) usr 0.17 (16%) sys 0.75 ( 7%) wall 25440 kB ( 6%) ggc
lexical analysis : 0.18 ( 2%) usr 0.40 (38%) sys 0.59 ( 6%) wall 0 kB ( 0%) ggc
parser : 0.55 ( 6%) usr 0.30 (28%) sys 0.82 ( 8%) wall 72039 kB (17%) ggc
inline heuristics : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
tree gimplify : 0.96 (11%) usr 0.03 ( 3%) sys 0.99 (10%) wall 88334 kB (21%) ggc
tree eh : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.01 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 13199 kB ( 3%) ggc
tree CFG cleanup : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
tree find ref. vars : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 9130 kB ( 2%) ggc
tree PHI insertion : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.01 ( 0%) wall 189 kB ( 0%) ggc
tree SSA rewrite : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 11835 kB ( 3%) ggc
tree SSA other : 0.06 ( 1%) usr 0.04 ( 4%) sys 0.10 ( 1%) wall 193 kB ( 0%) ggc
tree operand scan : 0.06 ( 1%) usr 0.03 ( 3%) sys 0.09 ( 1%) wall 7012 kB ( 2%) ggc
tree SSA to normal : 0.11 ( 1%) usr 0.00 ( 0%) sys 0.11 ( 1%) wall 448 kB ( 0%) ggc
dominance computation : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
expand : 1.88 (21%) usr 0.01 ( 1%) sys 1.89 (19%) wall 131416 kB (31%) ggc
integrated RA : 1.68 (19%) usr 0.00 ( 0%) sys 1.68 (17%) wall 3144 kB ( 1%) ggc
reload : 0.99 (11%) usr 0.00 ( 0%) sys 0.99 (10%) wall 17785 kB ( 4%) ggc
thread pro- & epilogue: 0.13 ( 1%) usr 0.00 ( 0%) sys 0.13 ( 1%) wall 342 kB ( 0%) ggc
final : 0.43 ( 5%) usr 0.02 ( 2%) sys 0.45 ( 4%) wall 2487 kB ( 1%) ggc
symout : 0.11 ( 1%) usr 0.01 ( 1%) sys 0.12 ( 1%) wall 22415 kB ( 5%) ggc
TOTAL : 8.95 1.06 10.01 429887 kB
# cc1 8.96 1.09
# as 0.77 0.06
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o 9.73s user 1.15s system 99% cpu 10.901 total
time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o -ftime-report
Execution times (seconds)
garbage collection : 0.11 ( 1%) usr 0.00 ( 0%) sys 0.11 ( 1%) wall 0 kB ( 0%) ggc
callgraph construction: 0.31 ( 4%) usr 0.00 ( 0%) sys 0.31 ( 3%) wall 13570 kB ( 3%) ggc
callgraph optimization: 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 339 kB ( 0%) ggc
cfg cleanup : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 1%) wall 24 kB ( 0%) ggc
trivially dead code : 0.08 ( 1%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.15 ( 2%) usr 0.00 ( 0%) sys 0.15 ( 2%) wall 6957 kB ( 2%) ggc
register information : 0.08 ( 1%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 1%) wall 2405 kB ( 1%) ggc
rebuild jump labels : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
preprocessing : 0.37 ( 4%) usr 0.19 (16%) sys 0.56 ( 6%) wall 25440 kB ( 6%) ggc
lexical analysis : 0.21 ( 2%) usr 0.36 (31%) sys 0.63 ( 6%) wall 0 kB ( 0%) ggc
parser : 0.63 ( 7%) usr 0.33 (28%) sys 0.90 ( 9%) wall 72039 kB (17%) ggc
inline heuristics : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
tree gimplify : 1.03 (12%) usr 0.06 ( 5%) sys 1.09 (11%) wall 88334 kB (21%) ggc
tree eh : 0.02 ( 0%) usr 0.00 ( 0%) sys 0.02 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.04 ( 0%) usr 0.01 ( 1%) sys 0.05 ( 1%) wall 13199 kB ( 3%) ggc
tree CFG cleanup : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
tree find ref. vars : 0.03 ( 0%) usr 0.01 ( 1%) sys 0.04 ( 0%) wall 9130 kB ( 2%) ggc
tree PHI insertion : 0.02 ( 0%) usr 0.00 ( 0%) sys 0.02 ( 0%) wall 189 kB ( 0%) ggc
tree SSA rewrite : 0.01 ( 0%) usr 0.02 ( 2%) sys 0.03 ( 0%) wall 11835 kB ( 3%) ggc
tree SSA other : 0.04 ( 0%) usr 0.04 ( 3%) sys 0.07 ( 1%) wall 193 kB ( 0%) ggc
tree operand scan : 0.05 ( 1%) usr 0.04 ( 3%) sys 0.10 ( 1%) wall 7012 kB ( 2%) ggc
tree SSA to normal : 0.11 ( 1%) usr 0.00 ( 0%) sys 0.11 ( 1%) wall 448 kB ( 0%) ggc
dominance computation : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
expand : 1.79 (20%) usr 0.03 ( 3%) sys 1.82 (18%) wall 131416 kB (31%) ggc
integrated RA : 1.60 (18%) usr 0.01 ( 1%) sys 1.61 (16%) wall 3144 kB ( 1%) ggc
reload : 0.98 (11%) usr 0.04 ( 3%) sys 1.02 (10%) wall 17785 kB ( 4%) ggc
thread pro- & epilogue: 0.12 ( 1%) usr 0.00 ( 0%) sys 0.12 ( 1%) wall 342 kB ( 0%) ggc
final : 0.47 ( 5%) usr 0.01 ( 1%) sys 0.48 ( 5%) wall 2487 kB ( 1%) ggc
symout : 0.14 ( 2%) usr 0.00 ( 0%) sys 0.14 ( 1%) wall 22415 kB ( 5%) ggc
TOTAL : 8.82 1.17 9.99 429887 kB
# cc1 8.83 1.20
# as 0.79 0.04
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o 9.62s user 1.24s system 99% cpu 10.861 total
time gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o -ftime-report
Execution times (seconds)
garbage collection : 0.11 ( 1%) usr 0.00 ( 0%) sys 0.11 ( 1%) wall 0 kB ( 0%) ggc
callgraph construction: 0.24 ( 3%) usr 0.03 ( 3%) sys 0.27 ( 3%) wall 13570 kB ( 3%) ggc
callgraph optimization: 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 339 kB ( 0%) ggc
cfg cleanup : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 24 kB ( 0%) ggc
trivially dead code : 0.09 ( 1%) usr 0.00 ( 0%) sys 0.09 ( 1%) wall 0 kB ( 0%) ggc
df live regs : 0.09 ( 1%) usr 0.00 ( 0%) sys 0.09 ( 1%) wall 0 kB ( 0%) ggc
df reg dead/unused notes: 0.14 ( 2%) usr 0.00 ( 0%) sys 0.14 ( 1%) wall 6957 kB ( 2%) ggc
register information : 0.07 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 0 kB ( 0%) ggc
alias analysis : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 2405 kB ( 1%) ggc
rebuild jump labels : 0.05 ( 1%) usr 0.00 ( 0%) sys 0.05 ( 0%) wall 0 kB ( 0%) ggc
preprocessing : 0.49 ( 5%) usr 0.17 (16%) sys 0.74 ( 7%) wall 25440 kB ( 6%) ggc
lexical analysis : 0.27 ( 3%) usr 0.43 (39%) sys 0.65 ( 6%) wall 0 kB ( 0%) ggc
parser : 0.53 ( 6%) usr 0.21 (19%) sys 0.71 ( 7%) wall 72039 kB (17%) ggc
inline heuristics : 0.03 ( 0%) usr 0.00 ( 0%) sys 0.03 ( 0%) wall 0 kB ( 0%) ggc
tree gimplify : 1.00 (11%) usr 0.06 ( 6%) sys 1.06 (11%) wall 88334 kB (21%) ggc
tree eh : 0.01 ( 0%) usr 0.00 ( 0%) sys 0.01 ( 0%) wall 0 kB ( 0%) ggc
tree CFG construction : 0.06 ( 1%) usr 0.01 ( 1%) sys 0.07 ( 1%) wall 13199 kB ( 3%) ggc
tree CFG cleanup : 0.08 ( 1%) usr 0.00 ( 0%) sys 0.08 ( 1%) wall 0 kB ( 0%) ggc
tree find ref. vars : 0.04 ( 0%) usr 0.01 ( 1%) sys 0.05 ( 0%) wall 9130 kB ( 2%) ggc
tree SSA rewrite : 0.03 ( 0%) usr 0.01 ( 1%) sys 0.04 ( 0%) wall 11835 kB ( 3%) ggc
tree SSA other : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.07 ( 1%) wall 193 kB ( 0%) ggc
tree operand scan : 0.07 ( 1%) usr 0.03 ( 3%) sys 0.09 ( 1%) wall 7012 kB ( 2%) ggc
tree SSA to normal : 0.09 ( 1%) usr 0.00 ( 0%) sys 0.09 ( 1%) wall 448 kB ( 0%) ggc
dominance computation : 0.06 ( 1%) usr 0.00 ( 0%) sys 0.06 ( 1%) wall 0 kB ( 0%) ggc
expand : 1.69 (19%) usr 0.06 ( 6%) sys 1.75 (17%) wall 131416 kB (31%) ggc
integrated RA : 1.64 (18%) usr 0.01 ( 1%) sys 1.65 (16%) wall 3144 kB ( 1%) ggc
reload : 1.01 (11%) usr 0.02 ( 2%) sys 1.03 (10%) wall 17785 kB ( 4%) ggc
thread pro- & epilogue: 0.15 ( 2%) usr 0.00 ( 0%) sys 0.15 ( 1%) wall 342 kB ( 0%) ggc
final : 0.55 ( 6%) usr 0.00 ( 0%) sys 0.55 ( 5%) wall 2487 kB ( 1%) ggc
symout : 0.11 ( 1%) usr 0.02 ( 2%) sys 0.13 ( 1%) wall 22415 kB ( 5%) ggc
TOTAL : 8.95 1.09 10.04 429887 kB
# cc1 8.95 1.12
# as 0.76 0.08
gcc-4.4 -time -O0 -g -fPIC warmelt-normal-1.i -c -o warmelt-normal-4.4.o 9.71s user 1.20s system 99% cpu 10.915 total
##
So I don't understand what happens to me. Perhaps I have two different brands of RAM on my desktop???
Anyway, you can retrieve the warmelt-normal-1.i file from the bug report PR41971 and try yourself.
Regards.
--
Basile STARYNKEVITCH http://starynkevitch.net/Basile/
email: basile<at>starynkevitch<dot>net mobile: +33 6 8501 2359
8, rue de la Faiencerie, 92340 Bourg La Reine, France
*** opinions {are only mines, sont seulement les miennes} ***
^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2009-11-06 16:48 UTC | newest]
Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2009-11-06 15:04 very different compilation times [no optimisation] Basile STARYNKEVITCH
2009-11-06 15:16 ` Dave Korn
2009-11-06 15:36 ` Basile STARYNKEVITCH
2009-11-06 15:35 ` Ian Lance Taylor
2009-11-06 15:43 ` Basile STARYNKEVITCH
2009-11-06 15:49 ` Dave Korn
2009-11-06 16:00 ` Ian Lance Taylor
2009-11-06 16:48 ` Basile STARYNKEVITCH
2009-11-06 16:37 ` Basile STARYNKEVITCH
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).