Using mysqldumpslow to read the mysql slow query log

Rob

Administrator
Staff member
Joined
Oct 27, 2011
Messages
1,207
Reaction score
2,239
Credits
3,467
The MySQL slow query log is one helpful tool that helps system administrators to determine which queries are taking a longer-than-normal time to run. The only thing is.. how to read it so it's helpful?

If you don't have the slow query log enabled yet, do that first: mysql enable slow query log
(Then, let it cook at least a few hours)

If you just less the log file, it'll look something like this:
Code:
# Time: 151123 12:30:06
# User@Host: root[root] @ localhost []
# Query_time: 4.742081  Lock_time: 0.000284 Rows_sent: 28  Rows_examined: 2179
use mysql;
SET timestamp=1448299806;
SELECT TABLE_SCHEMA as DB,SUM(DATA_LENGTH)+SUM(INDEX_LENGTH) AS SPACEUSED from information_schema.tables WHERE TABLE_TYPE NOT LIKE '%view%' GROUP BY TABLE_SCHEMA;

mysqldumpslow will look through the log file and group similar queries together - even showing you the top x queries - either by group or time.

Here are a couple of good examples of how to read it using mysqldumpslow:

You can run it without any flags. It will combine all of the like queries…
Code:
mysqldumpslow /var/log/mysql/mysql-slow.log

The following will show you the top 5 queries which returned the maximum rows. It can help you find the queries where you missed LIMIT clause.
Code:
mysqldumpslow -a -s r -t 5 /var/log/mysql/mysql-slow.log

Example output:
Code:
root@server [~]# mysqldumpslow -a -s r -t 5 /var/log/mysql/mysql-slow.log

Reading mysql slow query log from /var/log/mysql/mysql-slow.log
Count: 97  Time=4.54s (440s)  Lock=0.00s (0s)  Rows=861807.3 (83595305), root[root]@localhost
  SELECT /*!40001 SQL_NO_CACHE */ * FROM `db_banner_tracks`

Count: 11  Time=3.73s (41s)  Lock=0.00s (0s)  Rows=112228.8 (1234517), root[root]@localhost
  SELECT /*!40001 SQL_NO_CACHE */ * FROM `smtp`

Count: 1  Time=126.46s (126s)  Lock=0.00s (0s)  Rows=866765.0 (866765), somedb[somedb]@localhost
  SELECT * FROM `db2_sandbox`.`db_banner_tracks`

Count: 46  Time=4.60s (211s)  Lock=0.00s (0s)  Rows=13268.0 (610330), root[root]@localhost
  SELECT /*!40001 SQL_NO_CACHE */ * FROM `db_ucm_history`

Count: 1  Time=31.40s (31s)  Lock=0.00s (0s)  Rows=258657.0 (258657), anotherdb[anotherdb]@localhost
  SELECT * FROM `db2_test`.`db_banner_tracks`

This one will sort output by count - the number of times the query is found in the slow log.
Code:
mysqldumpslow -a -s c -t 5 /var/log/mysql/mysql-slow.log

Play around with it a bit - here are the various flags you can use:
Code:
-a    Do not abstract all numbers to N and strings to S
-n    Abstract numbers with at least the specified digits
--debug    Write debugging information
-g    Only consider statements that match the pattern
--help    Display help message and exit
-h    Host name of the server in the log file name
-i    Name of the server instance
-l    Do not subtract lock time from total time
-r    Reverse the sort order
-s    How to sort output
-t    Display only first num queries
--verbose    Verbose mode[code]

More information on MySQL's mysqldumpslow page: <a href="https://dev.mysql.com/doc/refman/5.6/en/mysqldumpslow.html" target="_blank">https://dev.mysql.com/doc/refman/5.6/en/mysqldumpslow.html</a>
 
Last edited:


Excellent tip. I am assuming if there is no 'mysql-slow.log' file this is because there has been no slow queries?
 
I've seen mysql create the file upon reload.. perhaps versioning is different. I tested on 5.5 and it created it, but not on 5.6 in my test environments..
 
I checked the version I am using:
mysql Ver 14.14 Distrib 5.5.55
 


Top