A PHP tale of self awareness
- 21 December, 2009 -
- PHP Coding -
- Tags : debug, development, performances, PHP
- 0 Comments
I don’t know about you guys but when I build a system, I like it to be aware of itself. “What the hell do you mean by that?” I hear coming from the back. Here comes my explanation.
When I build a system it knows how long each query took to run. It know what size the generated HTML is. It knows how long it took for the page to load. It knows what calls were made from where to whom. It knows who did what in the where. Paranoid? Damn right.
Timing how long it takes for a task to be completed
Let’s start with the simple stuff. Timing the time a page takes to load. Let’s create a page that outputs something and time it.
<?php
function getmicrotime(){
list($usec, $sec) = explode(" ",microtime());
return round( ((float)$usec + (float)$sec) , 3);
}
$startTime = getmicrotime();
echo "Hello world<br />\n";
echo round(( getmicrotime() - $startTime ) , 3 );
?>
In this (rather pointless) example, we’re timed how long your server takes to output “Hello world<br />”. Now, if we use the getmicrotime function to store the start and end time of any task we can keep track of how long it took for it to be executed. The interest here is to keep an eye on performances. Of course, this timing will add time to the general execution of the script. But this delay we add by observation can be turned on and off simply as shown bellow:
<?php
define('DO_WE_DEBUG' , 1 );
function getmicrotime(){
list($usec, $sec) = explode(" ",microtime());
return round( ((float)$usec + (float)$sec) , 3);
}
if( DO_WE_DEBUG ){
$startTime = getmicrotime();
}
echo "Hello world<br />\n";
if( DO_WE_DEBUG ){
echo round(( getmicrotime() - $startTime ) , 3 );
}
?>
From a strict performance point of view we still have extra time added by checking the value of the constant. But imagine, your system is running slow. You need to identify which part of the site is slow. To do that I use this simple solution incorporated into my generic classes (database access, APIs, etc.) to pinpoint the faulty piece of code. In my latest version of this system, when the debugging is turned on, I generate a record per page loaded in the debug table of my system containing the global run time of the script, size of the output text, IP, Session ID and a text field with every SQL query run in the page. This field contains caller class and method, the generated SQL, the run time of the query, the global page time line position. Extreme? Yes. Useful? Very.
To be continued…
No related posts.
Related posts brought to you by Yet Another Related Posts Plugin.