Профилирование PHP под нагрузкой: где ломаются Xdebug и Blackfire

Прод на PHP 8.3 держал 400 запросов в секунду, пока кто-то не оставил включённым xdebug.mode=profile на одной ноде из четырёх. Эта нода стала отдавать ответы в 6–8 раз медленнее остальных, время генерации страницы выросло с 40 мс до 300+ мс, а через пару часов процесс FPM упёрся в лимит памяти и был убит OOM-киллером. Классическая иллюстрация того, что профайлер — это инструмент, который сам по себе меняет систему, которую измеряет. Разберём, что именно ломается первым у Xdebug и Blackfire, когда вы пытаетесь применить их под нагрузкой, и как этого избежать.

Две разные природы искажения

Xdebug и Blackfire решают одну задачу — показать, где тратится время и память, — но искажают измерения принципиально по-разному. Понимать это важно, потому что цифры, которые они возвращают, значат не одно и то же.

Xdebug в режиме профилирования — это инструментатор: он вставляет хук на каждый вход и выход из функции. Overhead пропорционален количеству вызовов функций. Код с миллионом мелких вызовов замедлится драматически, код из десятка тяжёлых операций почти не заметит разницы. Абсолютные тайминги в профиле Xdebug бесполезны — они завышены самим фактом инструментации. Полезны только пропорции: какая функция съела 60% времени относительно других.

Blackfire в базовом режиме тоже инструментирует, но у него есть механизм вычитания собственного overhead из итоговых цифр, поэтому его тайминги ближе к реальным. Однако само вычитание — это модель, и на коде с интенсивными системными вызовами или сетью она даёт погрешность.

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

Xdebug: что отваливается первым

Память и размер cachegrind-файлов

Первое, что ломается на реальной нагрузке, — не CPU, а диск и память. Каждый профилируемый запрос Xdebug пишет отдельный файл cachegrind.out.*. На нагруженном приложении с сотнями RPS каталог xdebug.output_dir забивается гигабайтами за минуты. Файлы копятся, диск кончается, а параллельная запись сотен профилей ещё и добавляет IO-задержку к каждому запросу.

Отсюда правило: профилирование Xdebug в режиме сплошного включения на проде под трафиком — не диагностика, а второй инцидент поверх первого.

Триггерный режим вместо сплошного

Xdebug 3.x умеет включать профилирование только по триггеру, а не на каждом запросе. Это единственный вменяемый способ подойти к продовой ноде, и то на ноде, выведенной из-под основного трафика.

; php.ini для PHP 8.3, Xdebug 3.3
xdebug.mode=profile
xdebug.start_with_request=trigger
xdebug.trigger_value=SECRET_TRIGGER
xdebug.output_dir=/var/log/xdebug
xdebug.profiler_output_name=cachegrind.out.%p.%r

При такой настройке профиль пишется, только если в запросе присутствует триггер — GET/POST-параметр XDEBUG_TRIGGER, cookie с тем же именем или переменная окружения. Вы дёргаете конкретный медленный эндпоинт с триггером, получаете один cachegrind-файл, всё остальное работает без overhead. Актуальные имена параметров сверяйте с документацией Xdebug вашей версии — механизм триггеров менялся между 2.x и 3.x.

Почему нельзя держать xdebug.mode=develop,debug на бою

Даже без профилирования сам факт загрузки расширения с включёнными develop или debug добавляет заметный overhead на переформатирование стектрейсов и проверку точек останова. На боевой ноде под трафиком в php.ini должно быть либо xdebug.mode=off, либо расширение не загружено вовсе. Разница между off и физическим отсутствием расширения на горячем коде тоже измерима.

Blackfire: что искажается под нагрузкой

Сэмплирование меняет картину latency

Blackfire профилирует не каждый запрос, а по команде — через CLI, браузерное расширение или периодические автоматические сэмплы. Профилируемый запрос идёт по «медленному» пути с инструментацией, непрофилируемые — по обычному. Это хорошо для прода: overhead не размазан по всему трафику. Но появляется другая ловушка.

