Simon Wright

A case study of performance optimisation

I run what could quite possibly be the highest trafficked ColdFusion/MySQL website out there, and while our web hosting benefactors have been gracious, we really don't have the computing power needed to competently handle the million or so page views we get each day. So I spend a lot of time looking for ways to do more with less, server-wise.

There's a lot you can do to identify bottlenecks and poorly performing code in your environment. Even after you've picked the low hanging fruit, there can be a lot of small wins that mean a great deal particularly when the server is running hot 18 hours a day. Some of the techniques I use include:

• Monitor ColdFusion for slow-running or blockage-inducing templates using its built-in monitoring facility or a third party tool such as SeeFusion. This method not only lets you quickly identify rogue templates, it also gives you a sense where in your code general performance improvements could be sought.
• Time suspicious pieces of code, follow the trail, and don't be afraid to believe what might at first seem improbable. Session variables, locking and array declarations conspire to make innocuous looking code decidedly malevolent.
• Watch various critical metrics with Windows Performance Monitor such as memory and processor usage, average execution times and disk activity. Investigate suspicious variations with tools like Process Monitor from Sysinternals. We've used this to discover numerous problems including a performance-sapping virus scanner and a misbehaving backup process.
• Keep debugging completely switched off in Administrator! Even when the debug output is suppressed in code, it's still doing a lot of extra work that it does not need to do. Just moving the mouse near that checkbox causes the Whirlpool server to haemorrhage.
• Watch the health of your SQL server. Is your query cache being effective, or even enabled? What about the key buffer? MySQL users now have the excellent Administrator tool, which charts some very useful live metrics including the query cache hitrate.
• Monitor your database server for slow running queries. Microsoft SQL Server has a tool called Profiler that can be configured to show queries that exceed a threshold, although it has limitations (particularly, it can't show slow queries as they're running). With MySQL, run a SHOW FULL PROCESSLIST to discover what's happening in that moment. This becomes particularly handy in a GUI tool where you can refresh this multiple times per second, effectively animating current execution behaviour. You can learn a lot this way.

The case study

Back in January 2007, we upgraded to ColdFusion 7 and MySQL 5... and immediately started seeing a whole bunch of queries running in the MySQL process list which I didn't write. SHOW FULL COLUMNS FROM tablename? I wanted to know where these mysterious queries were coming from, as we were having performance problems with the new configuration and I was sure this was the cause... or at least the symptom.

Step one — make sure it's not my fault. Does it happen on a freshly installed copy of ColdFusion? I had one on my local computer, and it was causing the same symptom: whenever a query is run, SHOW FULL COLUMNS followed like a shadow. Similarly, a freshly installed copy of MySQL with a carefully recreated database schema didn't change anything.

Step two — try regressing versions. My gut assumption was that ColdFusion 7 was innocent, as I had recently upgraded a swath of machines to version 7 at work and didn't see these queries popping up on our MSSQL servers. After many hours of installing and reinstalling, it turned out that it was neither program's fault: it was the combination! Regress either back to their previous versions and the problem went away.

Step three — identify the culprit. After tracing network activity between the servers, it quickly became apparent that these queries were being generated on ColdFusion's end... but how? As I was restoring the configuration for the umpteenth time, the answer hit me: Connector/J! I had been dutifully swapping versions of this jar every time I changed versions of MySQL. So I tried connecting to MySQL 5 with an older version of the connector, and magically, the rogue queries disappeared.

Now this presented an awkward situation. The previous connector did fix things, but it didn't support a number of MySQL 5 features I wanted to take advantage of. And I don't like being forced into avoiding upgrades; certainly not for something as trivial as this. So I downloaded the Java source code to see if I couldn't figure this one out for myself.

One download, unzip and search later, I had my answer. The query string existed in the getCollation() method of com.mysql.jdbc.Field, which in turn was exclusively called by isCaseSensitive() in com.mysql.jdbc.ResultSetMetaData. Immediately I made the logical connection to ColdFusion 7's new result attribute for <cfquery>, which returns such metadata as, you guessed it, case sensitivity.

It turns out ColdFusion was asking Connector/J for the metadata on every field, which in turn triggered a SHOW FULL COLUMNS query for every varchar and text column returned. Since I was using case insensitive collation exclusively throughout my database schema (and I wasn't using the result attribute anywhere), I was able to recompile the connector with the isCaseSensitive() method neutered. Problem solved.

I filed a bug report with MySQL, and it has been resolved as of version 5.0.7 of Connector/J.