Профилирование PHP: как найти узкое место по цифрам

Страница генерируется 2,3 секунды. В коде — ни одного очевидного тяжёлого места: пара запросов к базе, шаблон, немного бизнес-логики. Пока не поставишь профайлер, ты гадаешь: то ли база тормозит, то ли автозагрузка классов, то ли сериализация ответа. Профилирование превращает догадки в раскладку по миллисекундам — и почти всегда результат оказывается не там, где вы ждали.

Разбираем, чем мерить PHP 8.x, какие цифры снимать и как отличить настоящее узкое место от шума. Оптимизацию самих запросов к базе не трогаем — это отдельная тема, здесь только про то, как найти, куда уходит время процесса PHP.

Три уровня измерения — не путайте их

Прежде чем ставить инструмент, определитесь, что именно измеряете. Три уровня дают три разные картины, и подмена одного другим — самая частая ошибка.

• Wall time¹ — реальное время от начала до конца запроса. Включает ожидание базы, сети, диска. Это то, что чувствует пользователь.
• CPU time — сколько процессор реально считал. Если wall time 2 секунды, а CPU time 200 мс — процесс 1,8 секунды чего-то ждал, и оптимизировать надо не код, а I/O.
• Память — пиковое потребление. Ломается независимо от времени: скрипт может укладываться в 100 мс и падать по memory_limit на большом массиве.

Практический вывод: сначала смотрите соотношение wall/CPU. Оно говорит, куда вообще копать, до того как вы открыли первый флеймграф.

Чем мерить в 2024 году

Инструментов много, но для PHP 8.x реально живы и поддерживаются три подхода. У каждого своя цена.

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

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

Как снять первый профиль Xdebug

Xdebug 3.x поставляется отдельным режимом. Профилирование включается через xdebug.mode, а не старыми директивами из версии 2 — если гайд советует xdebug.profiler_enable, он про устаревшую версию.

; php.ini или отдельный conf.d файл
; Xdebug 3.x
xdebug.mode=profile
xdebug.output_dir=/tmp/xdebug
; триггер, чтобы не профилировать каждый запрос
xdebug.start_with_request=trigger

С start_with_request=trigger профиль снимется, только если в запросе есть параметр XDEBUG_TRIGGER (в GET, POST или cookie). Иначе вы завалите диск cachegrind-файлами со всех запросов.

На выходе получаете файл cachegrind.out.*. Открывается в KCachegrind (Linux) или QCachegrind (macOS/Windows). Точное имя файла и формат — в разделе Profiling документации Xdebug для вашей версии; проверяйте там, если директивы не срабатывают.

В интерфейсе смотрите две колонки: Self — время в самой функции без вызванных ею, и Inclusive — вместе с потомками. Узкое место ищите по Self в топе списка. Если наверху висит функция автозагрузчика или PDOStatement::execute — это уже диагноз.

Что считать тревожной цифрой

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

1. CPU time — заметная доля wall time при работе с базой. Если запрос к базе занимает 800 мс wall, а PHP при этом жёг CPU 600 мс — вы, скорее всего, гоняете в цикле мелкие запросы (проблема N+1) и время уходит на разбор ответов, а не на саму базу.
2. Один вызов функции с числом обращений в сотни тысяч. В профиле смотрите колонку Count. Функция, вызванная 400 000 раз за один HTTP-запрос, — кандидат на кеширование или вынос из цикла, даже если каждый вызов быстрый.
3. Пик памяти близко к memory_limit. Снимайте memory_get_peak_usage(true) в конце скрипта. Если типичный запрос ест 110 МБ при лимите 128 — вы в одном большом ответе от 500-й ошибки.

Как снять цифры без профайлера прямо в коде

Для быстрой прикидки не нужен внешний инструмент. Стандартные функции PHP дают все три метрики:

<?php
// PHP 8.x
$startWall = hrtime(true);          // наносекунды, монотонный таймер
$startCpu  = getrusage();

// ... измеряемый участок кода ...

$wallMs = (hrtime(true) - $startWall) / 1e6;
$cpu    = getrusage();

// суммируем пользовательское и системное CPU-время
$cpuUserMs = ($cpu['ru_utime.tv_sec'] - $startCpu['ru_utime.tv_sec']) * 1000
    + ($cpu['ru_utime.tv_usec'] - $startCpu['ru_utime.tv_usec']) / 1000;

$peakMb = memory_get_peak_usage(true) / 1048576;

error_log(sprintf(
    'wall=%.1f ms, cpu_user=%.1f ms, peak=%.1f MB',
    $wallMs, $cpuUserMs, $peakMb
));

Используйте hrtime(true), а не microtime(true): hrtime — монотонный таймер, его не сдвинет синхронизация системных часов посреди замера. Ключи массива getrusage() зависят от платформы; на Windows часть полей будет нулевой — проверяйте вывод var_dump(getrusage()) на своём окружении.

Сэмплирование на проде через Excimer

Excimer — расширение от Wikimedia, ставится через PECL для PHP 8.x. Оно снимает стек по таймеру и строит агрегированный профиль почти без замедления, поэтому его можно держать включённым в бою на доле запросов.

<?php
// расширение excimer, интервал сэмплирования 10 мс
$profiler = new ExcimerProfiler();
$profiler->setPeriod(0.01);
$profiler->setEventType(EXCIMER_REAL); // wall time; EXCIMER_CPU — только CPU
$profiler->start();

// ... работа приложения ...

$profiler->stop();
// вывод в формате, который читает flamegraph.pl
$log = $profiler->getLog();
file_put_contents('/tmp/profile.txt', $log->formatCollapsed());

Файл в collapsed-формате скармливается генератору флеймграфов (скрипт flamegraph.pl из репозитория Brendan Gregg). Широкие плато на графе — это код, в котором процесс проводит больше всего времени. Точные имена методов Excimer и допустимые константы сверяйте в README расширения — API между версиями может отличаться.

Граничные случаи, где профиль врёт

• OPcache искажает первый запрос. С холодным кешем компиляция скриптов входит в замер. Прогрейте приложение перед снятием цифр, иначе оптимизируете компиляцию, а не свой код.
• Первый запрос после деплоя не показателен вообще. Autoloader тянет файлы с диска, соединения с базой ещё не в пуле. Мерьте установившийся режим.
• Xdebug сам искажает соотношение. Из-за высокого оверхеда на перехвате функции с миллионами вызовов выглядят тяжелее, чем в реальности без профайлера. Для точной картины по времени берите сэмплер.
• Один запрос — не статистика. Медиана по сотне запросов и один случайный замер могут расходиться в разы из-за GC, сборки OPcache и соседних процессов. Снимайте распределение, а не точку.

Что делать после первого профиля

План на следующий шаг, а не выводы:

• Снимите соотношение wall/CPU на установившемся режиме — оно решает, копать в код или в I/O.
• Если в топе Self висит база — идите профилировать SQL: EXPLAIN, лог медленных запросов. Это уже за рамками профиля PHP.
• Поставьте сэмплер на 1–5% продовых запросов и соберите флеймграфы за сутки: реальные узкие места видны только на боевом трафике.
• Заведите постоянную метрику пиковой памяти и p95 времени ответа — регрессию проще заметить по графику, чем ловить ручным замером.