Pull to refresh

Tracing PHP Applications with xdebug

Reading time 8 min
Views 22K
Original author: Stefan Priebsch
Добро пожаловать во вторую серию нашего повествования про xdebug. Установка xdebug и его базовые возможности были рассмотрены в первой серии. В данной статье мы рассмотрим трассировку программы.
Предыдущая серия цикла Introducing xdebug

Создание лога трассировки

Вместо ручного добавления различных функций вывода отладочной информации мы можем воспользоваться xdebug для создания лога трассировки. Лог трассировки это список вызовов функций и методов класса на всем протяжении выполнения скрипта. Преимущество заключается в том, что каждый вызов найдет свое отражение в логе
Лог трассировки обычно различается от запуска к запуску, так как он зависит от входящих данных, которые различаются от запроса к запросу.
Отслеживание лога трассировки помогает нам понять, как происходит выполнение нашей программы, однако очень сложно визуализировать все возможные ветвления, если только наша программа не является очень простой. Один if предполагает два возможных пути развития программы. С каждым дальнейшим if количество (теоретически) возможных путей развития умножается на 2. Именно из-за этого тестирование больших программ достаточно сложно: слишком много различный путей развития и каждый необходимо протестировать.
А сейчас приступим к созданию лога трассировки. xdebug поддерживает два различных формата для логов. По умолчанию логии создаются в приятном для человеческого глаза формате, их удобно читать и анализировать. Если вы хотите обработать лог трассировки какой-либо программой (предназначенной для обработки логов xdebug), необходимо сконфигурировать xdebug в другом формате. Такой формат (computer-readable) легко обрабатывается программой (анализатором логов), потому что он содержит колонки фиксированной длины
Если вы хотите получить лог трассировки для каждого запускаемого вами скрипта, добавьте следующие команды
xdebug.auto_trace=On
xdebug.trace_output_dir=c:\data

в php.ini. Не забудьте перестартовать ваш веб-сервер после изменения php.ini.
Вторая строка определяет путь, по которому xdebug будет сохранять логи. По умолчанию этот путь установлен в /tmp, это хороший выбор для, но вызовет проблемы в Windows, так как c:\tmp (считается что c: это текущий диск) обычно не создана. Поэтому необходимо создать каталог в Windows (или прописать существующий), в который xdebug будет сохранять логии трассировки, иначе ничего не получится.
Выполнение функций и методов будут очень медленными так как каждый их вызов, а также результаты будут записаны в лог.

Трассировка части приложения

Так как размер лога трассировки очень быстро растет, хорошим решением является создать лог только для «интересных» частей приложения, например, создание лога трассировки на этапе инициализации.
Давайте посмотрим как создать лог трассировки для маленькой рекурсивной функции (вычисление факториала), в данном примере мы начнем и закончим трассировку в реальном времени. Если вы активировали трассировку в php.ini, вы увидите предупреждение, что трассировка уже начата для вашего скрипта.
xdebug_start_trace('c:/data/fac.xt');
print fac(7);

function fac($x)
{
    if (0 == $x) return 1;
    return $x * fac($x — 1);
}

xdebug_stop_trace();

Как вы можете видеть по пути и названию файла, программа запущена в Windows. Если вы работаете в Unix, вы должны использовать другое имя файла. Функция xdebug_start_trace начинает запись трассировки, а xdebug_stop_trace останавливает. Когда этот код будет запущен, будет сформирован приблизительно такой лог файл:
TRACE START [2007-10-26 12:18:48]
  0.0068  53384  -> fac() C:\www\fac.php:5
  0.0069  53584   -> fac() C:\www\fac.php:10
  0.0069  53840    -> fac() C:\www\fac.php:10
  0.0070  54096     -> fac() C:\www\fac.php:10
  0.0070  54376      -> fac() C:\www\fac.php:10
  0.0071  54656       -> fac() C:\www\fac.php:10
  0.0072  54936        -> fac() C:\www\fac.php:10
  0.0072  55216         -> fac() C:\www\fac.php:10
  0.0073  55392  -> xdebug_stop_trace() C:\www\fac.php:13
  0.0237  55392
TRACE END [2007-10-26 12:18:48]

В каждой строке первая колонка показывает общее время запуска кода. Вторая колонка показывает количество памяти, которое скрипт занимает в данный момент. Последняя колонка показывает файл, строку и название функции. xdebug делает отступы для каждой функции в соответствие с местом в стеке вызов для удобочитаемости.
Если вы хотите чтобы xdebug показывал разницу в использовании памяти, добавьте
xdebug.show_mem_delta=On

в php.ini. Разница – это различие между использованием памяти между текущей строкой и предыдущей. Вы можете добавить данную настройку во время выполнения используя функцию ini_set, но только после того как начнется трассировка.
Функция xdebug_start_trace имеет второй необязательный параметр. Вы можете использовать один или больше из трех следующих настроек: XDEBUG_TRACE_APPEND добавляет к существующему файлу трассировки. Когда установлен XDEBUG_TRACE_COMPUTERIZED, xdebug создает лог трассировки в формате удобном для чтения программой-анализатором. Использование этого параметра такое же, как и установка параметра xdebug.trace_format в 1. Параметр XDEBUG_TRACE_HTML устанавливает формат лога трассировки в виде HTML.
Следующий скриншот показывает HTML-формат лога трассировки:


