I wrote my first guest post the other day. It was an intro to Xdebug for PHPDeveloper.org. I didn’t like the end result as much as my post on how to use Xdebug to speed up your code.

Popularity: 74% [?]

I swear I’ll get back to reviewing sites. But until then…

I was excited to see a recent SitePoint posting about Xdebug. I’ve recently started using Xdebug to help learn some code at my new job. I didn’t realize it when I first started messing around, but Xdebug also includes some very powerful profiling features.

I was able to figure out how to use the profiling with a little help from the Xdebug docs and playing with WinCacheGrind. Since I never read a formalized method for properly using these tools I was hoping the SitePoint article would show me a better way. Unfortunately, I felt the article was thin on content and actually gave poor advice at one point.

Below is the process I use to find bottlenecks in my web apps (seriously this isn’t all that deep…it shouldn’t take more than 1-2 paragraphs, but I promise pictures)

This assumes you’ve already got Xdebug up and running - it’s really not all the hard.

The SitePoint article suggests setting up your .htaccess as such:

php_value xdebug.profiler_output_dir /tmp
php_value xdebug.profiler_output_name timestamp
php_value xdebug.profiler_enable 1

I like to leave off the xdebug.profiler_output_name from the .htaccess. This defaults to crc32 mode. The advantage of this is that Xdebug won’t create a new output file every time you hit the page. This means I can make a code change, refresh the page, then refresh WinCacheGrind. I don’t have to hunt for the new cachegrind.out file and reload it.

Once Xdebug is outputting cachegrind files I open them in WinCacheGrind. NOTE: Parts of the image have been blacked out.

If I’m trying to learn the flow of an app I use the tree view in the left pane and begin walking through the execution sequence.

When I’m profiling an app to improve performance I go to “Overall” in the top right window. I then sort by “Total Self” to get an idea of what function is taking the longest.

In this example the script spends the most time in the Config_Container->getItem function. Individual function calls are fast (.5ms), but the function is called 2004(!) times.

Looking at the lower right pane I see the backtrace for every time the function was called. The backtrace is the sequence of functions that led to this function. I see that most of the 2004 calls came from the offsetGet function. The optimization I did in this case was refactor the offsetGet function. By doing this I completely removed calls to getItem and cut the number of calls to offsetGet from 393 to 236 (it was a recursive function).

Typically the function with the highest Total Self will be mysql_query (or pg_query depending on the db your using). Generally the sql queries are the slowest part of any application. By looking at the stack trace window for the mysql_query function you can see how many queries are being run and how long each takes.

Unfortunately it doesn’t show the actual query that is run, but it isn’t hard to figure out. If you’re using CakePHP, with debug on, you’ll see all the queries outputted in you browser. Or you use the stack trace to find where the query was created/called.

There are two types of optimizations you can do with this information. The first is reducing the number of queries. I was profiling an app I recently inherited and saw that is was doing over 100 queries to generate a search results page. It was doing one query to find the list of products, then looping through that and doing a query for each one to get the details. So for the 50 records displayed it needed to do 51 queries…

…And it did the whole sequence twice.

Thats 102 queries just for the results part of the page. By using a simple join and by checking if I already had search results I was able to cut this whole sequence to one query.

Another quick example from the same vein: I was trying to figure out a slow page on the same app. There were only five queries being run, but one of them was taking 1400ms. I found the query in the code and saw that it was a monster. Multiple levels of joins, with multiple sub selects. It wasn’t pretty. I refracted the query down to 300ms. Still slow, but over a second faster.

The fixes themselves aren’t the point of this. The point is to use Xdebug, find the slowdowns IN YOUR CODE and make the fixes there.

This brings me to my disagreement with the SitePoint article. The author writes “And the easiest way to get your code running faster? Cache, cache and more cache.”

SitePoint promotes query caching, APC, ect as methods for overcoming these bottlenecks. All great tools, but they should be used to help maximize an already slick app, not cover up the weaknesses of poor coding. The point is to use Xdebug to find your jams, refactor to make the code as optimized as possible, then add query caching, APC, whatever on top.

Xdebug is so ridiculously simple to use I can pick out the major bottlenecks in under thirty seconds. Speeding these up may take considerably longer, but it’s worth the effort in the end. Yes, using the tactics in the SitePoint article may be the “easiest”, but they’re really just masking the issue. If your using Xdebug to find slowdowns in your code, then go into your code and fix them.

Popularity: 73% [?]