Приложение в продакшене работает медленнее, чем хотелось бы, и нужно понять, где оно тратит процессорное время. Беда в том, что оно уже запущено и обслуживает пользователей - останавливать его ради замеров нельзя, а воспроизвести нагрузку в тестовой среде получается не всегда. Возникает ощущение тупика: чтобы измерить, надо вмешаться, а вмешиваться нельзя. На деле тупика нет. Профилировщик Linux умеет снимать профиль уже работающего процесса, не трогая его, - просто прицепившись к нему на несколько секунд и понаблюдав со стороны.
Профилирование работает выборкой: через равные промежутки профилировщик подсматривает, какие функции выполняются прямо сейчас, и по множеству таких снимков строит картину, где код проводит больше всего времени. Сырой результат громоздок и труден для чтения, поэтому его превращают в наглядную диаграмму пламени или загружают в интерактивный просмотрщик. Разберём, как снять профиль на ходу, как построить из него диаграмму, и как её читать.
Снятие профиля работающего процесса без его остановки
Профиль снимают записывающим режимом профилировщика, прицепив его к уже работающему процессу по его номеру. Профилировщик при этом не останавливает и не перезапускает приложение - он лишь наблюдает за ним со стороны заданное время.
sudo perf record -F 99 -g -p 12345 -- sleep 30
Разберём команду по частям. Указание номера процесса прицепляет профилировщик к нужному приложению. Завершающая команда паузы на тридцать секунд задаёт длительность наблюдения - ровно столько профилировщик будет собирать данные, после чего сам отцепится. Флаг захвата графа вызовов велит записывать не только горячие функции, но и цепочки вызовов, приведшие к ним. А флаг частоты задаёт, сколько раз в секунду брать выборку.
Частота выборки заслуживает пояснения. Значение около сотни выборок в секунду - разумная отправная точка. Чем выше частота, тем точнее картина, но и больше данных. Для поиска заметного замедления сотни выборок в секунду обычно более чем достаточно, потому что прожорливые функции работают долго и попадают в выборку многократно. Нечётное значение частоты выбирают намеренно, чтобы выборка не совпала по фазе с какими-нибудь периодическими событиями в системе и не исказила картину.
После завершения профилировщик складывает собранные данные в файл в текущем каталоге. Приложение всё это время работало как ни в чём не бывало - в этом и состоит главное достоинство такого подхода для продакшена.
Сырой отчёт громоздок, и его превращают в диаграмму
Снятый профиль можно посмотреть и текстовым отчётом, но он бывает в тысячи строк и труден для восприятия. Поэтому профиль превращают в диаграмму пламени - наглядную картинку, на которой горячие пути кода видны сразу. Делается это цепочкой обработки: профиль разворачивают в текстовый вид, сворачивают одинаковые стеки в свёрнутую форму, а из неё строят саму диаграмму.
perf script | stackcollapse-perf.pl > свёрнутое.txt
flamegraph.pl свёрнутое.txt > диаграмма.svg
Первая команда разворачивает записанный профиль в построчный текст со стеками вызовов. Вторая сворачивает одинаковые стеки, подсчитывая, сколько раз каждый встретился. Третья превращает свёрнутую форму в диаграмму. Скрипты для свёртки и построения диаграммы - сторонние, их обычно скачивают отдельно.
Есть и удобство для тех, кто не хочет городить цепочку вручную: в ряде систем профилировщик умеет снять профиль и построить диаграмму одной командой, сразу выдавая готовую картинку. Но понимание цепочки полезно, потому что её звенья можно подменять - например, отфильтровать на этапе текста лишние внутренние функции, чтобы диаграмма читалась чище.
Чтение диаграммы пламени по двум осям
Диаграмма пламени кажется загадочной, пока не усвоены две её оси, и тогда она читается с одного взгляда. По горизонтали откладывается доля времени: ширина каждой полосы показывает, какую часть выборок заняла эта функция. Чем шире полоса, тем больше времени проведено в этой функции. По вертикали откладывается глубина стека вызовов: нижняя полоса - точка входа, каждая полоса выше - функция, вызванная нижней.
Ключевой принцип чтения: искать широкие полосы наверху. Широкая полоса означает, что функция съела много времени. Если она вдобавок наверху стека, значит, время тратится в ней самой, а не в том, что она вызывает, - это и есть горячая точка, кандидат на оптимизацию. Широкая полоса внизу с узкими сверху означает, что время размазано по многим вызываемым функциям.
Важно понять, что горизонтальная ось - это не время по хронологии, а суммарная доля. Полосы не идут слева направо в порядке выполнения - они сгруппированы, чтобы одинаковые пути слились в широкие блоки. Это сбивает с толку тех, кто ждёт временной шкалы, но именно слияние делает горячие пути видимыми: множество мелких одинаковых вызовов сливается в одну заметную полосу.
Существует и перевёрнутый вариант диаграммы, растущий вниз, - так называемая сосулька. Он показывает то же самое, но удобен, когда интересны не листья дерева вызовов, а корни - откуда всё начинается.
Интерактивный просмотрщик добавляет гибкости
Статичная диаграмма хороша для общего взгляда, но для въедливого разбора удобнее интерактивный просмотрщик профилей. Один из распространённых - быстрый просмотрщик в браузере, куда профиль просто перетаскивают мышью. Он понимает разные форматы профилей и даёт переключать виды.
Главное его достоинство - несколько режимов отображения одного профиля. Помимо привычного вида диаграммы пламени, он умеет показывать профиль в хронологическом порядке, отсортировать стеки по тяжести слева, либо собрать вокруг одной функции всё, что её вызывает и что вызывает она. Эти виды отвечают на разные вопросы: один показывает общую картину горячих путей, другой - как нагрузка менялась во времени, третий - всё окружение конкретной подозрительной функции.
Чтобы скормить профиль такому просмотрщику, его выводят в подходящем формате из снятых данных. Интерактивность особенно ценна на больших профилях, где статичная картинка слишком мелка: в просмотрщике можно приблизить интересный участок, отфильтровать лишнее, поискать функцию по имени. Существуют и другие подобные просмотрщики, в том числе позволяющие поделиться профилем по ссылке, чтобы коллега увидел ровно то же место, где код тормозит.
Тонкость с символами и сравнение профилей
Чтобы профиль был осмысленным, а не набором адресов в памяти, нужны отладочные символы - они переводят адреса функций в их человекочитаемые имена. Без символов диаграмма пестрит непонятными адресами вместо имён функций. Поэтому профилируемое приложение стоит собирать с отладочными символами, а для некоторых сред выполнения требуются дополнительные шаги, чтобы профилировщик увидел имена функций, скрытые за оптимизациями времени выполнения.
Развитый приём - сравнение двух профилей, снятых при разных условиях. Сняв профиль на быстрой и на медленной системе, можно построить разностную диаграмму, подсветившую ровно то, что замедлилось. Это превращает поиск регрессии производительности из гадания в наглядное сравнение: на разностной картинке видно, какие именно функции стали отъедать больше времени.
# снять профиль и собрать свёрнутую форму для сравнения
perf script -i медленный.data | stackcollapse-perf.pl > медленный.folded
perf script -i быстрый.data | stackcollapse-perf.pl > быстрый.folded
Сопоставив две свёрнутые формы, строят диаграмму различий, где подсвечены подросшие участки. Так находят причину, по которой новая версия или иное окружение стали работать медленнее прежнего.
Что складывается в методику
Картина выстраивается ясно. Профиль работающего приложения снимают записывающим режимом профилировщика, прицепившись к процессу по номеру на заданное время, - без остановки и перезапуска, что бесценно для продакшена. Частота выборки около сотни в секунду обычно достаточна, а захват графа вызовов сохраняет цепочки до горячих функций.
Сырой профиль громоздок, поэтому его превращают в диаграмму пламени цепочкой обработки или одной командой. Читают диаграмму по двум осям: ширина - доля времени, высота - глубина стека, а горячая точка - широкая полоса наверху. Горизонталь тут не хронология, а суммарная доля. Интерактивный просмотрщик добавляет режимы и масштабирование для въедливого разбора. И всюду нужны отладочные символы, чтобы видеть имена функций, а сравнение двух профилей наглядно ловит регрессию.
Главная мысль: измерить производительность можно, не останавливая приложение, - профилировщик наблюдает со стороны, пока оно работает. Сырые данные нечитаемы, но диаграмма пламени превращает их в карту, где горячий путь виден по широкой полосе наверху. Стоит освоить снятие профиля на ходу и чтение диаграммы по двум осям, и оптимизация перестаёт быть гаданием - она опирается на точную картину, где код проводит время, снятую прямо в бою.