Почему два последовательных вызова одного и того же метода приводят к разному времени выполнения?
https://stackoverflow.com/questions/804620
-
03-07-2019 - |
italiano
english
français
española
中国
日本の
العربية
Deutsch
한국어
Português
RussianВопрос
Вот пример кода:
public class TestIO{
public static void main(String[] str){
TestIO t = new TestIO();
t.fOne();
t.fTwo();
t.fOne();
t.fTwo();
}
public void fOne(){
long t1, t2;
t1 = System.nanoTime();
int i = 10;
int j = 10;
int k = j*i;
System.out.println(k);
t2 = System.nanoTime();
System.out.println("Time taken by 'fOne' ... " + (t2-t1));
}
public void fTwo(){
long t1, t2;
t1 = System.nanoTime();
int i = 10;
int j = 10;
int k = j*i;
System.out.println(k);
t2 = System.nanoTime();
System.out.println("Time taken by 'fTwo' ... " + (t2-t1));
}
}
Это дает следующий результат:100 Время, затраченное "Фоном" ...390273 100 Время, затраченное "Двумя" ...118451 100 Время, затраченное "Фоном" ...53359 100 Время, затраченное "Двумя" ...115936 Нажмите любую клавишу , чтобы продолжить...
Почему для выполнения одного и того же метода в первый раз требуется больше времени (значительно больше), чем для последовательных вызовов?
Я пытался давать -XX:CompileThreshold=1000000 в командную строку, но никакой разницы не было.
Решение
На это есть несколько причин.Возможно, компилятор JIT (Just In Time) не был запущен.JVM может выполнять оптимизацию, которая отличается в разных вызовах.Вы измеряете прошедшее время, так что, возможно, на вашем компьютере запущено что-то другое, кроме Java.Кэш-память процессора и оперативной памяти, вероятно, "прогревается" при последующих вызовах.
Вам действительно нужно выполнить несколько вызовов (в тысячах), чтобы получить точное время выполнения каждого метода.
Другие советы
Проблемы, упомянутые Андреас и непредсказуемость JIT верны, но все же еще одной проблемой является загрузчик классов:
Первый звонок в fOne радикально отличается от последних, потому что именно это делает первый вызов System.out.println, что означает, что именно тогда загрузчик классов извлекает из кэша диска или файловой системы (обычно он кэшируется) все классы, необходимые для печати текста.Укажите параметр -verbose:class в JVM, чтобы увидеть, сколько классов на самом деле загружено во время этой небольшой программы.
Я заметил похожее поведение при запуске модульных тестов - первый тест для вызова большого фреймворка занимает намного больше времени (в случае Guice около 250 мс на C2Q6600), хотя тестовый код был бы таким же, потому что первый вызов выполняется, когда загрузчик классов загружает сотни классов.
Поскольку ваш пример программы такой короткий, накладные расходы, вероятно, связаны с очень ранней оптимизацией JIT и активностью по загрузке класса.Сборщик мусора, вероятно, даже не запустится до завершения программы.
Обновить:
Теперь я нашел надежный способ выяснить, что такое в самом деле не торопитесь.Никто еще не узнал об этом, хотя это тесно связано с загрузкой класса - это было динамическое связывание собственных методов!
Я изменил код следующим образом, чтобы журналы показывали, когда начинаются и заканчиваются тесты (просматривая, когда загружаются эти пустые классы маркеров).
TestIO t = new TestIO();
new TestMarker1();
t.fOne();
t.fTwo();
t.fOne();
t.fTwo();
new TestMarker2();
Команда для запуска программы с правильным Параметры JVM это показывает, что происходит на самом деле:
java -verbose:class -verbose:jni -verbose:gc -XX:+PrintCompilation TestIO
И результат:
* snip 493 lines *
[Loaded java.security.Principal from shared objects file]
[Loaded java.security.cert.Certificate from shared objects file]
[Dynamic-linking native method java.lang.ClassLoader.defineClass1 ... JNI]
[Loaded TestIO from file:/D:/DEVEL/Test/classes/]
3 java.lang.String::indexOf (166 bytes)
[Loaded TestMarker1 from file:/D:/DEVEL/Test/classes/]
[Dynamic-linking native method java.io.FileOutputStream.writeBytes ... JNI]
100
Time taken by 'fOne' ... 155354
100
Time taken by 'fTwo' ... 23684
100
Time taken by 'fOne' ... 22672
100
Time taken by 'fTwo' ... 23954
[Loaded TestMarker2 from file:/D:/DEVEL/Test/classes/]
[Loaded java.util.AbstractList$Itr from shared objects file]
[Loaded java.util.IdentityHashMap$KeySet from shared objects file]
* snip 7 lines *
И причина этой разницы во времени заключается вот в чем: [Dynamic-linking native method java.io.FileOutputStream.writeBytes ... JNI]
Мы также можем видеть, что JIT-компилятор не влияет на этот бенчмарк.Существует только три метода, которые компилируются (например, java.lang.String::indexOf в приведенном выше фрагменте), и все они происходят до fOne вызывается метод.
Тестируемый код довольно тривиален.самое дорогостоящее предпринятое действие - это
System.out.println(k);итак, что вы измеряете, так это скорость записи отладочного вывода.Это варьируется в широких пределах и может даже зависеть от положения окна отладки на экране, если требуется прокрутить его размер и т.д.
JIT/Hotspot постепенно оптимизирует часто используемые пути к коду.
Процессор оптимизирует работу с учетом ожидаемых путей к коду.Пути, используемые чаще, выполняются быстрее.
Размер вашей выборки слишком мал.Такие микропленки обычно выполняются на этапе разминки. Вы можете видеть, насколько интенсивно это должно быть сделано, например Java действительно быстро ничего не делает.
В дополнение к дрожанию, другими факторами могут быть:
- Выходной поток процесса блокируется при вызове System.out.println
- Ваш процесс будет запланирован другим процессом
- Сборщик мусора, выполняющий некоторую работу в фоновом потоке
Если вы хотите получить хорошие контрольные показатели, вам следует
- Запустите код, который вы тестируете, большое количество раз, по крайней мере, несколько тысяч, и вычислите среднее время.
- Игнорируйте время первых нескольких вызовов (из-за джиттинга и т.д.)
- Отключите GC, если сможете;это может быть невозможно, если ваш код генерирует много объектов.
- Извлеките протоколирование (вызовы println) из тестируемого кода.
На нескольких платформах существуют библиотеки бенчмаркинга, которые помогут вам сделать это;они также могут вычислять стандартные отклонения и другие статистические данные.
Наиболее вероятным виновником является ДЖИТ движок горячих точек (точно в срок).По сути, при первом выполнении кода машинный код "запоминается" JVM и затем повторно используется при будущих исполнениях.
Я думаю, это потому, что во второй раз сгенерированный код уже был оптимизирован после первого запуска.
Как было высказано предположение, виновником может быть JIT, но так же может быть и время ожидания ввода-вывода, а также время ожидания ресурсов, если другие процессы на компьютере в этот момент использовали ресурсы.
Мораль этой истории такова, что микропримаркинг - сложная проблема, особенно для Java.Я не знаю, зачем вы это делаете, но если вы пытаетесь выбрать между двумя подходами к решению проблемы, не оценивайте их таким образом.Используйте шаблон разработки стратегии и запустите всю вашу программу с использованием двух различных подходов и измерьте всю систему.Это немного сокращает время обработки в долгосрочной перспективе и дает вам гораздо более реалистичное представление о том, насколько производительность всего вашего приложения на данный момент является узким местом (подсказка:вероятно, это меньше, чем вы думаете.)
Что ж, наиболее вероятный ответ - это инициализация.JIT наверняка не является правильным ответом, поскольку требуется гораздо больше циклов, прежде чем он начнет оптимизироваться.Но в самый первый раз может быть:
- поиск классов (кэшируется, поэтому второй поиск не требуется)
- загружаемые классы (после загрузки остаются в памяти)
- получение дополнительного кода из собственной библиотеки (собственный код кэшируется)
- наконец, он загружает код для выполнения в кэш L1 центрального процессора.Это наиболее подходящий случай для ускорения в вашем понимании и в то же время причина, по которой бенчмарк (являющийся микробенчмарком) мало что говорит.Если ваш код достаточно мал, второй вызов цикла может быть полностью выполнен изнутри процессора, что является быстрым процессом.В реальном мире этого не происходит, потому что программы крупнее, а повторное использование кэша L1 далеко не такое большое.
