PHP – анализ производительности кода и поиск узких мест

Настоящим переворотом в мире PHP стал PHPUnit, который вышел в 2004 году (появилась версия 1.0). До появления этого инструмента тестировать по сути приходилось вручную, каждый раз проверяя, что ничего не поломалось. В такой схеме баги непреднамеренно появлялись на production серверах.

В настоящее время помимо PHPUnit существуют другие фреймворки для тестирования, такие как PHPSpec, Behat, Codeception.

С производительностью же (а точнее с написанием тестов по ее оценке) дела обстоят гораздо хуже. Большинство разработчиков этим просто не занимается. В больших компаниях есть целые отделы, чья работа как раз заключается в поиске различных багов, а также оценке производительности приложения. Может у разработчиков просто не хватает инструментов для анализа своих приложений, либо нужно долго изучать то, чем по сути занимаются тестировщики?

Производительность тем не менее оказывает не меньшее (а иногда и большее) влияние на восприятие пользователя при работе с приложением, чем пресловутые баги.
Вот пример того, как Амазон увеличил свои доходы, улучшив производительность. А вот – опыт Google, Yahoo, AOL, Shopzilla.

Если багам разработчики стараются уделять большое внимание, то о производительности (в малых компаниях) мало кто из них по-настоящему задумывается.

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

microtime(true);

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

Но решение есть, для мира PHP существует инструмент, который позволяет в короткие сроки протестировать код в любых условиях, в dev окружении, либо на production сервере с минимальным влиянием на пользователя. Этот инструмент – Blackfire.

Он позволяет понять, почему ваше приложение работает медленно.

CPU, память, сетевое взаимодействие, работа дисков. Все это влияет на ваше приложение, и каждый параметр нужно просматривать отдельно для более четкой картины работы приложения. И Blackfire в этом помогает. Также он показывает сколько раз была вызвана та или иная функция, сколько времени потребовалось на это, общее количество SQL запросов.

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

Изначально инструмент появился в качестве форка XHProf, но потом был переписан. Для установки перейдите на официальную страницу и следуйте инструкциям. Для работы вам понадобятся агент (работает в качестве сервиса, где вы регистрируйте id и токен сервера для работы с Blackfire API), установленное расширение для PHP, и клиент, которым по сути и будете пользоваться.

Также перед началом работ нужно будет создать аккаунт на Blackfire.io. Далее рекомендую поставить Blackfire companion – расширения для Chrome. С его помощью будете одной кнопкой запускать профайлинг. Также профайлинг можно запускать вручную при помощи клиента. Если при запуске клиента что-то пойдет не так, то можно посмотреть логи в

/var/log/blackfire/agent.log

Как все это выглядит можете посмотреть ниже.

В моем примере включены модули xdebug и xhprof. Вообще их рекомендуется выключать во время профайлинга, чтобы убрать оверхед, который эти инструменты накладывают. Но в качестве демонстрации я их оставил. В моем примере рассматривается приложение на Symfony. На примере видно, что много времени тратится на парсинг yml файлов, а также получение метаданных классов для Doctrine. По-умолчанию, сверху располагаются вызовы функций, которые отнимают больше всего времени. На них-то и стоит смотреть в первую очередь. На диаграмме очень наглядно отражается поток выполнения программы.

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

Для устранения этих проблем можно включить APC кэширование, оптимизировать загрузку классов через composer, включить кэш для доктрины. После этого можно запустить профайлинг заново и сравнить с предыдущими результатами. Сравнение – это одна из лучших фич blackfire, которая отсутствует у многих инструментов для профилирования. Вот пример из официальной документации, как это выглядит.

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

Обычно при анализе в первую очередь смотрят на время. Blackfire предоставляет для времени несколько метрик.

Во-первых, это Wall Clock Time или Wall Time (общее время) – это настоящее время выполнения кода. Если говорить о функции, то это время отсчитывается от момента, когда интерпретатор вошел в функцию, и до выхода из функции, т.е. считается непосредственно само тело функции. Это время зависит от того, сколько инструкций потратил CPU на вычисления, сколько памяти было использовано, сколько операции чтения с диска было произведено и сколько пакетов по сети отослано. Упрощая, можно выделить две основных пункта: это CPU time и I/O time.

