Performance measures

How to introduce performance measures in your logging system ?

An easy way to measure response time is to use microtime() function.

PHP official documentation :

microtime() returns the current Unix timestamp with microseconds. This function is only available on operating systems that support the gettimeofday() system call.

In order to measure a response time of a request, you have to identify its entry point. Then put the Start top as the first action. Finally, detect the request response point and put the Final top just above...

//Launch timer
$time0 = microtime(TRUE);
$time00 = $time0;
echo 'Call: '.$time00.' - TIMER Request toto - Start : '.$time0.'<br/>';

//Response initialization
$response = 'Here is the final response to client !';

//some actions
usleep(100000);

//some intermediate measure
$timeX = microtime(TRUE);
$timeXDuration = $timeX - $time0;
echo 'Call: '.$time00.' - TIMER Request toto - Intermediate X : '.$timeX.'<br/>';
echo 'Call: '.$time00.' - TIMER Request toto - Intermediate X Duration : '.$timeXDuration.'<br/>';

//Stop timer
$timeResponse = microtime(TRUE);
$timeDuration = $timeResponse - $time0;
echo 'Call: '.$time00.' - TIMER Request toto - Response time : '.$timeResponse.'<br/>';
echo 'Call: '.$time00.' - TIMER Request toto - Duration : '.$timeDuration.'<br/>';

return $response;

This code displays :

Call: 1265645157.8705 - TIMER Request toto - Start : 1265645157.8705
Call: 1265645157.8705 - TIMER Request toto - Intermediate X : 1265645157.9706
Call: 1265645157.8705 - TIMER Request toto - Intermediate X Duration : 0.10011100769043
Call: 1265645157.8705 - TIMER Request toto - Response time : 1265645157.9707
Call: 1265645157.8705 - TIMER Request toto - Duration : 0.10015106201172

Note that $time00 is used to identify the call. It could be replaced by a random string, and you can pass it as a parameter to sub-functions to measure sub-treatments...