Profiling ecj (was: Using the natively-built Eclipse compiler)

[Ziga Mahkovec]

I upgraded to libgcj-4.0.0-0.32 and eclipse-ecj-3.1.0_fc-0.M5.12.
The results for compiling classpath:

ecj                |  ecj-native         |  jikes
-------------------------------------------------------------
real    1m31.786s  |  real    0m16.207s  |  real    0m8.423s
user    1m22.796s  |  user    0m14.925s  |  user    0m7.052s
sys     0m1.369s   |  sys     0m1.020s   |  sys     0m0.755s

(ecj-native went from 24.5s to 16.2s as a result of -O2)

I also uploaded oprofiles for ecj[1], ecj-native[2] and ecj-native-with-
the-old-gcjlib-tools-jar[3].

Note that I'm running a Centrino so the oprofile driver falls back to
timer interrupt mode.

[1] http://www.bootchart.org/misc/ecj/M5.12/opreport.ecj.log
[2] http://www.bootchart.org/misc/ecj/M5.12/opreport.ecj-native.log
[3] http://www.bootchart.org/misc/ecj/M5.12/opreport.ecj-native-gcjlib.log

[Andrew Haley]

Ziga Mahkovec writes:
> I upgraded to libgcj-4.0.0-0.32 and eclipse-ecj-3.1.0_fc-0.M5.12.
> The results for compiling classpath:
> ecj                |  ecj-native         |  jikes
>
> real    1m31.786s  |  real    0m16.207s  |  real    0m8.423s
> user    1m22.796s  |  user    0m14.925s  |  user    0m7.052s
> sys     0m1.369s   |  sys     0m1.020s   |  sys     0m0.755s
>
> (ecj-native went from 24.5s to 16.2s as a result of -O2)
>
> I also uploaded oprofiles for ecj[1], ecj-native[2] and ecj-native-with-
> the-old-gcjlib-tools-jar[3].
>
> Note that I'm running a Centrino so the oprofile driver falls back to
> timer interrupt mode.
>
> [1] http://www.bootchart.org/misc/ecj/M5.12/opreport.ecj.log
> [2] http://www.bootchart.org/misc/ecj/M5.12/opreport.ecj-native.log
> [3] http://www.bootchart.org/misc/ecj/M5.12/opreport.ecj-native-gcjlib.log

Thank you very much for doing this.  It's very useful.

Jikes is famously fast, so I'm fairly pleased to see we're close.

It says here: "[Jikes] is astoundingly fast -- hundreds of thousands
of lines of code per minute (about ten times faster than other
compilers)"

There are some surprises here.  Is ecj fully interpreted code?
_Jv_InterpMethod::run seems only to take 0.0036% of the time.  I'm
going to investigate some more.

I'm sure that ecj-native isn't purely native code, because of this line:

399       2.2024  libgcj.so.6.0.0          _Jv_BytecodeVerifier::verify_instructions_0()

which is weird.

Thanks again,
Andrew.

[Andrew Overholt]

Hi,

I decided to do something similar to what Ziga had done.  I took his
HelloWorld.java [1] and compiled it with three incarnations of ecj:

1. java-gcj-compat's javac
2. an ecj made as in [2]
3. an ecj made as in [3]

Quick and dirty results (see [4] for details):

(average of 5 runs)

|  j-g-c's javac  |  ecj (from .java)  |  ecj (linked)
-------------------------------------------------------------
real   |     1.1724 s    |      0.2812 s      |   0.3804 s
user   |     1.0576 s    |      0.217 s       |   0.313 s
sys    |     0.1144 s    |      0.0636 s      |   0.0672 s

I've attached the raw output of the time commands for all three tests.

Andrew

[1]
http://www.bootchart.org/misc/ecj/HelloWorld.java

[2] Note:  this took a _long_ time ... maybe I did something wrong?
(in an exploded Eclipse source tree (after rpmbuild --short-circuit -bp on
our eclipse.spec) in plugins/org.eclipse.jdt.core/compiler:

gcj -o ecj -I. --main=org.eclipse.jdt.internal.compiler.batch.Main -O2 \
`find -name *.java -print0 | xargs -0`

[3]
gcj -O2 --main=org.eclipse.jdt.internal.compiler.batch.Main \
-Wl,-R,/usr/lib/eclipse/plugins/org.eclipse.jdt.core_3.1.0 \
/usr/lib/eclipse/plugins/org.eclipse.jdt.core_3.1.0/jdtcore.jar.so \
/usr/lib/eclipse/plugins/org.eclipse.jdt.core_3.1.0/jdtCompilerAdapter.jar.so \
-o ecj.linked

[4]
export CLASSPATH=/usr/share/java/libgcj-4.0.0.jar
time <compiler> HelloWorld.java

[Andrew Haley]

Andrew Overholt writes:
> I decided to do something similar to what Ziga had done.  I took his
> HelloWorld.java [1] and compiled it with three incarnations of ecj:

Isn't this program to small to be a reasonable test?

Andrew.

[Ziga Mahkovec]

On Thu, 2005-03-24 at 15:51 +0000, Andrew Haley wrote:
> Andrew Overholt writes:
> > I decided to do something similar to what Ziga had done.  I took his
> > HelloWorld.java [1] and compiled it with three incarnations of ecj:
>
> Isn't this program to small to be a reasonable test?

Andrew, if you want to repeat the tests for GNU Classpath, here's what I
did:

1. grab a classpath snapshot (or checkout from CVS)
2. ./configure --with-ecj
3. apply the attached patch to work around an ecj bug[1]
4. link /usr/bin/ecj to one of your incarnations
5. cd lib; time make
6. make clean, rinse, repeat

If I understand correctly, any significant difference in these timings
would indicate BC-ABI performance penalty?

[1] https://bugs.eclipse.org/bugs/show_bug.cgi?id=88562

[Andrew Overholt]

* Ziga Mahkovec  [2005-03-24 11:19]:
> Andrew, if you want to repeat the tests for GNU Classpath, here's what I

Cool, thanks.

Here are two of the three results (the from-source ecj had some issues with
relocation):

ecj.linked:
----------
real    0m52.822s
user    0m21.669s
sys     0m2.018s

java-gcj-compat's javac:
-----------------------
real    1m5.062s
user    0m24.139s
sys     0m2.410s

Andrew

[Tom Tromey]

> > > > > "Ziga" == Ziga Mahkovec  writes:

Ziga> If I understand correctly, any significant difference in these timings
Ziga> would indicate BC-ABI performance penalty?

There are actually two variables hiding here: in case [3], not only is
(e.g.) jdtcore.jar.so compiled with the BC-ABI, but it is also
compiled from .class files and not .java source.  The latter can
sometimes have a performance impact.  I would suggest adding another
case, namely compiling the .jar files with the C++ ABI to see how that
changes things (note that at the moment you can't compile .java source
using the BC-ABI, as that part of the compiler is unfinished).

It would also be interesting to see oprofile results for these runs.

Tom