A Guide on Advanced Logging and Benchmarking with FirePHP

Aug 4 2009 by Nuno Franco da Costa | 3 Comments

A Guide on Advanced Logging and Benchmarking with FirePHP

In a previous article, we discussed FirePHP’s basic logging functions for debugging your PHP web applications. Although–as we have seen–it can be used for debugging purposes, its main utility is to log information about your web apps, and it does a terrific job in that regard.

In this article, I will introduce you to an old concept that seems to be forgotten by most web developers today: the importance of logging. Additionally, I’ll walk you through some of functions designed to keep your logging more organized.

We will talk about:

  • Grouping messages
  • Tables
  • Benchmarking your code

We’ll also learn how to redirect trappable PHP errors to FirePHP, which is a neat and very convenient feature.

The importance of logging

While debugging is essential to ensure an application works, it does not explain why, for example, a user is having trouble subscribing to your newsletter when other users can.

Logging information will allow you to gather all available information so that you can trace the user actions in great detail. The more information you have, the easier it will be to recreate the user actions and find out why he/she is having problems.

Unfortunately, many web developers tend to disregard logging, making bug squashing a lot harder.

Taking the newsletter example that I mentioned earlier – if you have logged the user input, you might find that he/she is using a new 6-character top-level domain, and therefore your email validation routine is failing because of that. If you had fired up your debugger and fed it your own test data, you probably would never find the problem without talking to the user and asking for the data they used. That’s why it’s important to log, and the more information you log, the better.

FirePHP is an excellent logging tool; its only problem is that its logs are not persistent. It would be great if FirePHP logs could be redirected to a file for later analysis (we’ll talk about this in a future article), but for now we will explore some of the existing features of the FirePHP library.

Grouping messages

There are many situations where it’s useful to group related messages together, and FirePHP allows you to do just that.

Groups in FirePHP can be nested; this means that you can have groups inside other groups and you can expand or contract these groups in the Firebug console, making it easy to analyze related sets of information.

By default, groups are shown expanded, but that can be easily changed. You can also change the color of the group label by specifying a standard HTML color value.

A hypothetical grouping example

Groups are useful to keep your logging organized. Let’s take a hypothetical site that has the basic four sections that most websites have: a header, a navigation menu, a content area, and a footer area. You can group your messages by area so that you can easily find, for example, the navigation menu log or just the content area log. This way, your log is systematic and easier to examine.

You have two functions to aid you in dealing with groups.

  • Group($groupName)starts a group
  • groupEnd()ends a group

You can customize the group appearance this way:

Fb::group('collapsed blue group',array('Collapsed' => true, 'Color' => '#00f'));

Note: Be sure to use the latest Firebug version for this to work.

Let’s see a practical example of group nesting.

//creating a collapsed group named "Navigation Menu" colored green
fb::group('Navigation Menu', array( 'Collapsed' => true,  'Color' => '#0f0') );
  //and now a group to hold messages for the home menu
  fb::group('Home menu', array( 'Collapsed' => false,  'Color' => '#000'));
    //some bogus messages
    fb::info('current menu, added menu-on class');
    fb::warn('no url found for this menu');
  //closing home menu group
  fb::groupEnd();
//closing navigation menu group
fb::groupEnd();

You end up with the following result after expanding the first group.

Nested groups.

Simple benchmarking

A functionality missing from FirePHP is the ability to count elapsed time which can be helpful if you are checking performance issues or are simply curious on how fast your PHP apps perform.

To help you with benchmarking, you can either extend the FirePHP class with your own benchmarking scripts, or you can create a simple helper class.

As we will not talk about extending FirePHP, we will build the helper class.

class fbTimer{
  protected static $timerStart = 0;
  protected static $timerEnd = 0;
  public static function start(){
    self::$timerStart = microtime();
    self::$timerEnd = 0;
  }

  public static function stop(){
    self::$timerEnd =microtime();
  }

