Php профилирование кода. Профилирование и отладка php-приложений с помощью xhprof

Профилирование PHP-кода

Рано или поздно каждый из нас сталкивается с унаследованным кодом и его оптимизацией. Дебаггер и профилировшик в такой ситуации - лучшие помощники программиста. У тех кто работает с PHP, благодаря Дерику Ретансу (Derick Rethans) есть хороший инструмент - xDebug. Информации касательно xDebug много даже в рунете, поэтому речь в этой статье пойдет не о нем.

Наткнувшись на упоминание о профилировщике для PHP я сразу подумал об xDebug (о проприетарных инструментах от Zend я давно уже успел позабыть), но на этот раз ошибся - речь пойдет об XHProf.
XHProf

Этот профилировшик был разработан специально для Facebook, а исходный код его был открыт в марте 2009 года.

Установка прошла достаточно быстро и гладко.
wget pecl.php.net/get/xhprof-0.9.2.tgz
tar xvf xhprof-0.9.2.tgz
cd xhprof-0.9.2/extension/
phpize
./configure && make && make install
cd /usr/local/etc/php.d/
vim xhprof.ini
cd /usr/local/
vim header.php
vim footer.php
vim etc/php.ini
/etc/init.d/php-fpm restart
cp vhost.conf.template prof.my.conf
sed -i s/site/prof/ prof.my.conf
vim prof.my.conf
/etc/init.d/nginx restart

Разберем упомянутые конфиги

Xhprof.ini
extension=/usr/local/lib/php/extensions/no-debug-non-zts-20090626/xhprof.so
xhprof.output_dir="/home/max/www/profile/"

Prof.my.conf - конфиг нгинкса - самый стандартный.

Server {
listen 80;
server_name prof.my;
charset utf8;

Root /usr/local/src/xhprof-0.9.2/xhprof_html ;
location / {
index index.php;
}

Location ~ \.php$ {
fastcgi_pass 127.0.0.1:12000;
fastcgi_index index.php;
fastcgi_param SCRIPT_FILENAME /usr/local/src/xhprof-0.9.2/xhprof_html/$fastcgi_script_name;
include fastcgi_params;

В /usr/local/src/xhprof-0.9.2/xhprof_html лежат PHP-исходники, создающие неплохой WEBGUI к профайлеру.

Итак о двух главных файлах:

Header.php

include_once "/usr/local/src/xhprof-0.9.2/xhprof_lib/utils/xhprof_lib.php";
include_once "/usr/local/src/xhprof-0.9.2/xhprof_lib/utils/xhprof_runs.php";
xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY);
}
}

Footer.php
if(isset($_COOKIE["xhprof"])){
if (extension_loaded("xhprof")) {
$profiler_namespace = "myapp"; // namespace for your application
$xhprof_data = xhprof_disable();
$xhprof_runs = new XHProfRuns_Default();
$run_id = $xhprof_runs->save_run($xhprof_data, $profiler_namespace);

// url to the XHProf UI libraries (change the host name and path)
$profiler_url = sprintf("http://prof.my/index.php?run=%s&source=%s", $run_id, $profiler_namespace);
echo << Profiler output
OUT;
}
}

Теперь запускаем любой PHP-скрипт через веб и видим в левом верхнем углу ссылку на вывод профилировщика - именно для этого и был создан хост prof.my

Обратите внимание - я использую проверку на COOKIE! При такой проверке можно безопасно использовать профилировщик на production-сервере - на реальных данных и реальной загрузке.

Веб-интерфейс профилировщика выводит таблички с информацией о каждой функции и сообщает следующую информацию:

• Число вызовов каждой функции
• Wall-time, время затраченное на выполнение функций (включая ожидание ответов от сокетов, файловой системы и т.д.).
• CPU-time, время затраченное на выполнение функций (исключая ожидание ответов от сокетов, файловой системы и т.д.).
• Использование памяти
• Пиковое использование памяти

Есть возможность сортировки таблицы по любому из параметров

Информация по каждой функции делится еще на два вида Inclusive и Exclusive. Inclusive включает цифры использованные дочерними вызовами, а Exclusive не включает их. Так же есть возможность, кликнув на название функции увидеть информацию только по ней и функциям из которых она вызывалась и которые вызывались ей.

