PHP Profile Class
September 24, 2008
Profiling is a important part of software development, allowing you to find bottlenecks in your application and discover areas that would benefit from optimisation. In PHP a common technique is to calculate the total time to render a page. This can be achieved using the microtime function:
<?php
$startTime = microtime(true);
// normal page code here
$time = microtime(true) - $startTime;
echo "<!-- Page generation time: {$time} seconds -->";
?>
This simple approach is a a great way to find out how long certain pages are taking to load. Sometimes, however, you want more granular profiling information. That’s why I created a Profile class, which records the execution time of a given method. Here’s how to use it:
$p = new Profile();
$time = $p->profile("myClassName", "methodName", array("arg1", "arg2"));
You can also pass in an optional fourth argument, which specifies how many times to run the given method. After running it multiple times you can call the Profile::printDetails() method to view the total time, average invocation time, and the maximum single invocation time. Below is a simple example:
<?php
include("Profile.php");
/**
* Test class just for the purposes of demonstration
*/
class Test {
public function add($a, $b) {
// add the numbers together 100 times
for($i = 0; $i < 100; $i++) {
$c = $a + $b;
}
}
}
$p = new Profile();
$p->profile("Test", "add", array(1, 2), 1000);
$p->printDetails();
?>
If you run the above code you’ll see the following output:
Test::add(1, 2) was invoked 1000 times
Total duration: 0.0447s
Average duration: 0s
Worst duration: 0.002s
The code listing for the Profile class is below, with some of the comments removed for the sake of brevity. A fully commented version is available for download.
<?php
/**
* Class to time the execution of method calls.
*
* @author Ben Dowling - www.coderholic.com
*/
class Profile {
/**
* Stores details about the last profiled method
*/
private $details;
public function __construct() {}
/**
* @param classname string
* @param methodname string
* @param methodargs array
* @param invocations int The number of times to call the method
* @return float average invocation duration in seconds
*/
public function profile($classname, $methodname, $methodargs, $invocations = 1) {
if(class_exists($classname) != TRUE) {
throw new Exception("{$classname} doesn't exist");
}
$method = new ReflectionMethod($classname, $methodname);
$instance = NULL;
if(!$method->isStatic()) {
$class = new ReflectionClass($classname);
$instance = $class->newInstance();
}
$durations = array();
for($i = 0; $i < $invocations; $i++) {
$start = microtime(true);
$method->invokeArgs($instance, $methodargs);
$durations[] = microtime(true) - $start;
}
$duration["total"] = round(array_sum($durations), 4);
$duration["average"] = round($duration["total"] / count($durations), 4);
$duration["worst"] = round(max($durations), 4);
$this->details = array( "class" => $classname,
"method" => $methodname,
"arguments" => $methodargs,
"duration" => $duration,
"invocations" => $invocations);
return $duration["average"];
}
/**
* @return string
*/
private function invokedMethod() {
return "{$this->details["class"]}::{$this->details["method"]}(" .
join(", ", $this->details["arguments"]) . ")";
}
/**
* Prints out details about the last profiled method
*/
public function printDetails() {
$methodString = $this->invokedMethod();
$numInvoked = $this->details["invocations"];
if($numInvoked == 1) {
echo "{$methodString} took {$this->details["duration"]["average"]}s\n";
}
else {
echo "{$methodString} was invoked {$numInvoked} times\n";
echo "Total duration: {$this->details["duration"]["total"]}s\n";
echo "Average duration: {$this->details["duration"]["average"]}s\n";
echo "Worst duration: {$this->details["duration"]["worst"]}s\n";
}
}
}
?>
