Статьи

Стоп часы Кто-нибудь? (Или «О непрерывном профилировании»)


Одним из наиболее интересных выступлений на последнем выпуске Community One в Сан-Франциско, посвященном NetBeans, стало выступление ведущего архитектора NetBeans
Ярды Тулач о повышении производительности в последней IDE NetBeans 6.1. Ярда также говорила о влиянии настройки производительности на процесс разработки и, подводя итог, одним из основных моментов является то, что вам следует выполнять непрерывное профилирование. Другими словами, вы можете быть довольны производительностью определенной функции, затем вы начнете исправлять ошибки, добавлять новые функции и т. Д. И не будете осознавать, что производительность постепенно снижается; и в какой-то момент это настолько ухудшилось, что вам понадобится серьезный рефакторинг. Желательно постоянно держать его под контролем и сразу же быть в курсе, если что-то замедляется.

Я на самом деле испытал это во время разработки blueMarine с трудом, что сейчас я больше не могу себе позволить, поскольку приближаюсь к настоящему релизу. Мои бета-тестеры были достаточно уверены в своих ожиданиях относительно производительности некоторых функций, и один из реальных «политических» недостатков Java состоит в том, что постоянный миф «Java медленный», хотя и ложный, может создать дополнительные проблемы, если вы что-то делаете неправильно в этом районе. Просто будьте неэффективны в своем коде, и кто-то скоро напишет ваше настольное приложение, поскольку оно «дерьмовое Java» (то есть, даже если ошибка ваша, и вы действительно можете ее исправить, вы рискуете навсегда отказаться от вашего приложения из-за технологии это сделано с).

Поэтому я начал проводить периодические ручные измерения производительности в самых важных областях BlueMarine. Пока что я провожу некоторые специальные нагрузочные тесты, извлекаю из них цифры и помещаю их в электронную таблицу OpenOffice, где я могу отслеживать прогресс, видеть тенденции и в конечном итоге сравнивать цифры и т. Д. (Самый первый пример был об этом говорили на моем блоге пару месяцев назад).

Теперь, в перспективе, я вижу обычную проблему «непрерывных» задач: это занимает все больше и больше времени, и чем больше тестов производительности я добавляю, тем хуже. Так что это должно быть каким-то образом автоматизировано и, возможно, интегрировано с Hudson .

Из многих проблем, связанных с непрерывным профилированием, самым первым является способ сбора данных. Теперь у NetBeans есть отличный профилировщик (за исключением нескольких ошибок, которые доставляют мне неприятности в моем конкретном сценарии RCP), но, на мой взгляд, это совсем другое:

  1. Профилировщик Java — это особый инструмент разработки, хотя я хочу, чтобы некоторые данные профилирования могли быть собраны в любой момент с помощью производственного кода, даже некоторым (бета) тестером. Несмотря на то, что профилировщик Java 6 гораздо проще в настройке, он все равно является инструментом JDK, который напугал бы случайного пользователя; мне нужна конкретная панель параметров пользовательского интерфейса, где пользователь может установить флажок и, возможно, выбрать функциональную область для профилирования.
  2. Профилировщик Java не «семантически осведомлен». Я имею в виду, что он может сказать мне, сколько раз и как долго выполнялся определенный метод, скажем loadImage (), в то время как мне нужно, например, сегментировать собранные данные в зависимости от параметров (например, типа изображения и скоро). Пожалуйста, прочитайте пример ниже для лучшего прояснения сути.
  3. Профилировщик Java собирает слишком много данных для подхода «непрерывного профилирования», и это, конечно, также влияет на производительность. Конечно, с помощью профилировщика Java можно точно настроить точки профилирования, но, опять же, это задача для программиста, а не для (бета) пользователя.

Из предыдущих пунктов я бы сказал, что сильнее номер 2, учитывая, что улучшения в Java Profiler могут ослабить № 1 и № 3 с течением времени.

