very different compilation times [no optimisation]

[Basile STARYNKEVITCH <basile at starynkevitch dot net>]

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} ***