Viraj's Weblog

Recently I looked at a client webserver where there were lots of MySQL processes eating up quite a bit of CPU. It's a fairly high traffic site, however when I see mysqld processes staying at 80-90% for more than a few seconds, that tells me something is wrong. It's usually an indication that either they are using some very inefficient queries, do not have the proper indexes, or the tables are getting too large.

So let's see how to debug this. First thing is by the looks of the processes, there must be 1 or 2 queries that are pegging the CPU, and we need to find out what queries are taking long. I started up the mysql client and did a 'show status':

show status;
...
| Slow_queries             | 12256     |
...

Hmm, lot's of slow queries. but that number isn't increasing rapidly. I believe this shows very slow queries only. Next I did a 'show processlist' a few times until something showed up:

show processlist;
...
| 2721 | web  | localhost | development | Query   |    0 | Copying to tmp table |
 SELECT DISTINCT wheel.make FROM inventory LEFT JOIN wheel ON
 inventory.id=wheel.id WHERE status="act |
...

Usually, if you see a query on 'show processlist' consistently, that query is probably unoptimized and taking a long time. The above only showed me part of the query, and I needed to find the whole query to test it. Now I could go digging in the client's source code, but it would be a waste of time trying to find the culprit query. The best way is to enable MySQL logging. MySQL is such a lightweight DB, restarting it usually goes unnoticed even on high traffic webservers. I added to /etc/my.cnf:

[mysqld]
log=/var/log/mysqld/mysqld.log

And made sure to create that logfile writable by the mysql user (it won't log it if it doesn't have the right permissions). Next I find the query I'm looking for:

SELECT DISTINCT diameter
FROM inventory
LEFT JOIN wheel_fitment ON wheel_fitment.wheel=wheel.id
LEFT JOIN wheel ON wheel_fitment.wheel=wheel.id
WHERE status="active" AND vehicle=4566  AND price!=0 AND
wheel_fitment.type="all"
ORDER BY diameter

Ok, I'm not too familiar with the multiple left joins, but I do know what a join is. I run this query manually and it takes anywhere from 6 to 10 seconds to return results. That's definitely too long for a query to take, and the tables are not even that big! Now is when you try to take everything out of the query except the bare necessity that makes it slow. I ended up with:

SELECT DISTINCT diameter 
FROM inventory
LEFT JOIN wheel ON wheel_fitment.wheel=wheel.id
LEFT JOIN wheel_fitment ON wheel_fitment.wheel=wheel.id
WHERE vehicle=4566

Now I needed to know something about these tables. As sysadmins, we usually come in the picture when something has gone wrong, and we really played no part in the development of the system we are diagnosing. I wanted to know whether there were indexes on the tables. I did 'show create table wheel' as well as wheel_fitment and inventory. They all seemed to have proper indexes on the fields being used in the query. Hm what next? Well the double 'LEFT JOINs' looked kinda wierd to me, they are just swapped. The resulting set if I take out the 'DISTINCT' is something like 250k rows, much larger than all of the tables combined. Clearly something is wierd.

I checked the mysql join docs for some help, and determined that the following provides the same results:

SELECT DISTINCT diameter
FROM inventory LEFT JOIN (wheel, wheel_fitment)
ON (wheel_fitment.wheel=wheel.id)
WHERE vehicle=4566

Only now the query takes less than .3 seconds, quite an improvement from 10 seconds! My guess is that MySQL is better able to optimize the latter query.