Не помешает также различать inclusive (включающее) и exclusive (исключающее) время.
Распределение времени является достаточно сложной вещью. Давайте посмотрим на примере, как это происходит.

function foo()
{
  $a = new Bar();
  $count = $a->getCount();
  $str = '';
  for ($i = 0; $i < $count; $i++) { $str .= str_repeat('foo', 10); } $str = $a->sanitizeString($str);
  return $str;
}

При вызове метода foo() соответствующая нода будет добавлена на граф вызовов. Inclusive time – это время, которое потребовалось на выполнение всех строк кода внутри метода. Во время выполнения функции вызываются методы sanitizeString, getCount и функция str_repeat. Эти три вызова будут представлены дочерними узлами функции foo() на графе. Таким образом у foo() есть три вызываемых метода (callees), а sanitizeString имеет вызывающий метод (caller).
Inclusive time позволяет находить критические места в приложении.

Exclusive time – это время, потраченное на выполнение самой функций без вызовов дочерних узлов.

function foo()
{
    $a = new Bar();
    $count =
        $a->getCount();

    $str = '';
    for ($i = 0; $i < $count; $i++) {
        $str .=
            str_repeat('foo', 10);
    }

    $str =
        $a->sanitizeString($str);

    return $str;
}

Exclusive time позволяет найти функции, которые сами потребляют много ресурсов.

До этого мы рассмотрели пример профайлинга GET запроса. Но Blackfire позволяет профилировать POST, PUT, DELETE запросы, AJAX вызовы, а также консольные скрипты. Для этого понадобится CLI команда blackfire.

Выполните следующую команду и убедитесь, что client-id и client-token соответствуют вашему аккаунту.

blackfire config --dump

Для теста можете выполнить

blackfire curl http://gitlist.demo.blackfire.io/

и посмотреть результат.

Вывод будет примерно следующим

