Using mysqldumpslow to read the mysql slow query log

[Rob]

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:

# 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…

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.

mysqldumpslow -a -s r -t 5 /var/log/mysql/mysql-slow.log

Example output:

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.

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:

-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>

 

[KarlLinux]

Excellent tip. I am assuming if there is no 'mysql-slow.log' file this is because there has been no slow queries?

 

[Rob]

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..

 

[KarlLinux]

I checked the version I am using:
mysql Ver 14.14 Distrib 5.5.55

 

[Rob]

I checked the version I am using:
mysql Ver 14.14 Distrib 5.5.55

Try a mysql restart instead and see if it creates the file..

Rob