Комментарии 19
Ещё раз хочу вас по благодарить за участие в мастер классе. Для мне было очень приятно увидеть такой интерес к теме с вашей стороны.
Как и обещал раскрываю секрет последнего кейса с мастер класса.
Вы могли заметить что в параметрах запуска JVM был параметер -Dlogback.level.org.optaplanner=debug
. Логи пишутся в файл target/optaplanner.log
. Вы легко можете убедиться, что один запуск бенчмарка создаёт около 50 мегабайт лога (в консоль при этом печатаются сообщения с уровнем INFO и выше).
При изменении параметра на -Dlogback.level.org.optaplanner=info
время оптимизации модели на моей машине сократилось с 35.7 до 9.3 секунд.
Mission Control не лучший инструмент для анализа подобного рода узких мест. Тем не менее, некоторые улики найти было можно.
“Длинный след” логгера на гистограмме горячих методов
На гистограмме ниже выделено несколько горячих. Каждая из них если раскрутить дерево вывода имеет отношение к легированию. В сумме выделенные строки уже дают 13.5%, что сопоставимо в временем работы наиболее горячих методов модели.
Активное использование исключений логгером
Во вкладке исключений мы видим не малое число java.lang.Throwable
, которые растут из логгера.
Файловые операции на таймлайне потока
Если посмотреть на таймлайн поток выполняющего оптимизацию, но плотно заполнен записью в файл. Заметьте что скриншот сделан с зумом в 650 миллисекунд.
Суммарное "чистое" время всех файловых операций всего 1.6 секунды (из 30 секунд записи), что само по себе. Однако большая плотность коротких IO операций обычно является поводом задуматься об их природе.
Все эти "улики" косвенные. Mission Control хорош тогда когда вы хорошо понимаете природу проблемы, которую вы хотите решить.
Почему же я выбрал этот кейс для мастер класса? Отчасти чтобы у вас был стимул испробовать все возможности Mission Control, a остановиться на первом скрине показавшем правильный результат. Отчасти чтобы показать как используя профйлер можно потерять лес за деревьями.
monosnap.com/file/RjQFBtdrZL1CSBc94CbmBPp5fW6HL1
Спасибо за анонс! Вопрос — почему в вашем плейлисте на Youtube такие неиформативные названия видео?
Можете предложить Андрею, как было бы удобнее, например, по аналогии с видео JUG.ru:
- доклады «Встреча jug.msk.ru с <имя фамилия> — <наименование доклада>» или «<имя фамилия> — <наименование доклада>»
- плейлисты «jug.msk.ru-YYYY»
Когда с телефона ищешь что посмотреть, то за всеми префиксами темы доклада уже не видно.
- доклады «<имя фамилия> — <наименование доклада>»
- плейлисты «jug.msk.ru-YYYY»
Видео со встречи — youtu.be/ypLoO49TLjI
Не думал сменить фамилию?
Я первый раз подумал про космос статья
Алексей Рагозин о Java Mission Control на jug.msk.ru