PHP Performance Tuning Timing Program Execution by Section

PHP Performance Tuning 

Timing Program Execution by Section

Problem

You have a block of code and you want to profile it to see how long each statement takes to execute.

Solution

Use the PEAR Benchmark module:

       require_once 'Benchmark/Timer.php';

       $timer = new Benchmark_Timer(true);

       $timer->start();

       // some setup code here

       $timer->setMarker('setup');

       // some more code executed here

       $timer->setMarker('middle');

       // even yet still more code here

       $timer->setmarker('done');

       // and a last bit of code here

       $timer->stop();

       $timer->display();

Discussion

The PEAR Benchmark package gives you a quick-and-dirty way to set a few markers in your code to identify hotspots at a more macro level. Install it using the PEAR package manager:

       % pear install Benchmark

Calling setMarker() records the time. The display() method prints out a list of markers, the time they were set, and the elapsed time from the previous marker:

       -----------------------------------------------------------------------------------

       marker   time index                           ex time                                     perct

       -----------------------------------------------------------------------------------

       Start       1029433375.42507400    -                                                 0.00%

       -----------------------------------------------------------------------------------

       setup      1029433375.42554800    0.00047397613525391       29.77%

       -----------------------------------------------------------------------------------

       middle   1029433375.42568700    0.00013899803161621         8.73%

       -----------------------------------------------------------------------------------

       done       1029433375.42582000   0.00013303756713867         8.36%

       -----------------------------------------------------------------------------------

       Stop        1029433375.42666600   0.00084602832794189     53.14%

       -----------------------------------------------------------------------------------

       total        -                                            0.0015920400619507      100.00%

       -----------------------------------------------------------------------------------

The Benchmark module also includes the Benchmark_Iterate class, which can be used to time many executions of a single function:

       require 'Benchmark/Iterate.php';

       $timer = new Benchmark_Iterate;

       // a sample function to time

       function use_preg($ar) {

              for ($i = 0, $j = count($ar); $i < $j; $i++) {

                     if (preg_match('/gouda/',$ar[$i])) {

                            // it's gouda

                     }

              }

       }

       // another sample function to time

       function use_equals($ar) {

              for ($i = 0, $j = count($ar); $i < $j; $i++) {

                     if ('gouda' == $ar[$i]) {

                            // it's gouda

                     }

              }

       }

       

       // run use_preg() 1000 times

       $timer->run(1000,'use_preg',

                                          array('gouda','swiss','gruyere','muenster','whiz'));

       $results = $timer->get();

       print "Mean execution time for use_preg(): $results[mean]\n";

       // run use_equals() 1000 times

       $timer->run(1000,'use_equals',

                                          array('gouda','swiss','gruyere','muenster','whiz'));

       $results = $timer->get();

       print "Mean execution time for use_equals(): $results[mean]\n";

The Benchmark_Iterate::get() method returns an associative array. The mean element of this array holds the mean execution time for each iteration of the function. The iterations element holds the number of iterations. The execution time of each iteration of the function is stored in an array element with an integer key. For example, the time of the first iteration is in $results[1], and the time of the 37th iteration is in $results[37].