1

Using Eclipse's PHP Profiler, I have discovered a bottleneck in my code on a method that is called many times. The problem is that I cannot tell what parameters were passed in to the method to determine how to reproduce the symptom.

I have tried surrounding the code that the profiler is reporting as taking a full second to complete with the following:

$startTime = microtime(true);
$safe_text = wp_check_invalid_utf8( $text );
$endTime = microtime(true);
$time = $endTime - $startTime;
if ($time > .05) {
    error_log('Time: ' . $time . ' text [' . $text . ']');
}

I never have a single hit in the error log for this, yet the profiler will continue to report one as taking a full second to complete. Refreshing the page in the browser does indicate that there is significant slowness.

I have this same problem in 3 different areas of my code and knowing what was being passed in to the methods at the time they run slowly may be of assistance in fixing the problem. Is there any way to determine what is being passed in to the intermittently slow method when it is running slowly?

bitsoflogic
  • 1,164
  • 2
  • 12
  • 28
  • Did you try `var_dump`ing your $startTime and $endTime variables? – Madara's Ghost Aug 17 '11 at 16:51
  • your using xdebug to profile? – Gerry Aug 17 '11 at 17:11
  • @Rikudo No. However I have removed the if($time > .05) condition and manually verified all $time results as taking only a couple milliseconds each. – bitsoflogic Aug 17 '11 at 17:51
  • @Gerry No. It looks like I'm using the Zend Debugger. – bitsoflogic Aug 17 '11 at 17:52
  • @Levinaris Well there appears to be even less documentation on the profiler in Zend Debugger, so the recommendation in my answer is still the best I can offer and I do believe it's the right solution. In future you may want to take a look at XHProf as it's the best php profiler I've used to date (although still doesn't offer call level breakdown): http://techportal.ibuildings.com/2009/12/01/profiling-with-xhprof/ – Gerry Aug 17 '11 at 18:37
  • Just [pause it](http://stackoverflow.com/questions/375913/what-can-i-use-to-profile-c-code-in-linux/378024#378024) a few times, and each time look at the call stack. You'll see what the arguments are, and you'll see exactly why it's being called. – Mike Dunlavey Aug 17 '11 at 19:31

1 Answers1

0

It is possible to set this up using xdebug which is what Eclipse uses for profiling, however it's disabled by default because recording this data in a project that makes a lot of calls or passes large data structures would quickly overwhelm your available memory.

I recommend you do manual logging as you are currently doing although I'd start by measuring the total time of all calls to wp_check_invalid_utf8 to make sure you do infact have a problem in just that part and that is isn't just a problem caused by the Eclipse profiler itself. Once you've established the total time is more than you would like, then start logging individual calls and their parameters.

Gerry
  • 10,584
  • 4
  • 41
  • 49
  • appreciate the info - It's ashame there isn't a better solution yet. I'm looking forward to having the hardware available to support that option. – bitsoflogic Aug 17 '11 at 19:32