Главная » Хабрахабр » Liveprof покажет, когда и почему менялась производительность вашего PHP-приложения

Liveprof покажет, когда и почему менялась производительность вашего PHP-приложения

Меня зовут Тимур Шагиахметов, я PHP-разработчик в Badoo. Привет, Хабр!

В вопросах оптимизации PHP-приложений помощником является профайлер. Производительность приложения — один из важнейших критериев качества работы программиста.

Напомню: одним из инструментов для анализа производительности, когда непонятно, какие части кода повлияли больше всего на увеличение времени формирования ответа, является XHProf. Недавно мы рассказывали о том, какими инструментами пользуемся для профилирования. Это расширение для PHP, которое позволяет профилировать код на боевом сервере и впоследствии  улучшать его.

Для этого около года назад мы разработали Liveprof — инструмент для автоматического профилирования всех запросов с интерфейсом для анализа изменения производительности приложения. Но хотелось бы ещё иметь историю изменения производительности, чтобы можно было отследить, что и когда повлияло на её ухудшение, не так ли?

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

В этой статье я расскажу о деталях реализации и особенностях использования этого инструмента.

Немного об XHProf

Для начала несколько слов о возможностях самого XHProf. Это профайлер для PHP, написанный на C как расширение. Он был разработан в Facebook и выложен в открытый доступ. Имеет несколько форков (uprofiler, Tideways), полностью совместимых на уровне формата выходных данных.

Его использование сопряжено с некоторыми накладными расходами. XHProf расставляет таймеры вокруг всех вызовов функций/методов. Но они не такие большие и позволяют использовать его в продакшене.

Результатом работы XHProf является массив элементов в следующем формате:

$data = [ 'parentMethodName==>childMethodName' => [ 'ct' => 1 'wt' => 8 'cpu' => 11 'mu' => 528 'pmu' => 0 ] ];

, где

parentMethodName и childMethodName — родительский и дочерний методы соответственно;
ct — количество вызовов в контексте запроса;
wt — время выполнения запроса (состоит из времени, затраченного процессором, и времени ожидания ввода/вывода или ответа другого сервиса);
cpu — время, затраченное процессором на обработку запроса;
mu — изменение потребления памяти после вызова метода;
pmu — изменение пикового потребления памяти после вызова метода.

Также возможно наличие некоторых других параметров.

Для каждой операции профилирования получаем таблицу с набором параметров по каждому методу. XHProf также содержит инструменты для визуализации полученных таким образом результатов.

Например,

результат сортировки пузырьком


<?php class ArrayGenerator
return $array; }
} class BubbleSorter
{ public function sort(&$array): void { $len = count($array); for ($i = 0; $i < $len ; $i++) { for ($j = 0; $j < $len - $i - 1; $j++) { if ($array[$j] > $array[$j + 1]) { $this->swap($array[$j], $array[$j + 1]); } } } } private function swap(&$a, &$b): void { $tmp = $a; $a = $b; $b = $tmp; } public function isSorted(array $array): bool { $len = count($array); for ($i = 0; $i < $len - 1; $i++) { if ($array[$i] > $array[$i + 1]) { return false; } } return true; }
} class ArrayPrinter
{ public function print(array $array, string $delimiter = ' '): void { echo implode($delimiter, $array) . PHP_EOL; }
} xhprof_enable(); $n = 10;
$arrayGenerator = new \ArrayGenerator();
$array = $arrayGenerator->getRandomArray($n); $sorter = new BubbleSorter();
if (!$sorter->isSorted($array)) { $sorter->sort($array);
} $printer = new \ArrayPrinter();
$printer->print($array); $xhprof_data = xhprof_disable();

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

Также можно посмотреть на граф вызовов с подсветкой самых ресурсоёмких методов:

Но нам также важно видеть картину в целом. XHProf полезен для анализа производительности каждого запроса вручную. Для этого был разработан инструмент, который профилирует запросы в автоматическом режиме и позволяет анализировать их в веб-интерфейсе. Нужно понимать, как изменилась производительность с течением времени.

Liveprof: агрегируем результаты и храним историю

Как получить историю профилирования?

