Когда сервис работает, но медленнее, чем надо, большинство первых вариантов диагностики заканчиваются примерно на метриках. Нагрузка по процессору видна, но куда именно уходят такты не говорит ни один счётчик в мире. Для этого существует профилировка: perf record снимает слепки стеков вызовов с рабочей системы в фоне, а пламенный граф показывает, в какой функции они расходуют своё время. В статье идёт вся дорога: от запуска на продакшене до чтения графа и выводов, с теми привычками, которые отличают полезное измерение от графической картинки.
Почему метрики не отвечают на вопрос о медленности
Метрики отвечают на вопрос сколько, а картина производительности нуждается в вопросе где. Цифры загрузки процессора и памяти всегда суммируются, потому что система не знает, для чего она это делает. Через час работы сервис наполовину загружен, но эта цифра не говорит, ушли ли такты на обработку запросов или на повторный ненужный расчёт строки в цикле. Анализ такого вопроса требует знать содержимое работы, а не её объём.
Главный вывод здесь один: до первого запуска профилировки полезно не придумывать диагноз, а собрать инструменты, потому что подтверждение ожиданий обычно оказывается мало похожим на правильный ответ. Ведь именно в этих случаях пропадает время просто из-за того, что в приложение проскользнула непредусмотренная подготовка данных, а исходники были исправлены год назад.
Запуск perf record и подготовка сервера
Снятие профиля на продаcшене выглядит проще, чем кажется: команда собирает слепки стеков вызовов с процессоров в течение заданного окна, а файл собирается в каталоге работы. На live-сервере важнее всего ограничить время и область наблюдения:
perf record -F 99 -a -g -- sleep 30
ls -lh perf.data
# прицельно на живой процесс
perf record -F 99 -p 4317 -g -- sleep 20
Флаг -F задаёт частоту отсчётов, -g собирает стеки вызовов, а переключатель -a переводит сбор на все процессоры. Файл с данными никогда не перезаписывает текущий рабочий каталог запуском приложения напрямую: проект открывается на чтении стека, и доступ к нему определяется параметром безопасности ядра. Именно поэтому на серверах с ограниченной политикой имеет смысл проверять параметр ещё до инцидента, а не в его разгаре, потому что странные анонсы об Недостаточных привилегиях могут получаться там, где их меньше всего ждут.
Дополнительно ценится в работе маленькая привычка: файл не переименовывается и не помещается в ходячий home-каталог под текущим пользователем, а сразу, при записи, получает имя с меткой конкретной проблемы и узла, иначе после пятого запуска данные людей превратятся в неразборчивый шифр.
Сборка графа, чтение пламени и живое наблюдение
Сырые данные читаются напрямую через perf report, но для картины расхода процессора по глубине привычнее привести их в формат flame graph. Рабочие скрипты преобразования живут в отдельном репозитории и берут на себя всю механику сборки:
perf record -F 99 -a -g -- sleep 30
perf script | ./stackcollapse-perf.pl > out.folded
./flamegraph.pl out.folded > profile.svg
Вся тяжёлая часть для системного администратора тут уже сделана: скрипт сворачивает повторяющиеся стеки в счётчик, генератор строит из него интерактивный граф для обзора. Дальше работа читателя графа заключается в одном: по уровням стека функций выясняется, какая часть дерева съедает такты, и неожиданные на первый взгляд ветви оказываются отнюдь не предусмотренными заранее.
Частоты дискретизации и накладные расходы
Главный тонкий параметр здесь это частота сбора отсчётов: чем она выше, тем подробнее картина и тем дороже её цена на живой машине. Практика начинается на уровнях ниже ста отсчётов в секунду, потому что этого хватает и для картины на несколько часов, и для разбора отдельных всплесков. Сотни отсчётов в секунду стоят лишь нескольких процентов ресурсов, и на обычной машине это разумный потолок. На самой нагруженной машине в стойке лучше брать окно короче, а частоту пониже, чем наоборот, потому что от глубины картины во времени пользы больше, чем от объёма.
Отдельный пункт касается многоядерных машин: когда процессоры сервера торгуют десятками, сбор по всем ядрам одним файлом компактно соединяет их в одну картину, и история на сервере читается в виде графа, а не в виде отдельных окон по ядрам. Достаточно запомнить сам подход к выбору частоты и окон: задача не "собрать побольше", а "собрать достаточно", чтобы следующий шаг уже не приходил в эту же дыру без вести.
Указатели кадров и построение графа вызовов
Глубина графа целиком стоит на точности сборки стеков, и она заслуживает отдельного разговора. Если программа собрана с оптимизациями без указателей кадров, стек вызовов в профиле виден частично, и глубокие кандидаты сливаются в плоские ленты. Для своих приложений следует предусматривать сборку с сохранением указателей рамок, и это единственное необходимое условие для значимого графа. Признак проблем с рамками на графике читается сразу: длинные стеки выглядят как оборванные ветки, где имена функций пропадают за порогом видимости.
Для библиотек сторонних вендоров, собранных без таких мер, задача решается другой механикой: current ядра умеет читать стеки через деревья вызовов, и при точной настройке прикладной сборки многие проблемы с кадрами проходят даже в таком режиме. Поэтому перед новым выпуском сервиса стоит иметь привычку быстро проверить снимок графа с сервера, и тогда потерянные стеки покажут себя заранее, а не при анализе инцидента.
Когда не нужен файл, а нужна картина, работает live-режим: утилита непрерывно собирает и сразу выводит активные функции, и это служит первым вопросом при раздумьях о том, нагружена ли машина или пуста. Вывод освежается каждую секунду и сортировка происходит по времени работы функции. Такой режим удобен как индикатор активной перемены: если профиль невозможно писать на работающую систему, одна мельница глазами индикатора часто выводит на верную гипотезу до снятия полного слепка.
При этом top не даёт глубины стека как граф, и в проблемных узлах, где верхняя функция укладывается в одну строку, live-режим не даёт ответа происхождения вызова. Поэтому разговор строят вдвоём: экран наблюдения в живую для обзора, а perf record с записью в файл позволяет удерживать стеки и разбирать медленные ветви с клиентами позже.
Утилита сборки профиля читает данные с ограниченного контура, а стандартные дистрибутивы навязывают уровень ограничений через параметр ядра perf_event_paranoid. На рабочих серверах из-за этого иногда не могут снасть полные стеки без прав суперпользователя, и хорошая привычка это проверить порог на начальных стадиях внешнего списка, а не в день машиностроения. Проверка выполняется одной командой чтения параметра, и подготовка с этой стороны занимает строчку в ансамбле конфигурации.
Дополнительная подготовка касается отладочных пакетов дистрибутива: без них имена динамических библиотек обрубаются до адресов, и граф выглядит как набор чисел. Эта привычка целенаправленно не дорога: на узлы автоматизированной инфраструктуры пакеты с отладочной информацией ставятся вместе с остальным старшим набором, и инцидент, ловящийся в час ночи, не заканчивается дополнительным ожиданием загрузки необходимых компонентов.
Пламенный граф это дерево вызовов с тем, сколько процентов времени проживал каждый лист, и правильное его чтение требует двух правил. Первое: смотреть не на ширину отдельных блоков, а на кумулятивную ширину ветвей, потому что конкретная функция редко набирает сколько сам по себе - она даёт размах именно через глубокие вызовы, а не через саму себя. Второе: deep path, где вызывается ветка процессора, обычно виден не по её имени, а по имени функции, делающей вызов, если она широкая. Тонкий раскадровка приводит в тупик, широкая ветвь у корня деревьев в определённо указывает на зарвавшиеся функции.
Практически полезно действовать глазами последовательно: сначала на самый широкий прямоугольник у самого корня, потом на ветвь под ним, и в местах, где дерево резко расширяется. Интерактивный граф допускает кликабельность, и углубление помогает сузить ветвь до конкретной проблемной функции. Для начала достаточно трёх вещей: найти самую широкую ветвь у основания, понять её родителя, и записать долю процессора по ней рядом. Иногда это единственное, что нужно для отчёта.
Отдельный пункт это привычка снимать снимки графа в разных частях дня. Процессор пользовательского пространства аккумулируется иначе ночью, нежели днём, и то, что выглядит как главная точка затрат во время подъёма, может оказаться не главным при нагрузке. Доказательный процесс обретает здесь ритуал: три прогона записи на час в течение суток, после чего графики ложатся рядом, и на поиске слияния корней удаляется половина ложных гипотез.
Практически: наиболее типичные широкие ветви это вызовы копирования буферов, пересчёты строк и работа драйверов, и широкие ветви у корня обычно происходят из выгрузок данных или из сетевого стека. Неожиданная горячая точка на медленных библиотеках на одном сервере указывает не на проблему в самой библиотеке, а в план её работы, потому что создатель графа обычно используется в пользовательском режиме.
Привычки съёма профиля на продакшене
Дисциплина профилировки на рабочем сервисе отличается умения на стенде: на живом сервере это аккуратность прежде всего, потому что загруженные машины не терпят лишнего наблюдения:
- ограничить окно записи первым запуском - двадцать или тридцать секунд, а не несколько минут;
- собирать на уровне всей машины в первый раз и узко для процесса во второй раз, чтобы средняя нагрузка была дважды прослежена во времени;
- записывать файл с постоянной меткой узла и темой: образец снимка без метки узла ни о чём не говорит спустя неделю;
- удалять файл после переноса на рабочую машину сразу после анализа, потому что данные профиля указывают на вызовы и пути, и они считаются формой отладочного лога;
- повторять съём на разных степенях нагрузки: то, что происходит ночью под нагрузкой иное, чем при минимуме.
Такие привычки позволяют профилировать горавшиеся процессоры без праздников, и команда не боится вносить их в эксплуатационный список регулярных наблюдений.
Ценность профиля проявляется только в измеримом результате, и для этого выводы фиксируются одним и тем же способом всегда: сначала снимается исходник до изменения, затем делается конкретная правка, например поправка кеша або переносы в функцию, и фиксируется новый снимок после него. Разница между двумя картинами по времени расхода по каждой функции кладёт последний камень в доказательство изменения: горячая ветка после правки должна весить меньше или вовсе исчезнуть. При этом позволяет и вторая проверка: смотрим нагрузочную разницу на живой системе на тех же запросах, и тогда ни рядовой обзор производительности, ни рабочий отчёт не выглядит чем-то эфемерным.
Дисциплина с запуском и измерением приучает ещё одну крайне полезную вещь: никакое изменение производительности не выставляется его дрожителями без проверочного измерения, и неожиданные кандидаты для замедления отключаются не по слухам о них, а по флажкам на графике. В эксплуатации эта привычка охраняет многие часы выработого переписывания, которые бездоказательно уходят от переписывания живого кода.
Когда perf не нужен и что делать вместо него
Несмотря на универсальность, профилировка обладает своими ограничениями: она показывает, куда расходуется процессор, но не говорит, сколько времени процесс простаивает. Для ожидания ответов из базы или диска ответ доставляется точками событий и таймерами ожидания, а не профилировкой процессора. Поэтому отличный старт это посмотреть на perf stat за минуту, потому что он даёт долю программной и аппаратной работы, и только потом профилировать вглубь. Эта переход от ответа на формальный вопрос про скорость машины до представления проводится одной и той же утилитой, поэтому три шага не требуют дополнительного инструментария.