Один-два сэмпла не репрезентативны. Если вы профилируете эндпоинт один раз и видите, что 200 мс ушло в запрос к базе, это может быть холодный кеш, попадание на реплику с лагом или блокировка от соседнего запроса. Под нагрузкой профиль отдельного запроса — это срез конкретного момента, а не среднее. Blackfire это частично закрывает агрегацией нескольких сэмплов, но за агрегацией нужно следить осознанно, а не верить одному профилю.

Wall time против CPU time

Главная ошибка чтения профиля под нагрузкой — путать wall time (реальное прошедшее время) с CPU time (время, когда процесс реально считал на ядре). Функция, висящая на ожидании ответа от Redis, покажет большой wall time и почти нулевой CPU. Под нагрузкой, когда ядер не хватает, процесс дополнительно ждёт своей очереди на планировщике — и это ожидание тоже попадёт в wall time, но к вашему коду отношения не имеет.

Blackfire разделяет эти метрики. Смотрите на CPU time, когда ищете, что оптимизировать в самом коде, и на wall time, когда ищете, где вы блокируетесь на IO. Перепутать — значит потратить день на оптимизацию функции, которая просто ждала базу.

Сравнение под реальной нагрузкой

Что ломается первым: порядок инцидентов

Если свести практику к последовательности, под нагрузкой отказывает именно в таком порядке:

1. Диск и память Xdebug при сплошном профилировании. Первое и самое частое. Каталог с cachegrind-файлами забивается, IO деградирует, FPM ловит OOM. Лечится триггерным режимом и выводом ноды из-под трафика.
2. Искажение таймингов, которое ведёт к оптимизации не того. Абсолютные цифры Xdebug принимают за правду, оптимизируют функцию с высоким overhead-множителем, на проде эффекта ноль.
3. Нерепрезентативный сэмпл Blackfire. Профилируют один запрос, ловят случайный медленный момент, делают вывод о системе.
4. Путаница wall time и CPU time. Оптимизируют код, который на самом деле ждал сеть или планировщик.

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

Рабочая последовательность для боевого приложения на PHP 8.x с PHP-FPM:

• Профилируйте на отдельной ноде, выведенной из балансировщика, но получающей реалистичную копию или долю трафика. Профилирование на пустом стенде не покажет проблемы, которые возникают только при конкуренции за ядра и соединения к базе.
• Для точечного разбора медленного эндпоинта используйте Xdebug в триггерном режиме — один файл на один вызов, читаете пропорции в KCachegrind или QCachegrind.
• Для картины «где система тратит время в целом» используйте Blackfire с несколькими сэмплами, смотрите на агрегат, разделяйте CPU и wall time.
• Ищете не абсолютные миллисекунды профайлера, а функции с непропорциональной долей — они одинаково видны у обоих инструментов, несмотря на разный overhead.
• Для непрерывного наблюдения на бою без ручного запуска смотрите в сторону непрерывного профилирования — у Blackfire есть режим постоянного мониторинга, но проверяйте его условия и overhead по актуальной документации, они меняются.

Что делать дальше

Начните с малого: соберите один честный профиль медленного эндпоинта через Xdebug в триггерном режиме на изолированной ноде и посмотрите на дерево вызовов в QCachegrind. Затем снимите тот же эндпоинт через Blackfire с 5–10 сэмплами под трафиком и сравните, совпадают ли выводы о горячей точке. Если Xdebug и Blackfire указывают на одну и ту же функцию — ей можно верить и заниматься оптимизацией. Если расходятся — значит, вы поймали либо overhead-артефакт Xdebug, либо нерепрезентативный сэмпл, и нужно собрать больше данных. Для продового наблюдения дальше смотрите на APM-метрики: p95/p99 latency по эндпоинтам и разбивку времени на CPU и ожидание — именно они подскажут, что вообще стоит нести в профайлер.