Benchmarking Drupal with xDebug Profiler and kCacheGrind

The other day I decided to finally figure out how to do a little benchmarking on some of the code we've been working on, and on my co-worker Jason's lead, I started fumbling around for a way to use kCacheGrind, which allows you to visualize where the bottlenecks are in your code, showing you information like how much time was spent on each function, in milliseconds or percentages. Very cool, but it took a while to get the setup just right. So, this is a cheat sheet to capture my research.

First of all, here's the aspects of my setup that might differ from yours:

  • Mac OSX
  • I'm using VMWare Fusion for hosting a Linux virtual machine
  • xDebug was already installed and enabled on my local machine

In a nutshell, here's how it works:

  • Using a firefox plugin and the php xDebug extension, you turn on xDebug profiler and load a page
  • xDebug creates 'cachegrind' files, which contains information about each php function that ran during that page load.
  • Open the cachegrind files with kCacheGrind to visualize the data.

You could do this all in Linux, but I end up creating the files on my mac and then drag them over to an Ubuntu virtual machine.

And here's the steps:

1. Download the firefox xDebug plugin

2. Set up xDebug profiler configuration in php.ini.

A cachegrind file can be created for each process, and Apache typically uses several processes for each page load. After some experimentation, I realized I wanted all of these merged together in a single file, which is what the settings below will do. Technically, this is 'append' mode, and if you refresh the page again, it will continue to append information. So, I will load a page, then I'll change the filename slightly (added a description at the end, for example), so the next page load will create a new file. Below are the php.ini settings I use for xDebug (set up to use remote debugging) and the xDebug profiler. I've bolded the lines you need to change to reflect your setup:

; xDebug settings
zend_extension=/Applications/MAMP/bin/php5/lib/php/extensions/no-debug-non-zts-20050922/xdebug.so
xdebug.remote_enable=1
xdebug.remote_handler=dbgp
xdebug.remote_mode=req
xdebug.remote_host=127.0.0.1
xdebug.remote_port=9000 ; Choose a port

; profiler settings
xdebug.profiler_append=1
;xdebug.profiler_append=0
xdebug.profiler_enable=0
xdebug.profiler_enable_trigger=1
xdebug.profiler_output_name = cachegrind.out.%s
xdebug.profiler_output_dir=/xdebug/

3. Make sure cachegrind files are getting saved

Turn on the profiler in Firefox by clicking the little (p) button in the lower right corner of the window. Then, load a page that's hosted on your local machine (I haven't checked how remote testing works). A file should be generated in the directory you specified for xdebug.profiler_output_dir.

4. Get an Ubuntu virtual machine

If you don't have an Ubuntu machine and have VMWare fusion, download a torrent for a full Ubuntu setup. If you haven't used torrents yet, Transmission is a good client for mac, and Azareus is the only one I have experience with on Windows.

5. Install kCacheGrind

Use the Add Applications menu item in Ubuntu and search for kCacheGrind. The install might take a while because there's a lot of dependecies.

6. Test out kCacheGrind

Once installed, open up a cachegrind file in kCacheGrind. You should see a lot of pretty colors and be a little confused. Perfect, that means it's working.

I haven't spent a lot of time figuring out the different levels of information in kCachegrind, but just the basic information is useful. It's easy to see which functions eat up the most processing power.

A couple other thoughts once you get to this point:

  • Each page load might be quirky for one reason or another, so it might help to balance out between several loads. Since we've set up the profiler in append mode, just refresh the page a particular number of times. Just remember how many time so that when you benchmark changes you can make an accurate comparison of the changes.
  • In addition to seeing the amount of time spend on functions, you can see how many times it was called, and by what. I noticed a function right away that was being run several times when it only needed to be run once. It's because I assumed that template.php was only included once. I realized this is a good way to test out some of your assumptions.

Sources

Below are some links I found particularly useful for information:
http://elrems.wordpress.com/2008/02/12/profiling-php-with-xdebug-and-wincachegrind/ - Info for setting up php.inihttp://www.maccallgrind.com/ Mac callgrind reader (for use in a pinch, it was hard to find useful information in it, though)http://derickrethans.nl/files/phparch-xdebug-qa.pdf - Info about what the xDebug configuration lines actually mean
http://www.xdebug.org/docs/all_settings#trace_output_name - Variables that can be used for naming the cachegrind output files

- Credit to other co-worker Caleb for "Promoting me to get off my ass and write a blog post"



Comments

Awesome! And? What's the verdict? Where are the bottlenecks? Looking forward to that next blog post =)

A few notes:
1) to install xdebug on OSX with the Entropy PHP package, this post is helpful: http://www.designified.com/blog/article/52/installing-xdebug-for-php-ent...
2) KCacheGrind can be installed on OSX via fink:

fink install kcachegrind

You may encounter problems with libxml2, ptex, kde. I had to install a few packages by hand but slowly got the problems to go away.

To run kcachegrind, open X11 and type kcachegrind in the terminal window. Now you just need to feed it your grinded files .

More complete instructions on installing kcachegrind on osx are here: http://24b6.net/2009/06/11/kcachegrind-osx
This is a bit more clear than my instructions here.

Kcachegrind is also available for Macports, so you don't need a separate Linux installation to use it.

I played around with kCacheGrind for about a month before I decided it was pointless. I was working on a site for this cluster of moving companies and I got so caught up in trying to analyze my code that I missed my deadline by about ten days. Just my personal experience, no intention of ripping on anybody or this blog, just wanted to share my experience.