Why is Java so slow????
Hi all,
I'm wondering if anyone can help me understand why my Java is being
very slow compared to an equivalent program written in "C".
I'm simply trying to print out the first N integers like
"This is line <nnnn>"
as a simple benchmark.
My Java version is over 60 times slower than my "C" version and I
would like to establish a lower bound on how long the very fastest
Java version could take, by applying every possible performance
speedup availalbe in the Java environment.
I've profiled with "-Xrunhprof" and looked at the output (below) and
was surprised by what I saw. Over 50 different methods are involved
before I arrive at the point where 80% of the cumulative CPU usage for
the run is accounted for! What the heck is this stuff?????
Is this really happening, and is there a way to get around it?
My client is threatening to implement in "C" and I am trying to talk
him out of it.
I'd be very curious to see how this equivalent benchmark peforms on
others' environments.
Thanks,
Larry
MY ENVIRONMENT
Machine: Intel Core 2 Duo 2 GHz processor, 8GB of ram
O/S: Linux kernel V. 2.6.18-8.1.14.el5, x86_64 architecture
Java: >> java -version
java version "1.6.0_03"
Java(TM) SE Runtime Environment (build 1.6.0_03-b05)
Java HotSpot(TM) Server VM (build 1.6.0_03-b05, mixed mode)
MY BENCHMARK
This "C" program takes about 11.5 seconds to print 50,000,000 lines or
4.3 million lines / sec... output is to /dev/null
Compiled with:
gcc -O4 -o t t.c
======================== t.c
#include <stdio.h>
int main(int argc, char ** argv)
{
int lim = atoi(argv[1]);
int i;
for (i=1; i <= lim; i++)
printf("this is line %d\n", i);
}
======================== t.c
This Java class takes about 15.6 seconds to print 5,000,000 lines or
63,700 lines / sec ... 67 times slower!
======================= t.java
class t
{
static public void main(String[] argv)
{
int lim = new Integer(argv[0]);
int i;
for (i=0; i < lim; i++)
System.out.println("This is line " + i);
}
}
======================= t.java
Here is the result of running with
-Xrunhprof:cpu=times
and # interations argument of 10,000
============== java.hprof.txt
JAVA PROFILE 1.0.1, created Mon Nov 19 13:40:52 2007
Header for -agentlib:hprof (or -Xrunhprof) ASCII Output (JDK 5.0 JVMTI
based)
....
....
rank self accum count trace method
1 10.64% 10.64% 20000 300932 sun.nio.cs.US_ASCII
$Encoder.encodeArrayLoop
2 5.59% 16.23% 20000 300958 sun.nio.cs.StreamEncoder.writeBytes
3 4.22% 20.45% 20000 300939 sun.nio.cs.StreamEncoder.implWrite
4 3.00% 23.45% 20000 300936
java.nio.charset.CharsetEncoder.encode
5 2.97% 26.42% 20000 300956 java.io.PrintStream.write
6 2.84% 29.26% 20000 300933 sun.nio.cs.US_ASCII
$Encoder.encodeLoop
7 2.23% 31.49% 10000 300985 java.io.PrintStream.newLine
8 2.15% 33.64% 20000 300955 java.io.BufferedOutputStream.flush
9 2.10% 35.74% 10000 300964 java.io.PrintStream.write
10 2.01% 37.75% 20013 300087 java.nio.Buffer.<init>
11 1.96% 39.71% 1 301017 t.main
12 1.70% 41.40% 60027 300305 java.nio.ByteBuffer.arrayOffset
13 1.61% 43.01% 60027 300301 java.nio.CharBuffer.arrayOffset
14 1.51% 44.53% 10000 300922 java.io.BufferedWriter.write
15 1.41% 45.94% 10000 300912
java.lang.AbstractStringBuilder.append
16 1.37% 47.31% 10000 300971 java.io.BufferedWriter.write
17 1.35% 48.66% 20000 300926 java.nio.CharBuffer.<init>
18 1.34% 50.00% 20000 300928 java.nio.CharBuffer.wrap
19 1.29% 51.29% 20000 300952 java.io.FileOutputStream.write
20 1.26% 52.55% 20000 300927 java.nio.HeapCharBuffer.<init>
21 1.25% 53.80% 20000 300953
java.io.BufferedOutputStream.flushBuffer
22 1.23% 55.03% 10000 300960 sun.nio.cs.StreamEncoder.flushBuffer
23 1.17% 56.20% 10000 300986 java.io.PrintStream.println
24 1.13% 57.33% 40018 300306 java.nio.Buffer.position
25 1.13% 58.46% 10000 300977 java.io.BufferedWriter.flushBuffer
26 1.12% 59.58% 10000 300923 java.io.Writer.write
27 1.08% 60.66% 40018 300303 java.nio.Buffer.limit
28 1.07% 61.73% 40018 300302 java.nio.Buffer.position
29 1.06% 62.80% 10000 300979
sun.nio.cs.StreamEncoder.implFlushBuffer
30 1.06% 63.85% 10000 300942 java.io.BufferedWriter.flushBuffer
31 1.03% 64.88% 10000 300972 java.io.Writer.write
32 1.00% 65.88% 10000 300980 sun.nio.cs.StreamEncoder.flushBuffer
33 0.98% 66.87% 10000 300959
sun.nio.cs.StreamEncoder.implFlushBuffer
34 0.97% 67.84% 10000 300908
java.lang.AbstractStringBuilder.append
35 0.97% 68.81% 10000 300975 sun.nio.cs.StreamEncoder.write
36 0.95% 69.76% 10000 300984 java.io.BufferedOutputStream.flush
37 0.94% 70.69% 10000 300940 sun.nio.cs.StreamEncoder.write
38 0.87% 71.56% 10000 300941 java.io.OutputStreamWriter.write
39 0.75% 72.32% 10000 300914 java.util.Arrays.copyOfRange
40 0.72% 73.03% 9000 300988 java.util.Arrays.copyOf
41 0.71% 73.74% 10000 300915 java.lang.String.<init>
42 0.68% 74.42% 10000 300905 java.lang.StringBuilder.<init>
43 0.66% 75.08% 10000 300963 java.lang.String.indexOf
44 0.66% 75.74% 10000 300981
java.io.OutputStreamWriter.flushBuffer
45 0.65% 76.39% 10000 300976 java.io.OutputStreamWriter.write
46 0.63% 77.03% 10000 300909 java.lang.StringBuilder.append
47 0.63% 77.66% 10000 300916 java.lang.StringBuilder.toString
48 0.63% 78.29% 20000 300947 java.nio.Buffer.position
49 0.63% 78.93% 10000 300961
java.io.OutputStreamWriter.flushBuffer
50 0.61% 79.54% 20000 300930 java.nio.CharBuffer.hasArray
51 0.61% 80.15% 10000 300913 java.lang.StringBuilder.append
....
100 0.02% 99.51% 4 300254 sun.net.www.ParseUtil.decode
101 0.02% 99.53% 4 300257 java.io.UnixFileSystem.normalize
102 0.02% 99.55% 1 300619
sun.net.www.protocol.file.Handler.createFileURLConnection
103 0.02% 99.57% 2 300717 java.io.FilePermission$1.run
CPU TIME (ms) END