Добавление информации в лог трассировки

Также мы может настроить xdebug, чтобы он сохранял нам параметры, которые мы передаем в функции. Это очень полезно чтобы лучше понимать, как происходит выполнение программы.
Сохранение параметров в лог трассировки устанавливается параметром xdebug.collect_params, о котором было описано в предыдущей статье. xdebug.collect_params принимает числовые значения, 0 означает никакой дополнительной информации, 4 означает, что необходимо отобразить название переменной и всю информацию о каждом параметре функции. Значение 3 будет отображать имена и значения переменных, обрезанных в соответствие с настройками параметров xdebug.var_display_max_data, debug.var_display_max_children и xdebug.var_display_max_depth, описанных в предыдущей статье.
Ниже выдержка из лога трассировки с сохранением параметров функций:

  0.0033  54320  -> fac($x = 7) C:\www\fac.php:6
  0.0034  54432   -> fac($x = 6) C:\www\fac.php:11

Давайте добавим дополнительную информацию. Используя
xdebug.collect_return=On

мы настроим xdebug чтобы он сохранял возвращаемые значения для каждой функции. Это сделает лог немного трудным для чтения, но посмотрите на лог нашей функции, вы увидите какое значение возвращается на каждом этапе рекурсии:
TRACE START [2007-10-26 12:30:04]
  0.0133  55704   +48  -> fac($x = 7) C:\www\fac.php:8
  0.0133  55840  +136    -> fac($x = 6) C:\www\fac.php:13
  0.0134  56096  +256     -> fac($x = 5) C:\www\fac.php:13
  0.0134  56352  +256      -> fac($x = 4) C:\www\fac.php:13
  0.0134  56632  +280       -> fac($x = 3) C:\www\fac.php:13
  0.0135  56912  +280        -> fac($x = 2) C:\www\fac.php:13
  0.0135  57192  +280         -> fac($x = 1) C:\www\fac.php:13
  0.0135  57472  +280          -> fac($x = 0) C:\www\fac.php:13
                                             >=> 1
                                            >=> 1
                                          >=> 2
                                         >=> 6
                                         >=> 24
                                       >=> 120
                                      >=> 720
                                     >=> 5040
  0.0140  57648 +176 -> xdebug_stop_trace() C:\www\fac.php:26
  0.0140  57648
TRACE END [2007-10-26 12:30:04]

Как вы видите в данном примере установлен параметр xdebug.show_mem_delta.

Озаглавливание лога трассировки

До текущего момента, мы явно указывали название лога трассировки. Это не всегда удобно. Если вам необходимо рассматривать логи в зависимости от входящих данных или состояния приложения, неплохо чтобы сам xdebug автоматически присваивал название. xdebug может присваивать имя в зависимости от того что вы используете, параметр xdebug.auto_trace или функцию xdebug_start_trace() для активации трассировки. Если в последнем примере передать пустой аргумент в качестве параметров функции xdebug_start_trace, xdebug автоматически выберет имя для файла.
Название файла сгенерированного xdebug всегда начинается с «trace.» и имеет расширение .xt. Часть имени между точками по умолчанию это CRC от рабочего каталога. Устанавливая xdebug.trace_output_name вы можете определить другое имя для лога трассировки. xdebug.trace_output_name принимает строку в качестве аргумента, строка может содержать различные спецификаторы. Ниже список самых важных спецификаторов:
  • %c — CRC рабочего каталога
  • %p – идентификатор процесса
  • %r – некое случайное число
  • %u – текущее время с микросекундами
  • %H — $_SERVER['HTTP_HOST']
  • %R — $_SERVER['REQUEST_URI']

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

в php.ini.
Если вам необходимо знать во время запуска какое имя выберет xdebug для записи лога, вы можете вызвать функцию xdebug_get_tracefile_name().

Заключение

Возможность использовать трассировку функций это очень полезная вещь, которую нам предоставляет xdebug. Вы можете создавать логии ваших программ без добавления вызовов различных функций. Все вызовы функций будут отображены без явных вызовов функций отображения справочной информации.
Вы можете использовать различные утилиты подобные grep чтобы найти необходимую информацию или секцию в логе трассировки, или написать маленькую программку на PHP, которая будет разбирать этот файл для вас. Трассировка это не замена отладчику. Отладчик будет рассмотрен в четвертой части повествования.
Вы не должны активировать трассировку на боевых машинах, это очень сильно ухудшит производительность, каждая строка программы будет отражена в логе трассировки.
Следующая статья будет посвящена Profiling PHP Applications With xdebug.
Tags:
Hubs:
+17
Comments 16
Comments Comments 16

Articles