Why slowdown in this identical code?

Question

I was trying to measure the time to execute this loop :

for (boolean t : test) {
    if (!t)
        ++count;
}

And was getting inconsistent results. Eventually I have managed to get consistent results with the following code :

public class Test {
    public static void main(String[] args) {
        int size = 100;
        boolean[] test = new boolean[10_000_000];
        java.util.Random r = new java.util.Random();
        for (int n = 0; n < 10_000_000; ++n)
            test[n] = !r.nextBoolean();

        int expected = 0;
        long acumulated = 0;
        for (int repeat = -1; repeat < size; ++repeat) {
            int count = 0;
            long start = System.currentTimeMillis();
            for (boolean t : test) {
                if (!t)
                    ++count;
            }
            long end = System.currentTimeMillis();
            if (repeat != -1)  // First run does not count, VM warming up
                acumulated += end - start;
            else                  // Use count to avoid compiler or JVM
                expected = count; //optimization of inner loop
            if ( count!=expected )
                throw new Error("Tests don't run same ammount of times");
        }
        float average = (float) acumulated / size;
        System.out.println("1st test : " + average);

        int expectedBis = 0;
        acumulated = 0;
        if ( "reassign".equals(args[0])) {
            for (int n = 0; n < 10_000_000; ++n)
                test[n] = test[n];
        }
        for (int repeat = -1; repeat < size; ++repeat) {
            int count = 0;
            long start = System.currentTimeMillis();
            for (boolean t : test) {
                if (!t)
                    ++count;
            }
            long end = System.currentTimeMillis();
            if (repeat != -1)  // First run does not count, VM warming up
                acumulated += end - start;
            else                     // Use count to avoid compiler or JVM
                expectedBis = count; //optimization of inner loop
            if ( count!=expected || count!=expectedBis)
                throw new Error("Tests don't run same ammount of times");
        }
        average = (float) acumulated / size;
        System.out.println("2nd test : " + average);
    }

}

The results I get are :

$ java -jar Test.jar noreassign
1st test : 23.98
2nd test : 23.97
$ java -jar Test.jar reassign
1st test : 23.98
2nd test : 40.86
$ java -version
java version "1.7.0_79"
OpenJDK Runtime Environment (IcedTea 2.5.5) (Gentoo package icedtea-7.2.5.5)
OpenJDK 64-Bit Server VM (build 24.79-b02, mixed mode)

The difference is in executing or not this loop before the 2nd test.

for (int n = 0; n < 10_000_000; ++n)
    test[n] = test[n];

Why? Why does doing that reassignation cause those loops after it to take twice the time?
Getting profiling right is hard...

Answer 1

"As for why the JIT compiler causes such behaviour... that is beyond my skill and knowledge."

Three basic facts:

1. Code runs faster after JIT compilation.

2. JIT compilation is triggered after a chunk of code has run for a bit. (How long "a bit" is is influenced the JVM platform and command line options.)

3. JIT compilation takes time.

In your case, when you insert the big assignment loop between test 1 and test 2, you are most likely moving the time point at which JIT compilation is triggered ... from during test 2 to between the 2 tests.

The simple way address this in this case is to put the body of main into a loop and run it repeatedly. Then discard the anomalous results in the first few runs.

(Turning off JIT compilation is not a good answer. Normally, it is the performance characteristics of code after JIT compilation that is going to be indicative of how a real application performs ...)

By setting the compiler to NONE, you are disabling JIT compilation, taking it out of the equation.

---

This kind of anomaly is common when people attempt to write micro-benchmarks by hand. Read this Q&A:

• How do I write a correct micro-benchmark in Java?