I work with a lot of PHP applications, and part of my job is optimizing those applications to reduce server costs and maximize how many requests each server can handle. There are many ways to do this, but I’m going to talk about using a profiler, which is one of the better ways to start optimizing your code base.
You’ve probably heard people saying not to get caught up in premature optimization, maybe you’ve heard them follow up with profile your code to find the bottlenecks. A lot of people don’t know what this means, or are under the impression that profiling is quite hard to setup. However, this is certainly not true. Profiling PHP is very simple, thanks to the wonderful Xdebug extension. Before we get started setting up Xdebug, you’re going to need a program to read the profiling information files, known as cachegrind files. I personally recommend using KCacheGrind (also available on Windows), although WinCacheGrind is another good alternative. Finally, there is a very lightweight profiler called WebGrind that is web based. You should download and install one of these programs.
Before continuing, a small note about callgrind/cachegrind files. Callgrind is a tool included with Valgrind, a C/C++ analysis tool. A lot of different profilers support this format, so the information about interpreting the results below are language agnostic.
These instructions are for Ubuntu, however it’s pretty easy to find instructions for whatever platform you are on. Xdebug is quite popular.
Simply install the Xdebug PHP extension using apt, and you’re set:
sudo apt-get install php5-xdebug
You may need to restart Apache/PHP-FPM. You can verify it’s installed using phpinfo, or by running
php -i | grep xdebug.
Next, we need to enable the Xdebug profiler (it’s disabled by default). We have two options here: Always on, or we can turn it on my setting a GET parameter or cookie. I recommend the second option, it’ll make your life easier.
Edit your php.ini file, and add the following option:
xdebug.profiler_output_dir = /path/to/store/cachegrind/files
I use the following:
xdebug.profiler_output_dir = /var/www/_profiler
Make sure the directory exists.
Next, enable the profiler.
xdebug.profiler_enable = 1
Enabled using the GET/POST/COOKIE param XDEBUG_PROFILE=1:
xdebug.profiler_enable_trigger = 1
The above settings are mutually exclusive, so only use one of them.
Dumping A Cachegrind File
Cachegrind files contain all of the profiling information for your application. Simply navigate to your site with the GET parameter set, like so:
In the configured profiler output directory, you should see a file named like this: cachegrind.out.8803 (the number will be different for you)
Now, open this file using your cachegrind viewer.
This is an example from a local development machine running WordPress, that was loading quite slowly for some reason. The first thing you should do, is sort by “Self” time, like I have. Please note that times here are relative, and don’t mean a whole lot by themselves.
If you’re wondering what the different between “Incl” (Inclusive) and Self time is, it’s quite simple. Inclusive time is the time required to run a function including the time it took to run every other function called by this function. That’s why your main file will have the highest inclusive time, it runs everything. Self time is far more useful, and is the time it took to run just that function, not any functions called by it. That’s the column important for optimization. Here, we can see that curl_exec was called 7 times, and took about 10 times longer than the next slowest call.
You can use the callers tab to see which functions called each function, and step through the execution of your program. You can also browse the source code for the function being called (You may have to map directories to your source directory if you’re running kcachegrind on another machine, do this from the settings). I did this for the above curl_exec, and was able to narrow down the trouble to the WordPress version check, which I then disabled as I do updates to this site manually.
On another site, I noticed the custom routing function was taking a substantial amount of time to map routes. When I looked at the function, it was doing a bunch of work to clean up and normalize the routes. This was a developer convenience feature, but had a high performance cost. I removed all of the normalization code, and fixed all of the routes to ensure they were already normalized, and it sped the site up by about 12ms.
The Call Graph
The call graph, a tab located in the bottom right pane, is a useful visualization of the call graph for the currently selected function call.
A call graph is a directed graph that representing the calling relationships between functions in your code. The functions pointing TO get_option (in the middle) are functions that call get_option. The functions that get_option points to are functions called from in the get_option function itself. This tool is useful for visualizing the cost of a function and where the cost comes from.
Profiling your code allows you to find the slowest calls and spend effort fixing those, instead of blindly fixing things that may have very little impact on performance. It’s an essential tool for any developer. I urge any programmers reading this to get familiar with a profiling tool, whether it’s Xdebug for PHP or the equivalent for your language of choice. It will make you far more productive, and you’ll wonder how you lived without it!