Entendiendo la salida de -XX: + PrintCompilation

Estoy ejecutando algunos micro benchmarks en el código de iteración de lista de Java. He utilizado los indicadores -XX: + PrintCompilation y -verbose: gc para garantizar que no ocurra nada en segundo plano cuando se está ejecutando el tiempo. Sin embargo, veo algo en la salida que no puedo entender.

Aquí está el código, estoy ejecutando el punto de referencia en:

import java.util.ArrayList;
import java.util.List;

public class PerformantIteration {

    private static int theSum = 0;

    public static void main(String[] args) {
        System.out.println("Starting microbenchmark on iterating over collections with a call to size() in each iteration");
        List<Integer> nums = new ArrayList<Integer>();
        for(int i=0; i<50000; i++) {
            nums.add(i);
        }

        System.out.println("Warming up ...");
        //warmup... make sure all JIT comliling is done before the actual benchmarking starts
        for(int i=0; i<10; i++) {
            iterateWithConstantSize(nums);
            iterateWithDynamicSize(nums);
        }

        //actual        
        System.out.println("Starting the actual test");
        long constantSizeBenchmark = iterateWithConstantSize(nums);
        long dynamicSizeBenchmark = iterateWithDynamicSize(nums);
        System.out.println("Test completed... printing results");

        System.out.println("constantSizeBenchmark : " + constantSizeBenchmark);
        System.out.println("dynamicSizeBenchmark : " + dynamicSizeBenchmark);
        System.out.println("dynamicSizeBenchmark/constantSizeBenchmark : " + ((double)dynamicSizeBenchmark/(double)constantSizeBenchmark));
    }

    private static long iterateWithDynamicSize(List<Integer> nums) {
        int sum=0;
        long start = System.nanoTime();        
        for(int i=0; i<nums.size(); i++) {
            // appear to do something useful
            sum += nums.get(i);
        }       
        long end = System.nanoTime();
        setSum(sum);
        return end-start;
    }

    private static long iterateWithConstantSize(List<Integer> nums) {
        int count = nums.size();
        int sum=0;
        long start = System.nanoTime();        
        for(int i=0; i<count; i++) {
            // appear to do something useful
            sum += nums.get(i);
        }
        long end = System.nanoTime();
        setSum(sum);
        return end-start;
    }

    // invocations to this method simply exist to fool the VM into thinking that we are doing something useful in the loop
    private static void setSum(int sum) {
        theSum = sum;       
    }

}


Aquí está la salida.

    152   1       java.lang.String::charAt (33 bytes)
    160   2       java.lang.String::indexOf (151 bytes)
    165   3Starting microbenchmark on iterating over collections with a call to size() in each iteration       java.lang.String::hashCode (60 bytes)
    171   4       sun.nio.cs.UTF_8$Encoder::encodeArrayLoop (490 bytes)
    183   5
       java.lang.String::lastIndexOf (156 bytes)
    197   6       java.io.UnixFileSystem::normalize (75 bytes)
    200   7       java.lang.Object::<init> (1 bytes)
    205   8       java.lang.Number::<init> (5 bytes)
    206   9       java.lang.Integer::<init> (10 bytes)
    211  10       java.util.ArrayList::add (29 bytes)
    211  11       java.util.ArrayList::ensureCapacity (58 bytes)
    217  12       java.lang.Integer::valueOf (35 bytes)
    221   1%      performance.api.PerformantIteration::main @ 21 (173 bytes)
Warming up ...
    252  13       java.util.ArrayList::get (11 bytes)
    252  14       java.util.ArrayList::rangeCheck (22 bytes)
    253  15       java.util.ArrayList::elementData (7 bytes)
    260   2%      performance.api.PerformantIteration::iterateWithConstantSize @ 19 (59 bytes)
    268   3%      performance.api.PerformantIteration::iterateWithDynamicSize @ 12 (57 bytes)
    272  16       performance.api.PerformantIteration::iterateWithConstantSize (59 bytes)
    278  17       performance.api.PerformantIteration::iterateWithDynamicSize (57 bytes)
Starting the actual test
Test completed... printing results
constantSizeBenchmark : 301688
dynamicSizeBenchmark : 782602
dynamicSizeBenchmark/constantSizeBenchmark : 2.5940773249184588


No entiendo estas cuatro líneas de la salida.

260   2%      performance.api.PerformantIteration::iterateWithConstantSize @ 19 (59 bytes)
268   3%      performance.api.PerformantIteration::iterateWithDynamicSize @ 12 (57 bytes)
272  16       performance.api.PerformantIteration::iterateWithConstantSize (59 bytes)
278  17       performance.api.PerformantIteration::iterateWithDynamicSize (57 bytes)


¿Por qué estos dos métodos se compilan dos veces?¿Cómo leo esta salida ... qué significan los distintos números?

Respuestas a la pregunta(2)

Su respuesta a la pregunta