Если в системе установлен GraphViz, профилировщик нарисует вам граф вызовов.

P.S. Не нарушая традиций: это мой первый пост на хабре.

UPD: перепостил в PHP.

Установка xhprof для php:

Sudo apt-get install php5-xhprof

Перезапускаем Apache:

Sudo service apache2 restart

Распечатываем phpinfo(); и проверяем подключился модуль или нет?

Проверяем /etc/php5/apache2/conf.d появилась ли там ссылка на конфиг xhprof.ini.

Если нет, то создаем линку сами и перезапускаем apache.

Sudo ln -s /etc/php5/mods-available/xhprof.ini /etc/php5/apache2/conf.d/20-xhprof.ini sudo service apache2 restart

Проверяем подключение xhprof, проверяем подключен ли 20-xhprof.ini:

На скрине указана версия 0.9.2, хотя при инсталяции отобразилась версия 0.9.4, но это нам не помеха.

Теперь можем профилировать наш код.

1. В начале страницы включаем профайлинг с помощью xhprof_enable();
2. В конце страницы выключаем профайлинг с помощью xhprof_disable() и сохраняем собранные данные с помощью save_run();
3. Далее анализируем.

Функция xhprof_enable() принимает в качестве аргументов флаги:

XHPROF_FLAGS_CPU для фиксирования статистики процессора,

XHPROF_FLAGS_MEMORY - для памяти,

XHPROF_FLAGS_NO_BUILTINS - для игнорирования встроенных функций.

Для сохранения и дальнейшего разбора полетов, нам необходимо установить инструмент для анализа профайла.

Скачиваем архив с инструментом анализа со страницы xhprof: , берем версию 0.9.4.

У на сервере или локальном ПК создаем папку доступную через localhost или отдельный домен, в который разархивируем скачанный архив:

Теперь мы можем сохранять профайл.

Https://xn--d1acnqm.xn--j1amh/altadmin/posts/edit/188

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

// Инициализируем профайлер - будем считать и процессорное время и потребление памяти xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY);
// Профилируемый код # Останавливаем профайлер $xhprof_data = xhprof_disable(); # Сохраняем отчет и генерируем ссылку для его просмотра include_once "/var/www/html/xhprof-0.9.4/xhprof_lib/utils/xhprof_lib.php"; include_once "/var/www/html/xhprof-0.9.4/xhprof_lib/utils/xhprof_runs.php"; $xhprof_runs = new XHProfRuns_Default(); $run_id = $xhprof_runs->save_run($xhprof_data, "xhprof_test"); echo "Report: http://localhost/xhprof-0.9.4/xhprof_html/index.php?run=$run_id&source=xhprof_test"; echo "\n";

/var/www/html/xhprof-0.9.4 - путь к папке которую мы разархивировали в ней необходимые нам библиотеки.

Report: http://localhost/xhprof-0.9.4/xhprof_html/index.php?run=57c32f3095d21&source=xhprof_test

Так выглядит анализ профайла. Эта таблица отображает все вызовы функций которые профилируются.

Мы можем сортировать функции кликая на заголовки таблицы.

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

Показатели:
Total Incl. Wall Time (время затраченное на выполнение функций с учетом ожидания ответов от сокетов, файловой системы и других ресурсов)
Total Incl. CPU (время затраченное на выполнение функций)
Total Incl. MemUse (использование памяти)
Total Incl. PeakMemUse (пиковое использование памяти)
Number of Function Calls (количество вызовов функций)

Еще есть возможность графического отображения отчета. Но для этого надо убедится что у вас установлена библиотека graphviz:

Apt-get install graphviz

После в профиле нужно нажать для отображения и вуаля:

Теперь можете анализировать и улучшать код.

An extension to PHP called Xdebug is available to assist in profiling PHP applications , as well as runtime debugging. When running the profiler, the output is written to a file in a binary format called "cachegrind". Applications are available on each platform to analyze these files. No application code changes are necessary to perform this profiling.

