I was doing some MySQL query performance tuning on DGM Live today using maatkit. Maatkit is a toolkit for measuring, what else, MySQL performance. The two tools that I played around with specifically were the slow query log parser and the query profiler.
I don’t use perl a whole lot, so the first thing I had to do was install perl’s DBI module.
I jumped into the cpan prompt:
shell> cpan
And then installed the module:
cpan> install DBI
And then force installed DBD::mysql. I had to use force install so that when the tests to connect to my local MySQL server failed, it didn’t rollback the install. I know that the MySQL server is working and can be reached from my local box, so I don’t care about the tests failing:
cpan> force install DBD::mysql
I then exit out of the cpan shell and the maatkit scripts are now part of my executable path. First, I ran the mk-query-profiler script over a couple of sluggish queries that were stored in a .sql file. NOTE: It’s important that each query in the SQL file not only have a semi-colon at the end of the statement, but if you’re analyzing multiple queries then there as to be a full line of white space between the queries, not just a line break.
shell> mk-query-profiler --user backend --askpass --database dgmms ~/queries.sql
The output shows an overview of the information provided by the show status call provided by MySQL.
+----------------------------------------------------------+
| 2 (3.1201 sec) |
+----------------------------------------------------------+
__ Overall stats _______________________ Value _____________
Total elapsed time 6.231
Questions 2
COMMIT 0
DELETE 0
DELETE MULTI 0
INSERT 0
INSERT SELECT 0
REPLACE 0
REPLACE SELECT 0
SELECT 2
UPDATE 0
UPDATE MULTI 0
Data into server 944
Data out of server 169031
Optimizer cost 10919.360
__ Table and index accesses ____________ Value _____________
Table locks acquired 6
Table scans 0
Join 0
Index range scans 0
Join without check 0
Join with check 0
Rows sorted 137
Range sorts 0
Merge passes 0
Table scans 2
Potential filesorts 2
The key value that’s helpful to see here, either as a bulk value for all queries or on a per-query basis, is the optimizer cost. I want to get this number as low as possible. I can add a -s flag to my command to break the results out by query.
+----------------------------------------------------------+
| QUERY 1 (3.0744 sec) |
+----------------------------------------------------------+
SELECT COUNT...
__ Overall stats _______________________ Value _____________
Elapsed time 3.074
Data into server 478
Data out of server 11224
Optimizer cost 5459.680
__ Table and index accesses ____________ Value _____________
Table locks acquired 3
Table scans 0
Join 0
Index range scans 0
Join without check 0
Join with check 0
Rows sorted 10
Range sorts 0
Merge passes 0
Table scans 1
Potential filesorts 1
+----------------------------------------------------------+
| QUERY 2 (3.0618 sec) |
+----------------------------------------------------------+
SELECT COUNT...
__ Overall stats _______________________ Value _____________
Elapsed time 3.062
Data into server 466
Data out of server 157807
Optimizer cost 5459.680
__ Table and index accesses ____________ Value _____________
Table locks acquired 3
Table scans 0
Join 0
Index range scans 0
Join without check 0
Join with check 0
Rows sorted 127
Range sorts 0
Merge passes 0
Table scans 1
Potential filesorts 1
+----------------------------------------------------------+
| QUERY 2 (3.0618 sec) |
+----------------------------------------------------------+
__ Overall stats _______________________ Value _____________
Total elapsed time 6.136
Questions 2
COMMIT 0
DELETE 0
DELETE MULTI 0
INSERT 0
INSERT SELECT 0
REPLACE 0
REPLACE SELECT 0
SELECT 2
UPDATE 0
UPDATE MULTI 0
Data into server 944
Data out of server 169031
Optimizer cost 10919.360
__ Table and index accesses ____________ Value _____________
Table locks acquired 6
Table scans 0
Join 0
Index range scans 0
Join without check 0
Join with check 0
Rows sorted 137
Range sorts 0
Merge passes 0
Table scans 2
Potential filesorts 2
The difference between these two queries is that one of them has a LIMIT clause to reduce the result set size, which is the reason for the difference in teh size of the ‘Data out of server’, but it doesn’t make any difference to the optimization cost.
This was a difficult query to tune because the data was joined across three tables that all had a high cardinality, and the row traversals were minimal. I determined that a GROUP BY clause on the largest of the tables was causing a lot of CPU consumption which was slowing the query down. In the end, I decided to break the larger complex query up into two simpler queries. The total execution time was cut down to almost a tenth of the original query execution time, and resulted in less work for the processor overall.
The query profiler didn’t lead me to that conclusion right away, but it provided a very useful tool to quickly try different approaches and test them for performance.
The query profiler can do more than just take a file or standard input of queries. It can also analyze the performance of queries run against the server, by aggregating the show status information for all the queries. You simply use the –external flag instead of passing in a file and press ENTER when you’re done profiling the server.
This is very handy for getting a quick sense of the database overhead on a single page or action in your web application. I used ab, the apache benchmarking utility, to load test the server and ran the query profiler against the load test to get a better picture of how many queries are run and their performance when the server is under heavy load.
The query profiler is only one piece of the maatkit toolkit, and I look forward to playing with the rest of the available scripts to further tune the database layer of my applications.
