MySQL Slow Query Log – Stephen R Lang

Ever wonder why MySQL is spiking the CPU on your database server during the worst possible times? Then when you log into MySQL and run a ‘show processlist;’, you can never seem to catch exactly what query was running? The MySQL slow query log can help!

In short, the slow query log is a recording of all queries that took longer then a specified period of time to run. This information becomes valuable as it will help identify which queries are very intensive, which may lead you to having to create a table index, or perhaps showing you a plugin for you site that is performing queries in a very inefficient manner.

On most systems, the slow query log is disabled by default. However enabling it is very simple and can be applied without restarting MySQL.

Getting started, first create the log file, and set the proper permissions:

[root@db01 ~]# touch /var/lib/mysql/slow-log
[root@db01 ~]# chown mysql:mysql /var/lib/mysql/slow-log
[root@db01 ~]# chmod 640 /var/lib/mysql/slow-log

Now enable the slow query log without restarting the MySQL. The commands below will instruct MySQL to log any query that takes longer then 2 seconds:

[root@db01 ~]# mysql
mysql> SET GLOBAL slow_query_log=1;
mysql> SET GLOBAL slow_query_log_file="/var/lib/mysql/slow-log";
mysql> SET GLOBAL long_query_time=2

Now, update the systems my.cnf so the changes will persist if MySQL is restarted in the future:

[root@db01 ~]# vim /etc/my.cnf
[mysqld]
...
#log-output = FILE
slow-query-log = 1
slow-query-log-file = /var/lib/mysql/slow-log
long-query-time = 2
#log-queries-not-using-indexes = 0
...

Finally, don’t forget to setup log rotation for the slow query log as this can grow very large.

[root@db01 ~]# vim /etc/logrotate.d/mysqllogs
/var/lib/mysql/slow-log {
        missingok
        rotate 2
        size 125M
        create 640 mysql mysql
}

Now with the slow query log enabled, simple check the log file to see what queries took longer than 2 seconds to run. I’ll post an example below:

[root@db01 ~]# cat /var/lib/mysql/slow-log
# Time: 160210 22:45:25
# User@Host: wpadmin[wordpressdb] @ localhost []
# Query_time: 14.609104  Lock_time: 0.000054 Rows_sent: 4  Rows_examined: 83532
SET timestamp=1301957125;
SELECT * FROM wp_table WHERE `key`='5544dDSDFjjghhd2544xGFDE' AND `carrier`='13';

If the above query is shown repeatedly within the log file, perhaps running several times a minute, this could be a possible culprit for our CPU issues with MySQL. The key fields to pay attention to are “Rows_examined:” and the actual query itself.

If the “Rows_examined:” field is reporting over a few hundred, that could mean that you may need to create a table index. The query itself is also important because if a table index is not possible for one reason or another, your developer will be able to review the query to possible try optimizing or rewriting it, so it returns less rows to MySQL, therefore making the query more CPU friendly.