Simple PHP Timer

I was just trying to profile an HTML page for performance bottle-necks. I’m trying to follow a top-down approach, wherein I start from the entry script, and find the block of code that takes the biggest chunk of time before digging deeper into that chunk.

At this stage, it’s not feasible to drop in a full-blown profiling tool like xdebug because of the set-up overhead and amount of data it generates. So, I wrote a simple timing function that you can call at various points in your program to provide incremental and cumulative timing info in milliseconds. Just call this function anywhere in your code with a message and it’ll print that message to your PHP output, followed by millisecond timing information at that point. Here’s the function implementation:

<?php
function time_this($msg) {
  $prefix = '[[';
   static $start = 0;
   static $prev = 0;
   $now = microtime(true);

   if ($start == 0) {
      $start = $now;
      $prev  = $now;
      return;
   }

   printf("%s%s: %f (cum), %f (incr)\n", $prefix, $msg, ($now - $start)*1000.0, ($now - $prev)*1000.0);
   $prev = $now;
}
time_this(""); // initialization
?>

The nice thing about this script is that it automatically keeps track of timing information through static variables. You don’t need to keep track of that manually. Since it’s also taking in a message, you could use it to debug your program if you’re among those who find printf to be the best debugger 😀

Sample usage:

<?php
require_once('time_this.php');
time_this("starting script");

require_once('foo.php');
require_once('bar.php');
time_this("includes done");

// ...
time_this("somewhere in between");

// ...
time_this("script ends");
?>

Output:

[[starting script: 0.000015 (cum), 0.000015 (incr)
[[includes done: 94.221115 (cum), 94.221100 (incr)
[[somewhere in between: 110.846996 (cum), 16.625881 (incr)
[[script ends: 145.432760 (cum), 34.585764 (incr)

Let me know if you like it, or if you know of something similar that does the job better.