measuring the elapsed time between code segments in PHP

Question

From time time to time, I'd like to be able to measure the elapsed time between two segments of code. This is solely to be able to detect the bottlenecks within the code and improve what can be improved.

I'd like to design a function like that where the function should work with a global variable which echoes out the elapsed time between the current call and the last time it was called.

This way, you can use it many times one after the other.

And the function should be able to be calculate the differences in fractions of seconds such as 0.1 sec or 0.3 sec etc.

An example would probably explain it much better.

echo time_elapsed();   

     // This echo outputs nothing cause this is the starting case. 
     // There is nothing to compare against. 

//
// 1st code section here
//

echo time_elapsed();  

      // This echo outputs 0.5 seconds. 
      // ...which means there has been 0.5 seconds passed 
      // ...since the last time time_elapsed() was fired

//
// 2nd code section here
//


echo time_elapsed()   

      // This echo outputs 0.2 seconds

//
// 3rd code section here 
//

echo time_elapsed()   

      // This echo outputs 0.1 seconds etc

My question is what PHP utilities ( built-in functions ) do I need to use to achieve this kind of output?

Answer 1

A debugger like XDebug/Zend Debugger can give you this type of insight (plus much more), but here is a hint at how you can write a function like that:

function time_elapsed()
{
    static $last = null;

    $now = microtime(true);

    if ($last != null) {
        echo '<!-- ' . ($now - $last) . ' -->';
    }

    $last = $now;
}

Mainly the function microtime() is all you need in order to do the time calculations. To avoid a global variable, I use a static variable within the elapsed function. Alternatively, you could create a simple class that can encapsulate the required variables and make calls to a class method to track and output the time values.

Answer 2

From the first example in the php docs:

<?php
/**
 * Simple function to replicate PHP 5 behaviour
 */
function microtime_float()
{
    list($usec, $sec) = explode(" ", microtime());
    return ((float)$usec + (float)$sec);
}

$time_start = microtime_float();

// Sleep for a while
usleep(100);

$time_end = microtime_float();
$time = $time_end - $time_start;

echo "Did nothing in $time seconds\n";

Answer 3

Something along these lines should work:

$start = microtime(true); 

// Do something
sleep(2);

$end = (microtime(true) - $start);
echo "elapsed time: $end";

Answer 4

Same drew010 function (thanks!), only added custom comment and time displays in microseconds (us):

    function time_elapsed($comment) 
        {

        static $time_elapsed_last = null;
        static $time_elapsed_start = null;

        // $unit="s"; $scale=1000000; // output in seconds
        // $unit="ms"; $scale=1000; // output in milliseconds
        $unit="μs"; $scale=1; // output in microseconds

        $now = microtime(true);

        if ($time_elapsed_last != null) {
            echo "\n";
            echo '<!-- ';
            echo "$comment: Time elapsed: ";
            echo round(($now - $time_elapsed_last)*1000000)/$scale;
            echo " $unit, total time: ";
            echo round(($now - $time_elapsed_start)*1000000)/$scale;
            echo " $unit -->";
            echo "\n";
        } else {
            $time_elapsed_start=$now;
        }

        $time_elapsed_last = $now;
    }               

Example:

// Start timer
time_elapsed('');

// Do something
usleep(100);
time_elapsed('Now awake, sleep again');

// Do something
usleep(100);
time_elapsed('Game over');

Ouput:

<!-- Now awake, sleep again: Time elapsed: 100 us, total time: 100 us -->
<!-- Game over: Time elapsed: 100 us, total time: 200 us -->

Answer 5

Other factors affect the timing of your scripts. Example:

1. Complex code and recursive functions.
2. The type of web server being used, example: shared VS dedicated hosting.

Answer 6

<?php
$time_start = microtime(true);

// Sleep for a while (or your code which you want to measure)
usleep(100);

$time_end = microtime(true);
$time = $time_end - $time_start;

echo "Did nothing in $time seconds\n";

Source: http://php.net/manual/en/function.microtime.php#example-2568

Answer 7

My profiling needs in development are covered by this small yet powerful class:

<?php

class perflog {
    protected $perflog = [];

    public function start($tag) {
        if (!isset($this->perflog[$tag])) $this->perflog[$tag] = 0;
        $this->perflog[$tag] -= microtime(TRUE);
    }

    public function stop($tag) {
        $this->perflog[$tag] += microtime(TRUE);
    }

    public function results() {
        return $this->perflog;
    }
}

See it in action here.

It is intended to be invoked via subsequent start(<tag>) and stop(<tag>) calls. It produces an array with the totalized times your code spent in the sections enclosed by the calls of start() and stop() with matching tags.

start-stop sequences may be nested and may be entered multiple times, thus summarizing the time spent in the enclosed section.

Its compactness ensures minimum performance impact. Dynamic tag creation can be used to let the program modify what it monitors. Typically this is extended with outputting or storing functions.