О замерах времени работы кода или знай что замеряешь часть первая
Когда мне нужно проверить или продемонстрировать существенную разницу в производительности между различными алгоритмами или способами их реализации, я обычно не сильно забочусь о методике измерения. Конечно, измерение производительности кода, компиляция которого происходит на лету, требует особой аккуратности и понимания того, что происходит внутри виртуальной машины. Однако, если вы посмотрите на версию класса IntListIterationTiming, которую я использовал последний раз для замера времени при написании цикла заметок про оптимизацию кода, то не увидите там ничего сверхъестественного. Основные моменты, заслуживающие внимания, это запуск теста много раз подряд и вынос циклов измерения в отдельные методы, чтобы каждый прогон теста заходил в этот метод снова (на тему специфики измерения времени работы Java кода написано много статей).
Время выполнения каждого прогона теста просто измеряется и выводится на экран. Для публикации в своем блоге я давал этой программе поработать, убеждался что результаты адекватны и не сильно скачут от прогона к прогону, и выбирал набор чисел, который, на мой взгляд, являлся типичным. При не очень большом разбросе данных, да учитывая большую разницу между различными сравниваемыми алгоритмами, больше ничего и не надо. Насколько такой подход обоснован? Что я утаил в предыдущих заметках?
Как всегда, для начала надо понимать что же именно хочется померить. При написании системы жесткого реального времени, например, в первую очередь вас будет интересовать максимально возможное время работы. А обычно все-таки интересует среднее или типичное время работы. Если вы замеряете время работы некой системы в целом или скорость её реакции на действия пользователя, то вас будет интересовать не только среднее время работы и его максимум, но и подробности распределения времени работы от запуска к запуску. Если иногда система работает долго (здесь "долго" зависит от вашего конкретного приложения), то вас будет интересовать как часто это происходит.
Даже если вы многократно запускаете один и тот же детерминированный алгоритм с одними и теми же входными данными на современной ОС, как я это проделывал для демонстрации разницы между алгоритмами, то все равно измеренное время работы алгоритма будет отличаться при каждом прогоне. На измеренное время действует масса случайных факторов, которые могут замедлить исполнение. Да чего там рассуждать об этих факторах - я даже свой почтовый клиент на это время не выключаю.
В любом случае, любая более или менее универсальная система оценки времени работы приложений вынуждена собирать множества различных параметров, чтобы быть применимой в широком классе случаев. Минимум, максимум, среднее нужны очень часто, а различные промежуточные квантили дают еще больше информации о реальном распределении времени работы. Но иногда полезно посмотреть и на распределение в целом, особенно если речь идет о времени работы каких-нибудь очень важных для вас операций.
Я планирую продолжить писать цикл заметок про производительность и усложнил реализацию класса IntListIterationTiming так, чтобы результаты записывались в файл для упрощения их дальнейшей обработки и чтобы он сам собирал простейшую статистику (минимум, максимум, среднее) для более точной и быстрой оценки результатов (UPDATE: а заодно сделал чтобы под Java 5/6 можно было скомпилировать). Обратите внимание, что результаты первого прогона я отбрасываю полностью, ибо во время него происходит компиляция тестируемого кода, в чем я убеждаюсь запуская JVM с опцией -XX:+PrintCompilation.
В качестве бонуса, я сделал по 1000 прогонов, замеряя скорость суммирования целых чисел на разных объемах данных, хранящихся в разных реализациях простого интерфейса IntList: ViaArrayList - через ArrayList ( отсюда), ViaByteBuffer2 - через прямой ByteBuffer ( отсюда) и ViaJavaArray - через int[] (из первой заметки). Получились следующие распределения времени работы:
В табличном виде результаты замеров можно обобщить так (среднее время на итерацию ± среднеквадратическое отклонение в наносекундах):
РазмерViaArrayListViaByteBuffer2ViaJavaArray 1 0001.15 ± 0.030.77 ± 0.020.39 ± 0.01 10 0001.50 ± 0.060.77 ± 0.020.44 ± 0.02 100 0001.74 ± 0.050.77 ± 0.020.46 ± 0.02 1 000 0004.62 ± 0.120.93 ± 0.020.70 ± 0.03 10 000 0003.67 ± 0.100.93 ± 0.020.72 ± 0.02
Во первых, видно что распределения времени работы имеют весьма причудливую форму. А во-вторых, заметен интересный артефакт времени работы реализации ViaArrayList. Среднее время на итерацию по 1M элементам (4.62 нс) меньше, чем среднее время на итерацию по 10M элементам (3.67 нс) в расчете на одну итерацию. При этом, в оригинальной заметке " Память это новый диск или LinkedList vs ArrayList" этого эффекта не наблюдалось. И это не артефакт различных фоновых процессов на моей машине. Эффект повторяется от запуска к запуску - не только среднее время работы меньше, но и интервалы разброса времен не пересекаются. Как же так получилось? Кто из читателей догадается в чем здесь секрет (комментарии к записи скринятся в течение двух дней вплоть до написания продолжения этой темы)?
В качестве подсказки сообщу, что этот эффект стал проявляться в той версии класса IntListIterationTiming, которая была сделана для заметки о просмотре ассемблерного кода работающего Java приложения.
UPDATE: Читайте продолжение с отгадкой.