views:

1124

answers:

3

PHP is obviously tracking the amount of CPU time that a particular script has used (to enforce the max_execution_time limit). Is there a way to get access to this inside of the script? I'd like to include some logging with my tests about how much CPU was burnt in the actual PHP (the time is not incremented when the script is sitting and waiting for the database).

Update: Just wanted to make it clear that this is on a Linux box.

+1  A: 

The cheapest and dirtiest way to do it is simply make microtime() calls at places in your code you want to benchmark. Do it right before and right after database queries and it's simple to remove those durations from the rest of your script execution time.

A hint: your PHP execution time is rarely going to be the thing that makes your script timeout. If a script times out it's almost always going to be a call to an external resource.

PHP microtime documentation: http://us.php.net/microtime

danieltalsky
+4  A: 

On unixoid systems, you can use getrusage, like:

// Script start
$rustart = getrusage();

// Code ...

// Script end
function rutime($ru, $rus, $index) {
    return ($ru["ru_$index.tv_sec"]*1000 + intval($ru["ru_$index.tv_usec"]/1000))
     -  ($rus["ru_$index.tv_sec"]*1000 + intval($rus["ru_$index.tv_usec"]/1000));
}

$ru = getrusage();
echo "This process used " . rutime($ru, $rustart, "utime") .
    " ms for its computations\n";
echo "It spent " . rutime($ru, $rustart, "stime") .
    " ms in system calls\n";

Note that you don't need to calculate a difference if you are spawning a php instance for every test.

phihag
Awesome, thank you!
twk
Should the value at the end be subtracted from the value at the start of the script? I'm getting some really weird numbers if I don't. Like a page that took 0.05 seconds to generate is saying it took 6s of CPU time...is this correct? See here: http://blog.rompe.org/node/85
Darryl Hein
@Darryl Hein: That's because you are using a previously used instance of php. Modern web servers reuse the same instance over and over for performance reasons. I updated the answer to reflect that and present a solution that works in both cases.
phihag
@Darryl Hein: Oh, and you get weird results because you are using string concatenation instead of addition ;)
phihag
Since *.tv_usec is in microseconds (1,000,000 per second) and *.tv_sec is in seconds, don't you need to multiply by 1000000 (or 1e6) instead of 1000?
Joe Lencioni
@Joe Lencioni Can't believe I missed that. Thanks!
phihag
+1  A: 

I think you should look at xdebug. The profiling options will give you a head start toward knowing many process related items.

http://www.xdebug.org/

Stewart Robinson