Jan 20 2010

Simple PHP Profiling Class

datchley

Working in my current corporate environment we don’t have any useful PHP profiling abilities on any of our web servers. Unfortunately, trying to get our server support group to install something useful like APD or Xdebug and getting it integrated is a bureaucratic pain in the ass. We have some very useful tools like FireBug on the client side and we’ve started using FirePHP integration in FireBug which provides a number of nice features for debugging; but nothing specific to profiling. Given the situation, I decided to implement my own simple Profiling class that made use of FireBug/FirePHP to provide the output in a useful format. More could be done with this, to be sure; but for the time being it has taken care of my needs.

There’s no shortage of existing of profiling functions and classes by other developers on the Internet; but I figured I could use some creativity and play around with a class of my own. Plus, none of the one’s I’ve seen out there were using FireBug/FirePHP as part of their output which is something I wanted to try out. So, with some spare cycles while debugging, I came up with the fbProfile class (see download at end of the article).

The fbProfile class is very simple and straight forward. From a usage standpoint, it would provide only 3 methods: start(), stop() and display(). We’ll go into these in a bit more detail later; but, my goals for the class and it’s usage are summed up as follows:

  1. be able to nest calls to start() and stop() to produce a visible call chain
  2. be able to tag profiled tasks with a descriptive name for reference in the output
  3. track the total Page time (or close approximate)
  4. track how many times a block of profiled code was called, along with profiling information for each call
  5. optionally, be able to watch a set of variables on each subsequent call to a profiled block of code, seeing the values over time
  6. determine some basic results like total task time, average task time (per call), percentage of total page time, etc.
  7. show the output using FireBug’s console using FirePHP to take advantage of the work area and abilities it provides.

Using the fbProfile Class

Because we’re using FireBug/FirePHP you’ll need to have both of these installed and enabled for the site you’re using fbProfile on. At the top of your PHP code, do the usual setup for FirePHP and afterwards include the fbProfile.php file.

<?php
	ob_start();
	require_once($_SERVER['DOCUMENT_ROOT']."/firephp/lib/FirePHPCore/FirePHP.class.php");
	$firephp = new FirePHP;
	$firephp->registerErrorHandler();
	$firephp->registerExceptionHandler();

	include_once($_SERVER['DOCUMENT_ROOT'] . "/fbProfile.php");

Including the fbProfile.php class will be the marker for the page start timestamp it uses to keep track of total page load/processing time. It’s not as accurate as when using a real profiler like APD or Xdebug, but if you put it close to the top of the page (which is where it would normally fall to being with) it’s an accurate enough approximation of page start time.

From this point, just wrap the sections or blocks of code you would like to benchmark in calls to start() and stop() respectively. A call to start takes a string name which will be used as the label for that section of code when we output the results to the FireBug console, so use something descriptive. Also, these calls can be nested, as such:

	...
	fbProfile::start('Main Query Execution');
	$rs = $tdcsdb->Execute($sql);
	fbProfile::stop();
	...
	fbProfile::start('Main Processing Loop');
	while ($row = $rs->FetchRow()) {
		...
		fbProfile::start('Build Record');
		...
		update_output_file($row);
		...
		fbProfile::stop();	// Build Record
	}
	fbProfile::stop();	// Main Processing Loop

	...

	function update_output_file($rec) {
		fbProfile::start('update_output_file()');
		...
		fbProfile::stop();
	}

This is simple usage shown above. Each call to start() has a matching call to end() and each wrapped block/section of code is given a descriptive name. We have nested calls and even calls inside a function to profile function execution. fbProfile will track each call to the wrapped blocks of code and keep track of processing time per call and in relation to the entire page processing time.

At the end of your PHP script, do the necessary FirePHP close up because of output buffering and call fbProfile::display() to show the output of the profiling in your FireBug console. fbProfile::display takes a reference to your FirePHP instance object – the one that we created at the top of the page.

	fbProfile::display($firephp);
	ob_end_flush();
?>

Optionally, if you would like to see the individual profiling times for each call to a section of code and/or track one or more variable values related to that block of code, fbProfile::start() takes 2 optional parameters after the string label. The first is a boolean true or false to tell the fbProfile class that you would like to see this detailed information in the output when display() is called (defaults to false) and after that parameter you can pass a variable number of other parameters that are the variables you would like to see the values of during each subsequent call (shown in the detail records). So, to see the detail and watch some values, call fbProfile::start() as follows:

fbProfile::start('My Label', true, $var1, $var2, ...);

Below is some output from a run of fbProfile on some code I have been working on, the detail records are collapsed in this screenshot. If a task has detail records, you’ll see the little ‘table’ icon on the left side of the task summary, since we’re using FirePHP’s table() function to format the output.

And the next picture shows the output display of detailed call records for a task that was called numerous times. Just click the task summary with the table icon to expand the detail records display.

Hopefully, this class will provide useful for someone as-is, or even as a jumping off point in creating their own. Again, this is not hardened code and definitely not as clean as it could be; but it’s the kind of thing that developers do when they need a fix and are limited on resources.

Download link: fbProfile.php

Enjoy!