  public static function get(){
    if(self::$timerEnd == 0) self::stop();
      return self::$timerEnd - self::$timerStart;
    }
  }
// this class is simple to use
fbTimer::start();
// some code you want to benchmark
fbTimer::stop();
fb::log("execution time :" . fbTimer::get() . ' seconds' );

Here is the output from the above class and class calls showing the total execution time.

output from the above class and class calls

Tables

Another nice way to group related data together are by using tables.

For FirePHP, a table is an array of arrays. The first array row is automatically used as the heading, and the number of columns is determined by the number of items in it.

Firebug will display the table label and allow you to show or hide the table data.

This might sound confusing, but as soon as you see the code, it will all make sense and you will then realize just how horrible I am with explaining things.

Let’s say you want to see the execution time of some queries – here’s an example to use.

$table   = array();
$table[] = array('Sql query','execution time');
$table[] = array('Select bla from foo where bar =1','0.32');
$table[] = array('Select bla from foo where bar =1','1.76');
$table[] = array('Select bla from foo where bar =1', '0.23');
fb::table('executed queries', $table);

This will create a collapsible table with all the information you provided.

collapsible table with all the information

Error handling

Another feature that will help to keep your web pages uncluttered and secure from accidentally leaking information to the public is the ability to redirect non-fatal PHP errors to the Firebug console.

You can send Convert E_WARNING, E_NOTICE, E_USER_ERROR, E_USER_WARNING, E_USER_NOTICE and E_RECOVERABLE_ERROR to Firebug automatically.

$p = new FirePHP();
// converts errors into exceptions
$p->registerErrorHandler();
// makes FirePHP handle exceptions and sends it to FirePHP
$p->registerExceptionHandler();

Now you should start receiving errors in the Firebug console instead of in your HTML source code.

Therefore, the following code will redirect errors to Firebug.

$p = new FirePHP();
$p->registerErrorHandler();
$p->registerExceptionHandler();
// a forced error
echo "-" . asd;

The above will output:

output

Conclusion

I hope that with this article, I’ve broadened your view on FirePHP logging features and showed you some tips and techniques on how to make your logging processes more complete.

Don’t forget that–when solving problem –the more information you have, the better, because typically error reports from users and technology support are very broad and lacking information, such as: "there is a user that can’t subscribe our newsletter, fix it."

What’s next?

On a future article, we will discuss a method for filtering your logs. We’ll also investigate a way for making logs persistent by storing them in a file. To make sure you get notified when this article is published, please subscribe to the Six Revisions RSS feed.

Do you have FirePHP tips?

If you have tips, tricks, and effective techniques for utilizing FirePHP, please share them in the comments. *edited by Jacob Gube

Related Content

About the Author

Nuno Franco da Costa is a web developer and sys admin. By day, he works at a design agency coordinating the development and sys admin teams where he developed a PHP MVC framework and a WEB 2 CMS. He loves to code and has a "getting things done" attitude. You can find over at his online presence www.francodacosta.com

3 Comments

Jônatan Fróes

August 4th, 2009

I’m a PHP developer and I know the importance of FirePHP. Thanks for so nice article.

jasper

August 20th, 2009

I’m also a PHP developer but the applications (most of the time marketing related) I develop never require this high-level debugging. I will keep this in mind though. Every interesting!

Luis Aveiga

March 16th, 2010

FirePHP is an invaluable tool to debug in PHP. Thanks for the article Nuno :)

I have a question also… I’m a Drupal fan, and I have problems with redirections & debugging. For example, I want to debug certain objects, but the page where these objects belong have a redirection, let’s say a comment page. So, when using firebug in this page nothing happens…

I also tried using the persist feature of the console, but I think that the message fires later, maybe on client, and that’s why I’m not getting the FirePHP info.

Any suggestion on handling debugging with FirePHP in redirection pages?
Thanks!

Leave a Comment

Subscribe to the comments on this article.