jokkedk/webgrind

Failed to parse profiler logs properly

Closed this issue · 6 comments

OnkelTem commented

I tried to view log files created by Drupal drush program but it doesn't seem like these file are parsed correctly. The output is scanty and doesn't represent the real picture:

Empty 1

You can try two logs files yourself:

https://yadi.sk/d/M6nBftoI3FGbCU
https://yadi.sk/d/fUSnAmm73FGb5Y

Xdebug: 2.5.0
PHP: 5.6

alpha0010 commented

I will take a look at those logs this weekend.

My guess is that since the script takes so long to run, PHP's integer overflows (#10), causing anomalous output. (Fixing this has not been a top priority since Webgrind's main target is profiling web pages.)

OnkelTem commented

@alpha0010
It's a spurious time of course, the script takes ≈3 seconds to run.
There is a bug report on this https://bugs.xdebug.org/view.php?id=1404

alpha0010 commented

The correct total is in there:

2925760
2925761 fl=(724) /home/fantomas/drush8/vendor/drush/drush/drush.php
2925762 fn=(1922) {main}
2925763
2925764 summary: 2830385
2925765

However, later on we have:

2927767
2927768 fl=(724)
2927769 fn=(1922)                 <-- This also codes for "{main}"
2927770
2927771 summary: 1488967759093191
2927772

Webgrind is treating this as if you have Xdebug configured to append profile data from multiple runs to the same file. Does your configuration have any possibility of causing this?

OnkelTem commented

Does your configuration have any possibility of causing this?

No, every time a new file is created. But you can test it yourself e.g.:

$ composer require drush/drush:8.1.10
$ ./vendor/bin/drush

and check out resulting profiler's output.

alpha0010 commented

After some testing, it appears the register_shutdown_function() does not play nice with Xdebug, so it probably must be fixed on their end. Is there some way you think webgrind should handle this case differently?

Potentially related:
http://stackoverflow.com/questions/15035565/php-profiling-delay-before-shutdown-function
https://bugs.xdebug.org/view.php?id=87
https://bugs.xdebug.org/view.php?id=357