To profile the code base of a large-scale website I wrote a simple helper class to determine processing times of certain code sections. In general I find XDebug and KCachegrind very helpful for code profiling but this has proven very helpful for realtime profiling.
<?php // Define TIMER_RUNTIME_START for total script timing // This will also automatically be defined on inclusion of // class_timer.php define('TIMER_RUNTIME_START', microtime(true)); require_once('class_timer.php'); $timer = Timer::singleton('/tmp/logfile', array('precision' => 2)); // Timers can be nested too $timer->start('wrapper_timer'); $timer->start('first_timer'); // Do something slow sleep(1); $timer->stop('first_timer'); $timer->start('second_timer'); // Do something slow usleep(200000); $timer->stop('second_timer'); $timer->stop('wrapper_timer'); ?>
The output can be logged to a dedicated file or the standard error log. Here the output of the example above:
=== 2012-11-29 10:05:46 === wrapper_timer => total 1.20, count 1, max. 1.20, avg. 1.20 first_timer => total 1.00, count 1, max. 1.00, avg. 1.00 second_timer => total 0.20, count 1, max. 0.20, avg. 0.20 === 2012-11-29 10:05:46 ===
It is also possible to log the percentage of the total script execution time for each section.
To do so set the percent flag
$timer = Timer::singleton('/tmp/logfile', array('percent' => true));
The output will look something like this:
=== 2012-11-29 10:32:14 === wrapper_timer => total 99.24%, count 1, max. 99.24%, avg. 99.24% first_timer => total 82.62%, count 1, max. 82.62%, avg. 82.62% second_timer => total 16.57%, count 1, max. 16.57%, avg. 16.57% === 2012-11-29 10:32:14 ===
To get the most precise output define the TIMER_RUNTIME_START constant as early as possible in the script:
define('TIMER_RUNTIME_START', microtime(true));
If you don’t define this constant it will be automatically defined on inclusion of class_timer.php.
Download the code here.