To enable profiling, install the extension and adjust php.ini settings. Some Linux distributions come with standard packages (e.g. Ubuntu"s php-xdebug package). In our example we will run the profile optionally based on a request parameter. This allows us to keep settings static and turn on the profiler only as needed.

# php.ini settings # Set to 1 to turn it on for every request xdebug.profiler_enable = 0 # Let"s use a GET/POST parameter to turn on the profiler xdebug.profiler_enable_trigger = 1 # The GET/POST value we will pass; empty for any value xdebug.profiler_enable_trigger_value = "" # Output cachegrind files to /tmp so our system cleans them up later xdebug.profiler_output_dir = "/tmp" xdebug.profiler_output_name = "cachegrind.out.%p"

Next use a web client to make a request to your application"s URL you wish to profile, e.g.

Http://example.com/article/1?XDEBUG_PROFILE=1

As the page processes it will write to a file with a name similar to

/tmp/cachegrind.out.12345

By default the number in the filename is the process id which wrote it. This is configurable with the xdebug.profiler_output_name setting.

Note that it will write one file for each PHP request / process that is executed. So, for example, if you wish to analyze a form post, one profile will be written for the GET request to display the HTML form. The XDEBUG_PROFILE parameter will need to be passed into the subsequent POST request to analyze the second request which processes the form. Therefore when profiling it is sometimes easier to run curl to POST a form directly.

Analyzing the Output

Once written the profile cache can be read by an application such as or Webgrind . PHPStorm, a popular PHP IDE, can also display this profiling data .

KCachegrind, for example, will display information including:

• Functions executed
• Call time, both itself and inclusive of subsequent function calls
• Number of times each function is called
• Call graphs
• Links to source code

What to Look For

Obviously performance tuning is very specific to each application"s use cases. In general it"s good to look for:

• Repeated calls to the same function you wouldn"t expect to see. For functions that process and query data these could be prime opportunities for your application to cache.
• Slow-running functions. Where is the application spending most of its time? the best payoff in performance tuning is focusing on those parts of the application which consume the most time.

Note : Xdebug, and in particular its profiling features, are very resource intensive and slow down PHP execution. It is recommended to not run these in a production server environment.

Профилирование приложения - это сбор данных о скорости выполнения различных участков программы (файлов и функций). Существует множество инструментов профилирования PHP, но не все инструменты подходят для проведения анализа прямо на рабочем сайте.

XHProf и его форк Tideways - удобный и простой профайлер, который способен эффективно собирать статистику о работе приложения почти без снижения скорости работы вашего приложения (или вашего сайта).

Зачем профилировать код?

Если приложение начинает работать медленно (читай «сайт начал тормозить»), профилирование позволит узнать, какая именно часть наиболее медленная. Результат профилирования обычно представляет собой список выполненных функций вместе со временем их выполнения.

Процедура профилирования кода должна идти первой в процессе оптимизации приложения. Любые другие действия будут догадками и, скорее всего, неправильными. Нужно знать, что именно вызывает проблемы и «тормоза».

Профилирование - это процедура сбора и организации статистики о времени выполнения кода. Это не процесс оптимизации либо изменения программ. Результатом этого процесса обычно является расширенный отчёт о компонентах программы, статистика выполнения функций.

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

Как подключить php-профайлер в автоматическом режиме?

Наши специалисты потрудились и сделали данный процесс абсолютно автоматизированным.
Вам достаточно авторизоваться в , во вкладке «Домены» выбрать нужный домен, кликнуть по иконке «PHP.INI + PHP Профайлер» и включить чекбокс «Профайлер для домена».

На включение данной функции может потребоваться некоторое время, обычно не более 10 минут.

Для php версий 5.2, 5.3, 5.4, 5.5, 5.6, 7.0 мы используем профайлер XHProf , для php версии 7.1 и выше мы используем профайлер Tideways .

После включения на каждой странице вашего сайта, обрабатываемой php, в нижнюю её часть будет встроен специальный блок со ссылками на файл отчёта (ссылка будет выглядеть примерно так:

Domain-name.com/xhprof-master/xhprof_html/index.php?run=XXXXXXXXXXXX&source=someapp)

А вот как будет выглядеть файл отчета:

Таблица содержит список функций, которые были выполнены в рамках одной страницы с дополнительной информацией:

• Calls - количество и процентное соотношение вызовов функции
• Incl. Wall Time - время выполнения функции с вложенными функциями
• Excl. Wall Time - время выполнения функции без вложенных функций
• Incl. CPU - процессорное время с вложенными функциями
• Excl. CPU - процессорное время без вложенных функций
• Incl. MemUse - потребление памяти с вложенными функциями
• Excl. MemUse - потребление памяти без вложенных функций
• Incl. PeakMemUse - максимальное потребление памяти с вложенными функциями
• Excl. PeakMemUse - максимальное потребление памяти без вложенных функций

Нужно заметить, что отчет, построенный с помощью tideways, может немного визуально отличаться от этого отчета, но суть от этого не меняется.

Графические отчеты

Ресурсоёмкие участки кода выделены желтым (средние) и красным (самые тяжёлые). Это те участки кода, которые используют множество ресурсов относительно всей остальной программы. Это может быть одна медленная функция или большое количество вызовов быстрой функции. В нашем примере мы видим, что функция mysqli_multi_query() помечена красным из-за того, что выполняется медленнее всего.

Агрегатные отчеты

Интерфейс XHProf также позволяет просматривать агрегатную информацию сразу с нескольких отчетов. Для этого run_id передаются через запятую:

Domain-name.com/xhprof-master/xhprof_html/index.php?run=XXXXXXXXXXXX,YYYYYYYYYYY&source=someapp

Технические особенности

Автоматическое включение профайлера реализовано с помощью директив auto_append_file и auto_prepend_file , которые подключают два исполняемых php файла:

— auto_append_file выполняет инициализацию объекта сбора статистики и запускает его работу;

— auto_prepend_file завершает сбор статистики и генерирует файл-отчет со статистикой (в формате JSON);

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

1. Таким образом обращение к любой странице, обрабатываемой php, будет инициировать создание нового файла отчета, поэтому мы рекомендуем отключить профайлер после сбора статистики (обычно для этого хватает нескольких часов), во избежание переполнения дисковой квоты, которая может исчерпаться после генерации большого количества отчетов!
2. Важно: профайлер будет работать только если сайт прикреплен к серверу по стандартному пути, автоматическими средствами (то есть, с помощью панели управления хостингом), в противном случае для настройки профайлера вам нужно обратиться в техническую поддержку Hostland.
3. В автоматическом режиме профайлер подключается только к основному доменному имени, к поддоменам автоматического подключение профайлера не предусмотрено.
4. В автоматическом режиме профайлер собирает статистику только скриптов с расширением.php и.php5
5. Не возможно гарантировать бесперебойную работу сайта после подключения php-профайлера, поэтому, в случае некорректной работы сайта во время включенного профайлера его следует отключить и продолжить профилирование другими средствами.

Подведём итоги

Мы будем надеяться, что данный инструмент поможет вам сделать ваши сайты еще более быстрыми на хостинге Hostland.

В статье частично использованы материалы пользователя Den Golotyuk размещенные на сайте

Последнее обновление: 12.01.2019 г.

Публикация: 09.01.2016 г.

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

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

Давай посмотрим, как это работает.

1. Необходимые условия

IDE PhpStorm может использовать информацию профилирования собранную с помощью инструмента Xdebug . Это расширение должно быть установлено и настроено в твоей системе. Для получения дополнительной информации смотри Руководство по установке Xdebug .

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

Внимание

Xdebug не совместим с IonCube. IonCube - это инструмент (утилиты) для защиты ПО, написанного на языке программирования PHP. Отключи расширение IonCube совсем или на время использования Xdebug. Ещё одна вероятная проблема может состоять в том, что Xdebug по умолчанию настроен на порт 9000 и он же используется в Open Server. Для её решения следует в одном из случаев изменить номер порта.

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

2. Включение профайлера Xdebug

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

Конфигурирование Xdebug осуществляется через директивы в активном php.ini файле. При любом способе включения профайлера необходимо настроить следующую директиву:

xdebug.profiler_output_dir = /path/to/store/snapshots

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

2.1. В глобальном масштабе

Чтобы включить профайлер Xdebug в глобальном масштабе необходимо использовать нижеуказанную директиву:

xdebug.profiler_enable = 1

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

2.2. С помощью дополнительных параметров интерпретатора

Включить профайлер с помощью дополнительных параметров интерпретатора можно в окне Run/Debug Configurations . Для его открытия используй следующие пункты главного меню IDE:

Опция (отмечена красным контуром на скриншоте выше) Interpreter options (параметры интерпретатора) секции Command Line (командная строка) должна содержать следующую строку:

D xdebug.profiler_enable = 1

Такой вариант позволит тебе использовать профайлер для конкретной конфигурации, а не в глобальном масштабе.

2.3. С помощью специальных GET/POST параметров или cookie файла

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

xdebug.profiler_enable_trigger = 1

Если значение директивы установлено в 1, то при выполнении сценария с GET/POST параметром или кукой с именем XDEBUG_PROFILE профилирование будет выполнено вне зависимости от установки xdebug.profiler_enable .

Данный вариант включения профайлера самый популярный.

3. Сбор логов профилирования

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

3.1. Сбор логов профилирования для веб-приложений

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

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

3.2. Сбор логов профилирования для CLI приложений и юнит-тестов

Для профилирования CLI приложений и юнит-тестов используй профайлер Xdebug глобально или создай отдельную конфигурацию запуска для включения профайлера с помощью окна Run/Debug Configurations . После чего запускай CLI приложение или юнит-тесты для сбора данных профилирования.

При анализе проблем производительности в юнит-тестах хорошим подходом является создание отдельной конфигурации запуска только тех юнит-тестов, в которых есть подозрения на проблемы с производительностью. Это позволяет собирать целевые логи профилирования.

4. Анализ описания лога профилирования

Давай подробнее рассмотрим лог профилирования.

4.1. Открытие лога профилирования

Для открытия лога профилирования используй следующие пункты главного меню IDE: .

Если ты являешься пользователем замечательной портативной серверной платформы Open Server, то для просмотра лога профилирования также можешь использовать кроссплатформенный инструмент Webgrind . Его можно найти через следующие пункты главного меню Open Server [Дополнительно → PHP профайлер] .

Логи профилирования сохраняются в папку согласно настроенной директиве xdebug.profiler_output_dir . Имя генерируемого файла всегда начинается с cachegrind.out. и заканчивается либо идентификатором процесса PHP или процесса веб-сервера или crc32 хэшем каталога, в котором находится профилируемый сценарий.

4.2. Вкладка Execution Statistics

Во вкладке Execution Statistics (статистика выполнения) ты можешь изучить сводную информацию о метриках исполнения каждой вызываемой функции. Ты можешь увидеть все файлы, вызовы функций, сколько раз они были вызваны, и время (абсолютное и относительное) выполнения каждой функции.

В верхней сетке отображаются различные метрики:

• Own Time (собственное время) - количество времени, которое функция затрачивает на выполнение своего кода (без учёта вызова других функций).

В нижней сетке отображаются две вкладки: Callees (вызываемые) - функции, которые сценарий вызывает здесь и Callers (вызывающие) - откуда сценарий был вызван. Ты можешь видеть различные метрики и здесь:

• Time (время) - общее время выполнения.
• Calls (вызовы) - количество вызовов.

Функции с большим собственным временем выполения или большим количеством вызовов, безусловно, требуют проверки.

4.3. Вкладка Call Tree

Во вкладке Call Tree (дерево вызовов) отображаются пути выполнения твоего кода. Тут ты можешь увидеть более подробную информацию о времени выполнении каждой функции и так далее.

В верхней сетке отображаются деревья вызовов (какие функции вызываются в других функциях) и другие метрики:

• Callable (вызванный файл) - файл, который был выполнен.
• Time (время) - общее время выполнения.
• Calls (вызовы) - количество вызовов.

В нижней сетке отображаются две вкладки: Callees (вызываемые) - функции, которые вызываются здесь и Callers (вызывающие) - откуда вызывается функция. Ты можешь видеть различные метрики и здесь:

• Callable (вызванная функция) - функция, которая была выполнена.
• Time (время) - общее время выполнения.
• Calls (вызовы) - количество вызовов.

Контрольные вопросы

1. Для чего профилируют PHP-приложения?
2. Сколько существует основных способов включения профайлера Xdebug?
3. Каким образом лучше действовать при профилировании CLI приложений и юнит-тестов?
4. С помощью каких инструментов можно проанализировать логи профилирования?
5. При анализе лога профилирования на какие метрики следует обратить внимание в первую очередь?