optimization - Why is Java faster if it repeats the same code? -

given following code:

public class test{      static int[] big = new int [10000];      public static void main(string[] args){         long time;         (int = 0; < 16; i++){             time = system.nanotime();             gettimes();             system.out.println(system.nanotime() - time);         }         }     public static void gettimes(){         int d;         (int = 0; < 10000; i++){             d = big[i];         }         } } 

the output shows decreasing duration trend:

171918 167213 165930 165502 164647 165075 203991 70563 45759 43193 45759 44476 45759 52601 47897 48325 

why same code in gettimes being executed in less 1 third of time after has been executed 8 times or more? (edit: not happen @ 8th time, 5th 10th)

the fact see result of jit optimization should clear looking @ comments received. happening , why code optimized after same amount of iterations of outer for?

i'll try answer both questions please remember explained here relative only oracle's hotspot vm. there no java specification defines how jvm jit should behave.

first of all, let's see jit doing running test program additional flag (the plain jvm enough run this, no need load debugging shared library, required of unlockdiagnosticvmoptions options):

java -xx:+printcompilation test 

the execution completes output (removing few lines @ beginning show other methods being compiled):

[...] 195017 184573 184342 184262 183491 189494     131   51%      3       test::gettimes @ 2 (22 bytes) 245167     132   52       3       test::gettimes (22 bytes) 165144    65090     132   53       1       java.nio.buffer::limit (5 bytes) 59427     132   54%      4       test::gettimes @ 2 (22 bytes)   75137 48110         135   51%     3        test::gettimes @ -2 (22 bytes)   made not entrant      142   55       4       test::gettimes (22 bytes) 150820 86951 90012 91421 

the printlns code interleaved diagnostic information related compilation jit performing. looking @ single line:

131    51%      3       test::gettimes @ 2 (22 bytes) 

each column has following meaning:

1. timestamp
2. compilation id (with additional attributes if needed)
3. tiered compilation level
4. method short name (with @osr_bci if available)
5. compiled method size

keeping lines related gettimes:

    131   51%      3       test::gettimes @ 2 (22 bytes)     132   52       3       test::gettimes (22 bytes)     132   54%      4       test::gettimes @ 2 (22 bytes)          135   51%      3       test::gettimes @ -2 (22 bytes)   made not entrant     142   55       4       test::gettimes (22 bytes) 

it's clear gettimes being compiled more once, every time it's compiled in different way.

that % symbol means on-stack replacement(osr) has been performed, meaning 10k loop contained in gettimes have been compiled isolated rest of method , jvm replaced that section of method code compiled version. osr_bci index points new compiled block of code.

the next compilation classic jit compilation compiles gettimes method (the size still same because there nothing else in method other loop).

the third time osr performed @ different tiered level. tiered compilation have been added in java7 , allows jvm choose client or server jit mode at runtime, switching freely between 2 when necessary. client mode performs simpler set of optimization strategies while server mode able apply more sophisticated optimizations on other hand have bigger cost in term of time spent compiling.

i not go details different modes or tiered compilation, if need additional information recommend java performance: definitive guide scott oaks , check this question explain changes between levels.

back output of printcompilation, gist here point in time, sequence of compilations increasing complexity performed until method becomes apparently stable (i.e. jit doesn't compile again).

so, why start @ point in time, after 5-10 iteration of main loop?

because inner gettimes loop has become "hot".

the hotspot vm, defines "hot" methods have been invoked @ least 10k times (that's historical default threshold, can changed using -xx:compilethreshold=<num>, tiered compilation there multiple thresholds) in case of osr i'm guessing it's performed when block of code deemed "hot" enough, in term of absolute or relative execution time, inside method contains it.

additional references

printcompilation guide krystal mok

java performance: definitive guide