Identifying bottlenecks in your PHP scripts, using XDebug and KCacheGrind

This entry focuses on how to identify slow parts of your scripts using the PHP/Xdebug profiling feature along with KCacheGrind for profile data visualisation. Xdebug is a PHP extension used for debugging scripts, supporting stack and function traces and information and memory allocation profilling. KCacheGrind is a profile data visualisation tool, allowing for easy browsing of performance results. In this article, Xdebug is installed in Ubuntu Linux side by side with FreeBSD, and KCacheGrind is installed in Ubuntu Linux only.

Getting your server ready for PHP/Xdebug profiling

Bellow are the steps to follow for installing and configuring PHP Xdebug in Ubuntu Linux and FreeBSD. The process for other Linux distributions should be similar, but with different package names and configuration file paths.

How to Install in Ubuntu Linux

1. Install the PHP-Xdebug package:

   sudo apt-get install php5-xdebug

How to Install in FreeBSD

1. Install the PHP-Xdebug port (as root):
   Method 1 (using pre-built packages):

   pkg_add -r php-xdebug
   

   Method 2 (from ports, compiling the source code):

   cd /usr/ports/devel/php-xdebug && make install clean
   

2. Prepare ‘extensions.ini’ for the new extension (note that if an ‘xdebug.so‘ entry is already present, it should be removed before hand):

   echo "zend_extension=/usr/local/lib/php/20100525/xdebug.so" >> /usr/local/etc/php/extensions.ini
   

How to configure and enable:

Both operating systems have identical configuration syntax and options. The only difference is file location. In Ubuntu, it resides in ‘/etc/php5/conf.d/20-xdebug.ini‘, while in FreeBSD in ‘/usr/local/etc/php.ini‘. In the example below, I am configuring the profiler to be triggered by passing the XDEBUG_PROFILE get variable when accessing a target URL, the output folder to /tmp/, and the output file name to ‘cachegrind.SCRIPTNAME.out‘. The ‘SCRIPTNAME‘ format is ‘PATH_TO_PHP_FILE_ON_DISK_PHP‘ (further details are available here).

1. Open the file for editing, and append the following lines:

   xdebug.profiler_enable_trigger = 1
   xdebug.profiler_output_dir = /tmp/
   xdebug.profiler_output_name = cachegrind.%s.out

2. Restart Apache, to enable the module and apply settings:
   Ubuntu Linux:

   sudo service restart apache

   FreeBSD (as root):

   apachectl restart

Install KCacheGrind in Ubuntu Linux:

1. Install KCacheGrind package:

   sudo apt-get install kcachegrind

Generate a profiling file:

To generate a profiling file, you need to append the XDEBUG_PROFILE=1 get variable, to the requested URL. For example: http://grosan.co.uk/?XDEBUG_PROFILE=1. The resulting file should now be stored in ‘/tmp/cachegrind._var_www_grosan.co.uk_index_php.out‘. Note that slashes from the file path and dots from the script name have been replaced with an ‘_’. In this example, I am profiling the ‘index.php‘ script, from a standard WordPress install, located in a folder named ‘/var/www/grosan.co.uk/‘. This file can be downloaded to your Ubuntu Desktop.

Browse the profiling data:

Open KCacheGrind, by typing ‘kcachegrind‘ in the command line, click ‘Open‘ and select the profiling data file. Below is an example of resulting data:

How to read the above screenshot:

Left hand side: On the left hand side of the screen is a list ‘Function‘ calls, starting from then ‘main‘ function, which is the PHP process, ending with the last function called. The ‘Self‘ column specifies the percentage of time used by the function itself, while ‘Incl‘ specifies the amount of time in percentage including functions called by it. ‘Called‘ displays the number of times a function is called.

Top right hand side: The top right hand side tabs include: ‘Types‘, ‘Callers‘, ‘All Callers‘, ‘Callee Map‘ and ‘Source Code‘. In this example, the ‘Callee Map‘ tab displays a diagram of all function calls originating from ‘main‘.

Bottom right hand side: The bottom right hand side tabs include: ‘Parts‘, ‘Callees‘, ‘All Callees‘, ‘Caller Map‘, ‘Machine Code‘. In this example, the ‘Call Graph‘ displays a hierarchical diagram of all function calls originating from ‘main‘, along with percentage of use from the parent function.

Identifying the bottleneck:

In this example, a possible bottleneck appears to be the ‘get_template_part()‘ function, as it consumes 40% of the parent script, and is called 8 times. While this article does not focus on the optimisation process itself, this function would be a good starting point for optimising the script.

References:

http://kcachegrind.sourceforge.net/cgi-bin/show.cgi/KcacheGrindDocs

http://xdebug.org/docs/profiler