Java: Strange runtime behaviour in main

Question

I experience a (for me) strange runtimebehaviour in the following code:

public class Main{
 private final static long ROUNDS = 1000000;
 private final static double INITIAL_NUMBER = 0.45781929d;
 private final static double DIFFERENCE = 0.1250120303d;
 public static void main(String[] args){
 doSomething();
 doSomething();
 doSomething();
 }
 private static void doSomething(){
 long begin, end;
 double numberToConvert, difference;
 numberToConvert = INITIAL_NUMBER;
 difference = DIFFERENCE;
 begin = System.currentTimeMillis();
 for(long i=0; i<ROUNDS; i++){
 String s = "" + numberToConvert;
 if(i % 2 == 0){
 numberToConvert += difference;
 }
 else{
 numberToConvert -= difference;
 }
 }
 end = System.currentTimeMillis();
 System.out.println("String appending conversion took " + (end - begin) + "ms.");
 }
}

I would expect the program to print out similiar runtimes each time. However, the output I get is always like this:

String appending conversion took 473ms.
String appending conversion took 362ms.
String appending conversion took 341ms.

The first call is about 30% slower than the calls afterwards. Most of the time, the second call is also slightly slower than the third call.

java/javac versions:

javac 1.7.0_09 java version "1.7.0_09" OpenJDK Runtime Environment (IcedTea7 2.3.3) (7u9-2.3.3-0ubuntu1~12.04.1) OpenJDK 64-Bit Server VM (build 23.2-b09, mixed mode)

So, my question: Why does this happen?

• djangofan: I would put "String s" outside the loop and then assign the value using "s = Integer.toString(numberToConvert);" . This might improve performance because it doesn't create new String object every time.
• djangofan: @jlordo - yes, but the way you wrote it, it creates 2+ string objects. the way I am suggesting, there is only 1 string object used as a reference.
• randall_the_robot: @jlordo The code was initially designated to compare the runtime of "" + <primitive> and PrimitiveWrapper.toString(<primitive>) and String.valueOf(<primitive>). That is where I encountered the problems described above. I Just removed the other two methods from the source code for further investigation of this special problem. Thanks for the hint anyway. :)
• jlordo: @djangofan +1 my bad. I didn't read precise enough. You are referring to the "" + int part, I just referred to the move String s; outside of the loop part.
• djangofan: @jlordo - ok. well, if you really scrutinized the code you could find other causes of the performance difference as well. i bet you will figure out the culprit if you look hard enough.

Answer 1

The Just-in-time (JIT) compiler is profiling your code on the fly and optimizing execution. The more often a piece of code is executed the better it's optimized.

See, for example, this question for more info: (How) does the Java JIT compiler optimize my code?

• Patricia Shanahan: There may also more cache misses and page faults on the first iteration than on the second or subsequent iterations.
• randall_the_robot: @Dmitry Beransky: Thank you! Following and reading your link I found the JIT compiler (Hotspot is the name of it, I think) to be the cause of this behaviour. I found further informations here. I therefore tested the the code using the -Xint option just to find all calls to consume about the same amount of time. Thank you!

Answer 2

It is possible that other apps you have running are affecting the amount of memory you have allocated to the JVM on your machine. Try setting the same min and max memory to JVM when running the java command:

java -Xms512M -Xmx512M ...

I got fairly consistent intervals when trying to run it:

String appending conversion took 1153ms.
String appending conversion took 1095ms.
String appending conversion took 1081ms.

• randall_the_robot: Tried it, but no change in results.