Блог

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

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

 function foo(){ $x = 1; }
function bar(){ foo(); }
  

Протестируйте:

 $t0 = microtime(true);
for ($i = 0; $i < 1000000; $i  ) foo();
echo microtime(true) - $t0;
  

Тест B:

 $t0 = microtime(true);
for ($i = 0; $i < 1000000; $i  ) bar();
echo microtime(true) - $t0;
  

Итак, вот результаты, которые я получаю (в секундах):

           profiler  | profiler  > profiler
          disabled  | enabled   > results
          --------------------------------------------------------------------
          output    | output    > total time   time in foo()   time in bar()
Test A    0.159     | 12.199    > 12.245       0.110           - (not called)
Test B    0.233     | 25.399    > 25.578       0.104           11.068
  

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

Из результатов, взятых из теста B с отключенным профилировщиком, мы можем сказать, что скрипт тратит около 0,159 секунды на foo() и 0,074 секунды на bar() . Очевидно, что время, затраченное на bar(), меньше времени, затраченного на foo() .

Однако, когда я анализирую результаты профилировщика (с помощью qcachegrind), время, показанное как затраченное в bar() (= 11,068 секунды), смехотворно выше, чем время в foo() (= 0,104 секунды).). Этому есть возможное объяснение: каждый раз, когда выполняется вызов функции, профилировщик запускает дополнительный код, чтобы отслеживать время, затраченное на вызов. Я полагал, что это исключило это дополнительное время из результатов, но, видимо, это не так.

[РЕДАКТИРОВАТЬ] В результате профилировщик сообщает, что bar() в этой программе занимает больше времени, чем foo(), что не так, поскольку мы измерили с отключенным профилировщиком. Это даже близко не так! Относительные результаты (процент времени, затраченного каждой функцией) совершенно неверны. Этого не следует ожидать, потому что, если это так, профилировщик не может указать, какая функция занимает большую часть времени. Хотя ожидается, что абсолютное время будет иметь (большие) различия, относительное время не должно иметь. [/ ПРАВИТЬ]

Это делает результаты непригодными для использования. Любой более модульный код (с большим количеством вызовов функций, оболочек, объектов и т.д.) строго наказывается, хотя он не настолько медленный!

Итак, вопрос: есть ли какой-либо способ сообщить XDebug игнорировать или отдельно отслеживать дополнительное время, затраченное на вызовы профилировщика?

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

В качестве пояснения: xdebug выполняет всю работу, от начала до конца, сбрасывая / метрифицируя все, как было объявлено. За это приходится платить (как это не могло быть?).

Если вам нужно выбрать показатели в изолированном контексте в вашем скрипте, вы не должны запускать xdebug. Или, как показывает ваш вопрос: вы пытаетесь профилировать xdebug с включенным xdebug (с кодом PHP!). На самом деле это не сработает, вы не можете профилировать скомпилированное PHP расширение C с помощью пользовательского кода PHP, или, по крайней мере, я не буду этому доверять. Представьте, что библиотека изменяет поведение интерпретатора, того же интерпретатора, на котором выполняется ваш код профилирования.

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