По этим причинам я думаю об очень простом API. Вот пример: у меня есть класс, который отвечает за импорт фрагмента метаданных, представленных его классом, из изображения; и следующий — декоратор, который запускает секундомеры:

public class ImageBridgeStopWatchDecorator implements ImageBridge
{
private final ImageBridgeImpl delegate = new ImageBridgeImpl();

public <T> T readMetadataItem (final File file, final Class<T> itemClass)
throws IOException
{
final StopWatch stopWatch = StopWatch.create(delegate.getClass(), String.format("read/%s/%s", itemClass.getName(), extension(file)));

try
{
return delegate.readMetadataItem(file, itemClass);
}
finally
{
stopWatch.stop();
}
}
}

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

STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/ALL            [ 155 samples]: acc:     1.38/    0.01/    0.06/    0.01 msec, ela: 96549.59/  225.20/ 2781.93/  622.90 msec (val/min/max/avg)
STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/image/crw [ 8 samples]: acc: 3151.33/ 102.31/ 1134.09/ 393.92 msec, ela: 4396.07/ 225.18/ 1336.43/ 549.51 msec (val/min/max/avg)
STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/image/dng [ 10 samples]: acc: 6413.12/ 345.50/ 1541.62/ 641.31 msec, ela: 18840.89/ 996.86/ 2781.86/ 1884.09 msec (val/min/max/avg)
STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/image/jpeg [ 63 samples]: acc: 18608.76/ 104.39/ 583.07/ 295.38 msec, ela: 30141.81/ 309.16/ 915.03/ 478.44 msec (val/min/max/avg)
STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/image/mrw [ 10 samples]: acc: 3076.36/ 272.67/ 419.63/ 307.64 msec, ela: 4089.75/ 370.50/ 518.07/ 408.97 msec (val/min/max/avg)
STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/image/nef [ 59 samples]: acc: 26909.63/ 293.88/ 759.67/ 456.10 msec, ela: 37054.66/ 440.88/ 1118.92/ 628.05 msec (val/min/max/avg)
STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/image/srf [ 2 samples]: acc: 709.45/ 247.23/ 462.23/ 354.73 msec, ela: 1120.44/ 445.31/ 675.14/ 560.22 msec (val/min/max/avg)
STATS: it/tidalwave/bluemarine/metadata/importer/MetadataImporter/process/image/tiff [ 3 samples]: acc: 355.54/ 109.47/ 134.61/ 118.51 msec, ela: 902.77/ 258.22/ 333.88/ 300.92 msec (val/min/max/avg)

Как вы можете видеть, данные были сегментированы по типу изображения MIME, что очень важно для меня, поскольку срабатывают разные кодеки и отображается очень разная производительность (например, посмотрите на ужасные цифры о формате DNG). Секундомер собирает количество вызовов, прошедшее и накопленное время, а также максимум / мин и среднее. Точность составляет наносекунды (с помощью System.nanoTime ()). На данный момент данные просто собираются в памяти и сбрасываются в конце теста, но есть также специальный API для доступа к ним как JavaBeans, поэтому я могу поместить их в тестовые утверждения. Если функция вдруг становится медленнее, тест не пройден (конечно, здесь есть проблемы, такие как уверенность в том, что сервер CI не перегружен другими задачами, иначе собранное время будет искусственно слишком долгим).

Усовершенствования могут заключаться в том, чтобы сделать данные доступными через JMX, чтобы JConsole могла легко отслеживать их в режиме реального времени, если это необходимо. До сих пор я видел, что влияние StopWatches очень мало в моих тестах, и в любом случае они могут быть отключены конфигурацией (в этом случае фиктивный класс StopWatch будет возвращаться каждый раз методом create ()).

Что вы думаете? Я хотел бы услышать от вас об этом, поскольку непрерывное профилирование — это что-то новое для меня. В частности, я хотел бы знать, существует ли существующий простой API StopWatch с функциями, описанными в примере выше, прежде чем я начну разрабатывать свой собственный. Кроме того, любые предложения и лучшие практики будут оценены.