Почему существует такая большая разница во времени между первым вызовом nanoTime() и последовательными вызовами?

Итак, мой вопрос более общий. У меня есть следующий простой код:

for(int i=0;i<10;i++){
    long starttime=System.nanoTime();
    System.out.println("test");
    long runtime=System.nanoTime()-starttime;
    System.out.println(i + ":" +"runtime="+runtime);
}

я получаю следующий вывод:

test
0:runtime=153956
test
1:runtime=15396
test
2:runtime=22860
test
3:runtime=11197
test
4:runtime=11197
test
5:runtime=12129
test
6:runtime=11663
test
7:runtime=11664
test
8:runtime=53185
test
9:runtime=12130

В чем причина разницы между первой и второй версиями выполнения? Спасибо заранее =)

Ответ 1

Многие вещи, как в JVM, так и в стандартной библиотеке, лениво инициализируются, чтобы улучшить время запуска JVM. Поэтому при первом запуске строки

System.out.println("test");

происходит процесс инициализации тяжеловеса. Время его завершения включено в ваше первое измерение. Последующие вызовы идут по быстрому пути, где состояние уже инициализировано.

Вы можете наблюдать тот же эффект при множестве вызовов API в Java.

Естественно, что есть много факторов, которые могут влиять на время, необходимое для завершения любого вызова метода, особенно если он включает в себя системные вызовы на своем пути. Однако выброс в латентности первого вызова является особым в том, что он имеет детерминированные причины, лежащие в его основе, и поэтому надежно воспроизводимым.

Ответ 2

Многие вещи могут повлиять на ваши расчеты.

Как насчет других процессов на ваших машинах? Вы считали, что JVM прогревается? Может быть, сборка мусора? Все эти факторы и многое другое приводят к такому поведению.

Если вы хотите получить "лучшие" результаты, вы должны запускать его гораздо чаще и принимать среднее значение.

Вот почему вы должны знать, как оценивать вещи в Java, см. Как написать правильный микро-тест в Java?.

Ответ 3

JVM потратила некоторое время на инициализацию всех необходимых объектов, доступ к системному времени, поток вывода системы и т.д. У вас есть два метода, которые происходят между ними:

System.nanoTime() 
System.out.println()

Каждый из них мог выполнить много кода инициализации).

Каждый последовательный вызов выполняется намного быстрее, потому что все это уже настроено. Поэтому, когда вы сравниваете приложение для производительности, обычно прогревается и охлаждается фаза (например, первая и последняя 15 минут).