Производительность не бывает постоянной, и от запуска к запуску она колеблется. Для начала нужно настроить автоматический запуск профайлера и сохранение результатов. В результате мы получаем агрегированные результаты по каждому запросу, например, минимум, максимум, среднее и 95-й перцентиль. Чтобы избежать влияния таких колебаний, используем усреднённые данные нескольких запросов. Это помогает находить тяжелые вещи, которые могут вызываться не на каждый запрос.

У нашего инструмента есть и преимущества, и некоторые ограничения.

Что умеет агрегатор:

  1. Автоматическое профилирование каждого N-го запроса.
  2. Ежесуточное агрегирование собранных профилей.
  3. Возможность посмотреть графики изменения каждого параметра, измеренного профайлером. Например, wt, cpu,  mu, pmu, описанные выше.
  4. Посмотреть изменение производительности любого метода за определенный интервал.
  5. Флеймграф, построенный по последним агрегированным данным.
  6. Найти запросы, в которых вызывался определенный метод

Ограничения:

  1. Поскольку наш инструмент — агрегирующий, нельзя узнать производительность одного запроса (например, самого медленного) — результаты получаем усреднённые за последние сутки. Но этого достаточно, чтобы оценить общую динамику производительности. Если какой-то запрос просел в скорости выполнения, то изменятся среднее значение, 95-й перцентиль и максимальное время выполнения.
  2. Нельзя однозначно восстановить полный стек вызова, так как XHProf возвращает только уникальные пары «родитель — потомок» с суммой значений затраченных ресурсов.
  3. Погрешность времени выполнения запросов, связанная с накладными расходами XHProf. Разница не такая и большая, но ее надо учитывать при измерении времени выполнения запроса.

Как использовать профайлер

  1. Для начала профайлер нужно подключить к сайту или скрипту. Удобнее всего использовать инструмент для автоматического запуска профайлера:

    php composer.phar require badoo/liveprof # Run a script to configure database
    LIVE_PROFILER_CONNECTION_URL=mysql://db_user:db_password@db_mysql:3306/Profiler?charset=utf8 php vendor/badoo/liveprof/bin/install.php

    Он поддерживает версии PHP начиная с 5.4, и его использование сопряжено с минимальными накладными расходами, что позволяет использовать его в боевом окружении. Инструмент  автоматически определяет используемое расширение профайлера: XHProf, uprofiler или Tideways. При запуске нужно указать параметры подключения к базе данных и настройки профилирования.

    Пример использования в коде с настройками по умолчанию:

    <?php
    include 'vendor/autoload.php'; \Badoo\LiveProfiler\LiveProfiler::getInstance()->start();
    // Code is here

    Результаты профилирования сохраняются в базу данных. Раз в день происходит процесс агрегации. Для этого выбираются все записи по определённому запросу за день и вычисляются агрегированные функции по каждому из параметров. Функции агрегации можно расширить или переопределить.

    Сейчас доступны следующие:

    • минимум за день;
    • максимум за день;
    • среднее значение за день;
    • 95-й перцентиль за день.

  2. Для настройки агрегации и просмотра результатов используется веб-клиент агрегатора. Проще всего его установить в докер-контейнере:

    git clone https://github.com/badoo/liveprof-ui.git
    cd liveprof-ui
    docker-compose up web

  3. Перед первым запуском нужно настроить параметры подключения к базе данных, список полей и используемых агрегированных функций в файле конфигурации src/config/services.yaml. Затем выполнить скрипт установки:

    docker-compose exec web bash install.sh

  4. Надо прописать в крон автоматически запускаемые скрипты агрегации и очистки старых данных:

    # script aggregates all profiles for previous day, add it if you don't use a queue for aggregation jobs (parameter aggregator.use_jobs_in_aggregation=false)
    0 2 * * * docker-compose -f %PATH_TO_PROJECT%/docker-compose.yml run --rm --entrypoint '/usr/local/bin/php /app/bin/cli.php cron:aggregate-all-profiles' web
    # script removes old aggregated data, by default > 200 days
    0 1 * * * docker-compose -f %PATH_TO_PROJECT%/docker-compose.yml run --rm --entrypoint '/usr/local/bin/php /app/bin/cli.php cron:remove-old-profiles' web 200

  5. Для заполнения тестовыми данными можно запустить скрипт:

    docker-compose exec web php /app/bin/cli.php example:a-week-degradation

