7/18/2007
PHP Stopwatch Class to Time and Log Script Execution
Timing code execution is an often overlooked debugging tool. On a current large project we are doing a lot of work interfacing with multiple SOAP implementations on multiple servers and through multiple vendors. When script execution slows down considerably (or stops responding altogether) we needed to know which SOAP calls were causing the slowdown.
Using code and ideas from php.net/microtime I devised this PHP class to handle the timing tasks.
{
private $round = 3;
public $logfile = 'time.log';
function __construct($logfile = '')
{
$this->start = microtime();
if($logfile != '') $this->logfile = $logfile;
$this->fp = fopen($this->logfile, 'a+');
}
function __destruct()
{
fclose($this->fp);
}
function now()
{
$start = $this->math($this->start);
$now = $this->math();
return round($now - $start, $this->round);
}
function math($time = false)
{
if ( !$time ) $time = microtime();
$temp = explode(' ', $time);
return $temp[0] + $temp[1];
}
function write_log($loc, $data)
{
return fwrite($this->fp, date("Y-m-d H:i:s").' '.$loc.': '.$data."s \n");
}
}
Usage
Include the class in your application and create a new instance at the very top of the code.
$time1 = $sw->now();
... snip more code ...
$sw->write_log('CODE-LOCATION', $time2-$time1);
Substitute CODE-LOCATION with the function name or other identifier being timed.
In this case, the stopwatch class logged this data...
2007-07-18 05:01:10 GetLocationByZip: 62.439s
2007-07-18 12:19:18 GeneratePin: 12.232s
2007-07-18 12:19:24 GetVendor: 5.377s
2007-07-18 12:20:31 GetLocationByZip: 66.779s
It is now trivial to see which SOAP call is the culprit (GetLocationByZip) and which vendor to contact.
Popularity: 31%
