Identifying MySQL slow queries

One of the most important steps in optimizing and tuning mysql is to identify the queries that are causing problems. How can we find out what queries are taking a long time to complete? How can we see what queries are slowing down the mysql server? Mysql has the answer for us and we only need to know where to look for it…
Normally from my experience if we take the most ’expensive’ 10 queries and we optimize them properly (maybe running them more efficiently, or maybe they are just missing a simple index to perform properly), then we will immediately see the result on the overall mysql performance. Then we can iterate this process and optimize the new top 10 queries. This article shows how to identify those ‘slow’ queries that need special attention and proper optimization.

1. Activate the logging of mysql slow queries.

The first step is to make sure that the mysql server will log ‘slow’ queries and to properly configure what we are considering as a slow query.

First let’s check on the mysql server if we have slow query logging enabled:

mysqladmin var |grep log_slow_queries
| log_slow_queries                | OFF                          |

If log_slow_queries is ON then we already have it enabled. This setting is by default disabled - meaning that if you don’t have log_slow_queries defined in the mysql server config this will be disabled. The mysql variable long_query_time (default 1) defines what is considered as a slow query. In the default case, any query that takes more than 1 second will be considered a slow query.

Ok, now for the scope of this article we will enable the mysql slow query log. In order to do to do this in your mysql server config file (/etc/my.cnf RHEL/Centos or /etc/mysql/my.cnf on Debian, etc.) in the mysqld section we will add:

[mysqld]
long_query_time         = 1
log-slow-queries        = /var/log/mysql/mysql-slow.log

This configuration will log all queries that take more than 1 sec in the file /var/log/mysql/mysql-slow.log. You will probably want to define these based on your particular setup (maybe you will want the logs in a different location and/or you will consider a higher value than 1 sec to be slow query).

Once you have done the proper configurations to enable mysql to log slow queries you will have to reload the mysql service in order to activate the changes.

2. Investigate the mysql slow queries log.

After we enabled slow query logging we can look inside the log file for each slow query that was executed by the server. Various details are logged to help us understand how was the query executed:

• Time: how long it took to execute the query
• Lock: how long was a lock required
• Rows: how many rows were investigated by the query (this can help see quickly queries without indexes)
• Host: the actual host that launched the query (this can be localhost, or a different one in multiple servers setup)
• The actual mysql query.

This information allows us to see what queries need to be optimized, but on a high traffic server and with lots of slow queries this log can grow up very fast making it very difficult to find any relevant information inside it. In this case we have two choices:

1. We increase the long_query_time and we focus on the queries that take the most time to complete, and we gradually decrease this once we solve the queries.
2. We use some sort of tool to parse the slow query log file and have it show us the most used queries.

Of course based on the particular setup we might end up using both methods.

MySQL gives us a small tool that does exactly this: mysqldumpslow. This parses and summarizes the MySQL slow query log. From the manual page here are the options we can use:

    -v     verbose
    -d     debug
    -s=WORD
    what to sort by (t, at, l, al, r, ar etc)
    -r     reverse the sort order (largest last instead of first)
    -t=NUMBER
    just show the top n queries
    -a     don't abstract all numbers to N and strings to 'S'
    -n=NUMBER
    abstract numbers with at least n digits within names
    -g=WORD
    grep: only consider stmts that include this string
    -h=WORD
    hostname of db server for *-slow.log filename (can be wildcard)
    -i=WORD
    name of server instance (if using mysql.server startup script)
    -l     don't subtract lock time from total time

For example using:

mysqldumpslow -s c -t 10

we get the top 10 queries (-t 10) sorted by the number of occurrences in the log (-s c). Now it is time to have those queries optimized. This is outside of the scope of this article but the next logical step is to run EXPLAIN on the mysql query and then, based on the particular query to take the appropriate actions to fix it.