PHP: Timing the Script Execution

When debugging your scripts, and during the maintenance phase of any project, you often need to determine how long it takes for a PHP script to run. More importantly, you often know that a certain script takes a long time to run but don't know exactly what section of code is causing the slowdown. It is useful, therefore, to have an easy way to add time tracking to a script.

The first snippet below is a small include file that defines two functions useful in tracking down execution time issues. The first is used to mark different time stamps in your script. The final one generates a report based on these for you. This primarily uses the function microtime(), which when passed a parameter of true returns a UNIX epoch like time(), except that this epoch is a float with accuracy down to microseconds.

The second function defined in the first snippet, and intended to make the listing more interesting and useful, is the debug_backtrace() function, which determines the context of where the timing call was made. Filename: timer.php

<?php
$_timer_results = array();

function _timer() {
    global $_timer_results;
    $curtime = microtime(true);
    $trace = debug_backtrace();

    $_timer_results[] = array(
        'line' => $trace[0]['line'],
        'file' => $trace[0]['file'],
        'func' => isset($trace[1]['function']) ? $trace[1]['function'] : '',
        'time' => $curtime
        );
}

_timer();

function _timer_text() {
    global $_timer_results;
    $result = 'Timing Results';

    $clock = @$_timer_results[0]['time'];

    foreach ($_timer_results as $tr) {
        $thistime = $tr['time'] - $clock;
        $clock = $tr['time'];
        $fn = basename($tr['file']);

        $pretty = number_format($thistime, 5);

        $result .= "\n{$pretty} secs - File: {$fn} - Line: {$tr['line']}";

        if ($tr['func']) {
            $result .= " - Calling Function: {$tr['func']}";
        }
    }
    return $result;
}
?>

Now that we have created this script, let's use it. The following script does just that by including the script, doing some various operations while showing all the different ways in which timing can be used.

Using the timer.php

<?php
require 'timer.php';

foreach(range(1,100000) as $r) {
    rand();
}

_timer();

sha1($r);

_timer();

function do_it() {
    _timer();
    sleep(3);
}

do_it();
_timer();

$output = _timer_text();
echo "<pre>{$output}</pre>\n";
?>

Hope it helps.