Описание интерфейса

Веб-интерфейс доступен по адресу: 127.0.0.1:8000.

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

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

Страница с полным списком вызванных методов позволяет быстро найти интересующий метод и посмотреть графики, перейдя на страницу с графиками:


Страница с флеймграфом последнего агрегированного запроса позволяет визуально определить самые тяжелые части.

Это связано с тем, что профайлер не возвращает полное дерево вызовов, а только пары «родитель — потомок». Использование XHProf накладывает некоторые ограничения по точности результата. Для флеймграфа нужно  иметь полное дерево вызовов. При этом если какая-то пара методов вызывалась из разных мест приложения, то в результате получим сумму затраченного времени.  При восстановлении такого дерева значения параметров нормализуется с учетом времени, затраченного родителями.


Страница со списком методов, которые стали работать медленнее в течение выбранного интервала.

Например, на скриншоте ниже можно увидеть, что метод ServiceApi::getAvailableServices() стал выполняться на 116 мс медленнее. Также по каждому методу можно посмотреть, какой из дочерних вызовов повлиял больше всего на производительность. Причиной тому стало добавление вызова ServiceApi::getGifts() (изменение на 56 мс) и увеличение числа вызовов метода ServiceApi::getConfigForList() с 1 до 5 (еще 50 мс):

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


Страница с поиском запросов, в которых вызывался конкретный метод.

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

Возможности кастомизации

Инструмент имеет широкие возможности для кастомизации:

  • можно добавить собственные агрегирующие функции, которые вычисляют некое значение на основе переданного массива значений параметра;
  • можно изменить базу данных для хранения профилей и агрегированных результатов (сейчас поддерживаются SQLite, MySQL и PostgreSQL, но можно использовать и другие из списка доступных для Doctrine DBAL);
  • можно переопределить как менеджер подключения к базе данных, так и реализовать свои методы получения данных;
  • можно использовать веб-интерфейс как в качестве самостоятельного проекта, так и внутри любого фреймворка (например, панели управления сайтом). Пример:

    public function profileListAction()
    { <i>//Some custom logic before</i> $this->checkPermissions(); $App = new \Badoo\LiveProfilerUI\LiveProfilerUI(); $Page = $App->getPage('profile_method_list_page'); return $Page->setData($data)->render();
    }

Заключение

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

Он доступен на GitHub: github.com/badoo/liveprof, веб-интерфейс — github.com/badoo/liveprof-ui.

Надеюсь, при участии сообщества он станет еще лучше. Инструмент находится в активной разработке и может содержать некоторые ошибки. В планах добавить поддержку других профайлеров помимо XHProf, а также расширить список поддерживаемых баз данных.

Будем рады комментариям и предложениям! Отзывы и вопросы по использованию присылайте нам в Telegram, баги и пулл реквесты — прямиком в GitHub.

Отдельная благодарность Григорию за идею и первую реализацию.


Оставить комментарий

Ваш email нигде не будет показан
Обязательные для заполнения поля помечены *

*

x

Ещё Hi-Tech Интересное!

[Перевод] Конфигурируйте Visual Studio в вашей организации с помощью .vsconfig

В Visual Studio 2017 Update 15.9 мы добавили возможность экспорта и импорта рабочей нагрузки и выбора компонентов в файл конфигурации установки Visual Studio. Разработчики могут импортировать эти файлы в новые или существующие установки. Проверка этих файлов в ваших исходных репозиториях ...

Тест-драйв nanoCAD СПДС Стройплощадка 8. Часть 1

Тест-драйв nanoCAD СПДС Стройплощадка 8 Мы начинаем публикацию тест-драйва по nanoCAD СПДС Стройплощадка. В первой части тест-драйва мы разберем работу со специальным инструментом Менеджер проектов, его основные функции и способы построения элементов стройгенплана. Во второй части тест-драйва мы рассмотрим построение ...