В последней версии Java Microbenchmark Harness (JMH) появился новый профайлер — dtraceasm, долгожданный порт perfasm на Mac OS X, который умеет показывать ассемблерный профиль Java-бенчмарка.

Блиц-опрос показал, что не всем понятно, как в принципе возможно, получив на входе Java-метод, на выходе показать ассемблерный листинг скомпилированного метода с самыми горячими инструкциями, их распределением и небольшим профилем вида "А еще 5% времени виртуальная машина провела в методе Symbol::as_C_string(char*, int)".

В процессе портирования perfasm выяснилось, что на самом деле™ все не очень сложно и появилось желание рассказать, как такой профайлер устроен.

Для понимания статьи крайне желательно ознакомиться с JMH, например, посмотрев на примеры его использования.

Введение

Что должен делать такой профайлер?
Для Java-бенчмарка он должен точно показать, где именно тратится большая часть процессорного времени на уровне сгенерированного кода.

При этом сгенерированного кода обычно очень много, поэтому он должен уметь делать это довольно точечно, чтобы не приходилось с огнем выискивать нужную нам информацию в выводе профайлера.

Например, для метода, который считает логарифм:

@Benchmark
public double log(double x) {
    return Math.log(x);
}

dtraceasm или perfasm покажут профиль как на скриншоте слева, обвинив во всем инструкцию fstpl. Из-за сильной конвейеризации современных процессоров такой профиль может ошибаться, и часто имеет смысл смотреть не только на инструкцию, которая считается горячей, но и на предыдущую. Здесь это fyl2x, которая и считает логарифм.

Фактически такой профайлер очень похож на perf annotate, но умеет работать с JIT-скомпилированным Java-кодом.

Зачем?

А зачем вообще *asm-профайлер может понадобиться, если вы не пишете свой JIT-компилятор? Не в последнюю очередь, конечно же, из любопытства, потому что он помогает очень быстро отвечать на следующие вопросы:

• А во что вообще скомпилировался мой метод? (конечно, можно пойти в вывод PrintAssembly и найти там нужное место или воспользоваться JITWatch, но это обычно менее удобно)
• Какие оптимизации JIT-компилятор может или не может сделать, можно ли его обхитрить или запутать?
• Как изменится сгенерированный код, если поменять сборщик мусора?
• Насколько собственное восприятие реальности ("в этом методе тормозить точно будет Math.sqrt") отличается от суровой действительности
• А почему код, написанный одним способом, работает быстрее, чем такой же код, но написанный немного по-другому?

Кроме любопытства на те же самые вопросы полезно уметь отвечать, если вы вдруг решили оптимизировать какое-нибудь небольшое место, например вашу потокобезопасную очередь или узкоспециализированный класс.

Ну а если и пользоваться инструментом, то полезно хотя бы примерно понимать, как он внутри устроен, чтобы не воспринимать его как какую-то магию и иметь представление о его возможностях и ограничениях.

PrintAssembly

Чтобы построить профиль по сгенерированному коду, нужно сначала этот сгенерированный код откуда-нибудь достать а у нас денег нет. К счастью, все уже придумано за нас и виртуальная машина (здесь и далее я подразумеваю только hotspot) умеет печатать в stdout весь скомпилированный код, необходимо лишь включить нужный флаг (-XX:+PrintAssembly) и положить в $JAVA_HOME специальный дизассемблер. В интернете достаточно инструкций, как это можно сделать, обычно самому ничего собирать не нужно и достаточно лишь скачать собранный дизассемблер под вашу платформу.

PrintAssembly штука полезная, но не самая удобная. Его вывод имеет заранее известный формат, он даже аннотирован комментариями к какой байткод-инструкции относится текущая строка, какой метод сейчас напечатан или в каком регистре лежит какой аргумент, но измеряется он мегабайтами, и в нем будут все версии скомпилированного метода (C1-компилятор, C2-компилятор, версия после деоптимизации, GOTO 1), поэтому найти в нем желаемое обычно крайне затруднительно.

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

DTrace

