Learn DooPHP: High performance PHP framework

Profiling and DB Profiling with DooPHP

If you have read the previous tutorial on logging you will find that profiling with DooPHP framework is relatively similar to the way you log messages.

Performance profiling can be used to measure the time & memory needed for the specified code blocks and find out what the performance bottleneck is. Instead of calling log() you change it to beginProfile() and endProfile(). We need to mark the beginning and the end of each code block by inserting the following methods:

Doo::logger()->beginProfile('block_id_here');
//...everything here will be profiled
Doo::logger()->endProfile('block_id_here');

Code blocks need to be nested properly. A code block cannot intersect with another. It must be either at a parallel level or be completely enclosed by the other code block.

All of the profiled results can be organized in category, simply pass in another parameter at the end of the method beginProfile():

//default category is 'application'
Doo::logger()->beginProfile('id', 'editpost');
//...everything here will be profiled
Doo::logger()->endProfile('id');

To retrieve the profiled results, you called getProfileResult(). You have to pass in the block ID as parameter and you will get an associative array which shows you the time and memory used when processing the code block.

Doo::logger()->beginProfile('block_id');
//...everything here will be profiled
Doo::logger()->endProfile('block_id');
$result = Doo::logger()->getProfileResult('block_id');

To view the profiled results, you just have to call showLogs(). By default it will return a neatly formatted XML which can be filtered by ID or category. You can get a plain text log if you need so:


//display all profiled results
echo Doo::logger()->showProfiles();

//display in plain text
echo Doo::logger()->showProfiles(false);

//display only in category editpost
echo Doo::logger()->showProfiles(true, 'editpost');

//category editpost (plain text)
 echo Doo::logger()->showProfiles(false, 'editpost');

When you have to write the profile results into file, all you have to do is call writeProfiles(). Similar to showProfiles(), it writes the XML string to file by default (profile.xml as the default filename).

//Creates a file profile.xml
Doo::logger()->writeProfiles();

//You can write as plain text
Doo::logger()->writeProfiles('profile.txt', false);

//You can write certain category as well
Doo::logger()->writeProfiles('profile.xml', true, 'editpost');

If you are worried that the files get bigger over time, all you have to do is to specify a file size for file rotation. When this file is reached, the files are automatically purged and new messages will be written.

//maximum file size is 20kb
Doo::logger()->rotateFile(20);
Doo::logger()->writeProfiles();

The profiler writes the file to the where your app located by default (SITE_PATH). If you would like to change where the log files will be stored, simply add the LOG_PATH setting in common.conf.php:

//this will store log files at /var/logs/, eg. /var/logs/log.xml
$config['LOG_PATH'] = '/var/logs/';

Now, for Database profiling, it’s the same as profiling but you use another method instead ( beginDbProfile(’id’) ). DB profiling allows inspection of the queries that have been performed without needing to add extra debugging code to classes. To have a quick test on this, you can download the blog demo in the logging tutorial. Simply open up the bootstrap index.php and uncomment these lines:


# Uncomment for DB profiling
Doo::logger()->beginDbProfile('test');
Doo::app()->run();
Doo::logger()->endDbProfile('test');
Doo::logger()->rotateFile(20);
Doo::logger()->writeDbProfiles();

This will log all the queries executed in the blog application since the code between beginDbProfile and endDbProfile is the application code. Note, the DB profiles are logged in a file named db.profile.xml by default, you can change this behavior just like writeProfiles().

That’s not all! After you have your profiles stored, DooPHP has a handy little tool for you to monitor the results. If you have gone through the default application App, there’s a route call debug which looks like this:

$route['*']['/debug/:filename'] = array('MainController', 'debug');

Let’s view the results profile.xml and db.profile.xml with the log viewer tool. All you need to do is visit http://localhost/amfdemo/blog/tools/logviewer.html. Just enter the debug route + the file name as address:

http://localhost/amfdemo/blog/debug/profile

http://localhost/amfdemo/blog/debug/db.profile

There are bars on the duration and memory fields, process marked with different colors indicates relative difference from average processes.

profiler

Filter by ID (db.profile) or category+ID(profile):

profiler filter by id

Filter by URI:

profiler filter by URI

If you wish to discus further, there’s a thread on this tutorial in the forum here.




You can follow any responses to this entry through the RSS 2.0 feed.