Профилирование PHP кода в Badoo XHProf aggregator

[email protected] https://www.linkedin.com/in/kuzovnikov/ Григорий Кузовников Разработчик Badoo

Время ответа на запрос

Время ответа на запрос rusage

Время ответа на запрос

Результаты • ответ в среднем быстрее на 25мс; • это на 20% быстрее; • на 20% меньше памяти и rusage на кластере

Причины • быстро меняется код; • нагрузка растёт; • гибкий API.

Инструменты профилирования

XDebug Плюсы • хороший отладчик; • интеграция с IDE. Минусы • отладчик возможностями профайлера; • искажает результаты; • не стоит запускать в бою.

Pinba Плюсы • Минимально искажает результаты • Включается руками в нужных методах • Можно вызывать часто Минусы • Не включить для всех методов • Нет контекста вызова

XHProf Плюсы • минимально искажает результаты; • можно запустить изнутри PHP кода; • подходит для production-а. Минусы • нет отладчика, но нам он и не нужен

Другие профайлеры Z-Ray, Blackfire, Tideways, … Возможности • дерево вызовов; • отчёты по нескольким профилям; • SQL запросы. Минусы • нет истории; • нет перцентилей.

XHProf

• sudo pecl install -f xhprof • php.ini: extension=xhprof.so • Health and Safety Использование

• php extension в 2000 строк кода на C; • проксирует вызовы функций, измеряет их; • возвращает результат в виде массива; • массив пакуется в строку, сжимается и кладётся в базу. Как работает XHProf

No content

No content

Что неудобно • статистика по одному вызову; • много шума; • нет истории.

XHProf aggregator

Скрипт на коленке [email protected]:~> php xhprof_console.php f.php \Fetching data... SQL request start SQL done Fetched 300 rows; 606M memory used Fetched all rows Aggregating... PATH: -> main() ==== Self Stat ==== # AVG_CT min_ct max_ct min_wt AVG_WT PERCENT_WT max_wt mark method 1.00 1.00 1.00 85,226 235,324 455,160 887,596 main() ==== Children ==== # AVG_CT min_ct max_ct min_wt AVG_WT PERCENT_WT max_wt mark method 1 1.00 1.00 1.00 85,203 235,302 455,129 887,564 MobileFrontController::run ==== Parents ==== # AVG_CT min_ct max_ct min_wt AVG_WT PERCENT_WT max_wt mark method command (q|0 - go back|1|2|3|...|m1|m2|m3|...|wts1|wts2|...) >

Терминология • профиль — результат работы XHProf; • снапшот — статистика из нескольких профилей; • Application – название приложения, от которого был запрос; • Label – произвольная строка, которой помечаются однотипные профили (в нашем случае Label – название метода API).

Что собираем • все вызовы API (не чаще раза в минуту); • запуски профайлера вручную. Как собираем • специальный метод для запуска профайлера; • результаты пишутся в базу на shutdown-е.

Аргегатор • запускается по ночам; • пересчитывает снапшоты за вчера, агрегируя по паре app + label; • считаем: среднее, 90-ый перцентиль, min, max; • считаем для: memory, rusage, wall time.

No content

No content

No content

No content

No content

No content

t I II III IV

Результаты • история изменения всех API методов; • быстрый поиск проблем производительности; • одного xhprof aggregator недостаточно.

В заключение

Наша статистика • ~1200 снапшотов в день; • ~5Мб на снапшот; • через год будет 2Тб; • пересчёт занимает 3.5 часа в 6 потоков; • пересчёт каждого снапшота требует от 50мб до 2Гб памяти; • в каждом снапшоте сагрегированные данные от 1 до 1440 профилей.

Планы • улучшить интерфейс; • учесть пожелания коллег; • вывести в opensource.

XHProf Console https://github.com/badoo/xhprof_console • Health and Safety • настройки заполняются в специальный файл; • извлекает данные; • аггрегирует; • выводит статистику в консоли; • позволяет ходить по дереву вызовов.

Thank you!