DTrace — фреймворк для динамической трассировки, поддерживаемый в Solaris, FreeBSD, Mac OS X и, частично, в Linux. Состоит он из модуля ядра, в котором реализован основной функционал и клиентских программ на специальном языке D (не перепутайте с другим языком D). Клиентская программа декларирует, какое событие ей интересно, а модуль ядра компилирует программу в специальный байткод, проводит какую-то подготовительную работу и начинает эту программу при нужных событиях исполнять. При этом язык D безопасен и не позволяет сильно развернуться, например, уйти в бесконечный цикл или покрашить приложение, поэтому программы на нем можно исполнять прямо в ядре. Сам фреймворк очень мощный и позволяет делать много очень интересных и нетривиальных вещей, которые остаются за рамками этой статьи, я рассмотрю лишь функционал, необходимый для dtraceasm.

dtraceasm использует провайдер событий profile-n, который не вешается ни на какое специальное событие, а просто вызывает пользовательскую программу через фиксированные интервалы времени.
Механизм используется простой, ядро регистрирует таймер с заданной частотой и по нему начинает прерывать процесс, который сейчас исполняется на CPU, а в обработчике вызывает наш DTrace-скрипт.

Сам скрипт выглядит следующим образом:

profile-1001 /arg1/ { printf("%d 0x%lx %d", pid, arg1, timestamp); ufunc(arg1)}

Читать его можно так: "1001 раз в секунду напечатай pid текущего исполняемого процесса, его PC, текущее время и имя исполняемого метода (вместе с именем библиотеки), если процесс сейчас исполнялся в userspace".
PC (program counter) — это специальный регистр, содержащий адрес инструкции, которая сейчас исполняется. Но откуда берется имя метода?
Так как ядро знает всё о загруженных библиотеках, исполняемых файлах и их символах (методы являются символами), и адреса, по которым они загружены, то оно может с помощью этого знания построить индекс "адрес инструкции -> библиотека -> конкретный метод". То есть, зная значение PC, можно узнать и откуда эта инструкция взялась.

Пример

В библиотеке lib.so метод foo() начинается по смещению 1024, следующий метод bar() по смещению 2048, а сама библиотека в процесс загружена по адресу 1048576. Если у PC текущее значение лежит в интервале [1048576 + 1024, 1048576 + 2048], то сейчас исполняется метод foo() из lib.so.

Но если код был загружен динамически (собственно, чем и занимаются JIT-компиляторы) и информации о символах нет, то ядро название метода не найдет.

Просто добавь воды

Как теперь получить аннотированный ассемблер бенчмарка?
Бенчмарк запускается в отдельной JVM с флагом PrintAssembly и сразу после его старта запускается DTrace-скрипт, который свой результат записывает в файл.

Имея на руках эти данные остается только проделать следующие шаги:

1. Выхлоп DTrace фильтруется по pid и времени замеряемых итераций бенчмарка
2. Строки без имен символов объединяются с адресами инструкций из вывода PrintAssembly, у них появляется строковое представление вида inc %r10d и опциональный комментарий от дизассемблера
3. Результат агрегируется в профиль, в котором одинаковые строки схлопываются и для них накручивается счетчик их частоты
4. С помощью какой-нибудь эвристики в профиле находится непрерывный регион "горячих" инструкций. Например, если инструкции в регионе в сумме занимают 10% от всего профиля и добавление соседних инструкций добавляет незначительное число к весу региона, то можно считать, что на него нам и интересно смотреть
5. Нативные методы попадают в отдельный профиль, "горячие методы", также отсортированный по частоте
6. Результат работы красиво форматируется и отправляется пользователю в консоль

При этом проблемы с тем, что в выводе PrintAssembly есть код, скомпилированный как C1-компилятором, так и C2, уходят сами, потому что в горячий профиль после warmup-итераций попадет только одна версия скомпилированного кода (если у вас в steady state бенчмарка не происходят постоянные перекомпиляции, плюс *asm профайлеры фильтруют события от warmup-итераций), а нативные методы (внутренности самой JVM, нативные вызовы etc.) попадут в топ горячих методов.

NB: с точки зрения портирования на Mac OS X нужно было "всего лишь" сделать часть с сэмлированием PC с помощью DTrace, вся остальная инфраструктура для обработки результатов в JMH существовала со времен perfasm и ничего нового автор статьи (я) не сделал.

Заключение

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

Отдельное спасибо Алексею Шипилёву за то, что вычитал в статье все неточности и убедился, что я несу в массы знание, а не чушь :)