Profiling: [########################################] 10/10
Blackfire cURL completed
Graph URL https://blackfire.io/profiles/f8dadabc-ce36-4512-b7fd-a61819655ef6/graph
No tests! Create some now https://blackfire.io/docs/cookbooks/tests
No recommendations
Wall Time 17.8ms
CPU Time n/a
I/O Time n/a
Memory 1.4MB
Network n/a n/a -
SQL n/a -

Затем можно перейти по ссылке и посмотреть результаты более подробно.

Для профилировки скриптов можно использовать команду run.

blackfire run php -r 'echo "Hello World!";'

Можно сказать blackfire, чтоб он прогнал код несколько раз для получения усредненной оценки.

blackfire --samples=3 run php -r 'echo "Hello World!";'

Как же на самом деле работает Blackfire? Основная задача расширения Chrome либо клиента командной строки это добавить специальный флаг во время выполнения профайлинга. Для HTTP запроса это заголовок X-Blackfire-Query, для командной строки – это переменная окружения BLACKFIRE_QUERY. В этой переменной или заголовке запроса содержится сгенерированная цифровая подпись, которая затем проверяется расширением blackfire. Подпись может быть невалидна, либо пользователю не разрешено запускать профайлинг на этой машине, тогда blackfire не позволяет выполнить дальнейшую работу.

Теперь вы можете самостоятельно составить запрос, используя стандартные инструменты

# замена blackfire curl
blackfire run sh -c 'curl -H "X-Blackfire-Query: $BLACKFIRE_QUERY" http://example.com/ > /dev/null'
# wget вместо cURL
blackfire run sh -c 'wget --header="X-Blackfire-Query: $BLACKFIRE_QUERY" http://example.com/ > /dev/null'

Для httpie можно сделать так

blackfire run sh -c 'http --json PUT example.org name=Fabien "X-Blackfire-Query:$BLACKFIRE_QUERY" > /dev/null'

Blackfire поддерживает работу с окружениями. При помощи окружений можно

• разграничить права доступа отдельным пользователям
• изолировать профили, т.е. делать сравнения отдельно для разных машин (dev, staging, production)
• различные настройки для разных машин. Например, какие-то уведомления для production серверов.

Эта фича доступна только в платной версии, как и анализ SQL запросов, профайлинг HTTP запросов и многое другое.

Blackfire позволяет вам писать произвольные утверждения для анализа производительности приложения. Вот пример из документации

tests:
     "All pages are fast":
         path: "/.*"
         assertions:
             - main.wall_time < 50ms
             - main.memory < 2Mb

Эти утверждения пишутся в файле .blackfire.yml. В примере выше говорится, что на всех страницах время работы должно быть менее 50 миллисекунд и потребление памяти менее 2 Mb. Утверждения объединяются в группы, называемые метриками. Сами утверждения представляют собой некую характеристику заданной метрики. Список доступных метрик можно посмотреть на этой странице. Можно писать свои кастомные метрики, отслеживать сколько раз был вызван тот или иной метод, сколько памяти он израсходовал. Список доступных характеристик для метрик приведен ниже:

• count
• wall_time
• cpu_time
• memory
• peak_memory
• io
• network_in
• network_out

Выглядит все это таким образом

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

Для контроля таких ситуаций существуют специальные метрики

- metrics.symfony.processes.count < 10
- metrics.http.requests.count < 5
- metrics.parses.count == metrics.cache_driver.count
- metrics.sql.queries.count < 10
- metrics.sql.connections.count <= 1
- metrics.redis.connections.count <= 1
- metrics.amqp.connections.count <= 1 

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

# убираем компиляцию Twig/Smarty
- is_dev() or metrics.twig.compile.count == 0
- is_dev() or metrics.smarty.compile.count == 0

# нет проверки метаданных
- is_dev() or metrics.symfony.config_check.count == 0

# нет парсинга Doctrine
- is_dev() or (metrics.doctrine.annotations.parsed.count + metrics.doctrine.annotations.read.count + metrics.doctrine.dql.parsed.count + metrics.doctrine.entities.metadata.count + metrics.doctrine.proxies.generated.count) == 0

# YAML не загружается
- is_dev() or metrics.symfony.yaml.reads.count == 0

# Assetic controller не должен быть вызван
- is_dev() or metrics.assetic.controller.calls.count == 0

Еще одна тема, которую стоит осветить – это профилирование скриптов-демонов. Для этих случаев blackfire предоставляет SDK. Наберите следующую команду.

composer require blackfire/php-sdk

Вот пример скрипта из документации

require_once DIR.'/vendor/autoload.php';
use Blackfire\Client;
function consume()
{
    echo "Message consumed!\n";
}
$blackfire = new Client();
for (;;) {
    $probe = $blackfire->createProbe();
consume(); $profile = $blackfire->endProbe($probe); print $profile->getUrl()."\n"; usleep(10000);
}

Тут наш код мы оборачиваем методами createProbe и endProbe. Можно не снимать показания каждый раз, а делать это раз в n итераций. Для этого существует класс LoopClient. Для достижения максимальной гибкости blackfire предусматривает использование сигналов. Можно из какого-нибудь скрипта слать сигнал blackfire, а тот в свою очередь произведет снятие метрики. Более подробно можно посмотреть в документации.

Также SDK можно использовать для написания своих тестов, используя PHPUnit.

Например, можно померить Wall Time прямо в тесте

use Blackfire\Profile\Configuration;
public function testIsWallTimeOk()
{
    $config = new ProfileConfiguration();
    $config->assert('main.wall_time < 50ms', 'Wall Time is too high'); $this->assertBlackfire($config, function () {
        doSomething();
    });
}

Еще одним отличным инструментом blackfire является плеер. Можно создать файл gitlist.yml примерно такого содержания

scenario:
  options:
    title: GitList Scenario
    endpoint: http://gitlist.demo.blackfire.io/

  steps:
    - title: "Homepage"
      visit: url('/')
      expect:
        - status_code() == 200
        - header('content_type') matches '/html/'
        - css('footer').text() matches '/Powered by GitList/'

Затем запустить указанные шаги при помощи команды

blackfire-player run gitlist.yml -vv

Этот инструмент поможет вам при выполнении интеграционного тестирования. Последним шагом использования blackfire является его интеграция в CI систему. При помощи системы вебхуков можно очень гибко управлять оценкой производительности приложения. В ряде случаев это поможет избежать регрессии вашего кода.

Blackfire – это отличный инструмент, который позволит оценить производительность приложения на каждом этапе жизненного цикла.