JIYIK CN >

Unusually slow queries are one of the most common MySQL performance issues. Queries that perform acceptably in development may falter under the pressure of a production workload.

Large applications may run hundreds of unique database queries every time an endpoint is hit. This makes it difficult to single out the query that is causing the server to delay response. The MySQL slow query log is a debugging option that can help us identify suspicious SQL statements, providing a starting point for our investigation.

Enable slow query log

The log is a built-in mechanism for recording long-running SQL queries. Queries that do not complete within the configured time are written to the log. Reading the contents of the log will show the SQL executed and the time taken.

By default, slow query logging is turned off. We can activate it on our server by running the following command from the administrative MySQL shell:

SET GLOBAL slow_query_log_file='/var/log/mysql/mysql-slow.log';
SET GLOBAL slow_query_log=1;

The changes take effect immediately. Slow queries will now be logged to /var/log/mysql/mysql-slow.log . We can review this file periodically to identify poorly performing queries.

MySQL counts a query as "slow" if it takes more than 10 seconds to complete. This limit is often too lenient for user-facing web applications that require near-instant responses. We can long_query_timechange the limit by setting the variable:

SET GLOBAL long_query_time=1;

This value sets the minimum duration of slow queries. It is important to find the right balance for our own application. Too high a threshold will exclude queries that actually affect performance. Conversely, a very low value will cause too many queries to be captured, resulting in an overly noisy log.

Using the MySQL configuration file

If you plan to use it long term, you should enable the slow query log in your MySQL configuration file. This will ensure that logging is automatically resumed after a MySQL server restart.

The location of the configuration file may vary depending on the platform distribution. It is usually located at /etc/mysql/my.cnf or /etc/mysql/mysql.conf.d/mysqld.cnf . Add the following line to replicate the settings enabled dynamically above:

slow_query_log=1
slow_query_log_file=/var/log/mysql/mysql-slow.log
long_query_time=1

Restart MySQL for our changes to take effect:

$ sudo service mysql restart

The slow query log is active every time the MySQL server starts.

Customize log content

The logs typically only include SQL queries that exceed the "slow" threshold and are submitted by client applications. This does not include any slow administrative operations that may have occurred, such as index creation and table optimization, and queries that may become slow in the future.

We can extend the log to include this information by making the following changes to the configuration file:

• log_slow_admin_statements = 1 – includes administrative SQL statements such as ALTER TABLE, CREATE INDEX, , DROP INDEXand OPTIMIZE TABLE. This is rarely desirable, as these operations are typically run during maintenance and migration scripts. Nonetheless, this setting can be useful if our application also performs these tasks dynamically.
• log_slow_replica_statements = 1 – This setting enables slow query logging for replication queries on the replica server. Disabled by default. For MySQL 8.0.26 and earlier, use log_slow_replica_statements instead log_slow_slave_statements.
• log_queries_not_using_indexes = 1 – When this setting is enabled, queries that are expected to retrieve all records from the target table or view are logged, even if they do not exclude the slow query threshold. This helps determine when a query is missing an index or cannot use it. Queries with available indexes are still logged if there is a lack of constraints limiting the number of rows fetched.

Logging queries that do not use indexes can increase verbosity significantly. In some cases, a full index scan may be needed or required. These queries will continue to show up in the log even if they cannot be resolved.

We can log_throttle_queries_not_using_indexeslimit queries without indexes by setting the _query_info variable. This defines the maximum number of logs that will be written in 60 seconds. A value of 10 means that a maximum of 10 queries will be logged per minute. After the tenth event, no more queries will be logged until the next 60 second window opens.

Explaining the slow query log

Each query that goes into the slow query log will show a set of lines similar to the following:

# Time: 2022-07-12T19:00:00.000000Z
# User@Host: demo[demo] @ mysql [] Id: 51
# Query_time: 3.514223  Lock_time: 0.000010  Rows_sent: 5143  Rows_examined: 322216
SELECT * FROM slow_table LEFT JOIN another_table ...

The commented lines above the query contain the execution time, the MySQL user the client connected to, and statistics providing the duration and number of rows sent. The example above took 3.5 seconds to complete and looked at over 320,000 rows, then only sent 5,143 rows to the client. This may indicate that a missing index is causing MySQL to examine too many records.

We can choose log_slow_extra = 1to include more information in the log by setting the SYSLOG system variable in the configuration file. This will add the thread ID, the number of bytes received and sent, the number of rows considered sorted, and statement-specific request counts that provide visibility into how MySQL is processing queries.

The log file must be handled with care, as its content is sensitive. Queries are displayed in full, without any masking of parameter values. This means that user data will be present if we use the slow query log on a production server. Access rights should be limited to developers and database administrators who tune SQL statements.

Slow query logging and backup

MySQLDumpA common frustration with the slow query log occurs when we also use to create database backups. Long-running SELECT * FROM ...queries will be executed to get data from our tables and feed them to our backups. They will be included in the slow query log like any other SQL statements. If we are doing backups regularly, this can pollute the log.

We can mysqldumpfix this by temporarily disabling the slow query log before running . We can reactivate the log after the backup is complete. Adjust our backup script so that it looks similar to the following:

#!/bin/bash

# Temporarily disable slow query logging
mysql -uUser -pPassword -e "SET GLOBAL slow_query_log=0";

# Run mysqldump
mysqldump -uUser -pPassword --single-transaction databaseName | gzip > backup.bak

# Enable the slow query log again
mysql -uUser -pPassword -e "SET GLOBAL slow_query_log=1"

This will MySQLDumpkeep activity away from the slow query log, making it easier to focus on the SQL executed by your application.

Summarize

The MySQL slow query log is one of the most effective ways to pinpoint the cause of performance issues. Start by estimating the latency we are experiencing and use this value as the default long_query_time. If there is nothing in the log after reproducing the issue, decrease the value.

The slow query log won't tell us the exact fix. However, the ability to see the exact SQL the server received allows us to re-execute poorly performing statements and then measure the effect of the optimization. Adding an index or missing constraint can be the difference between a query involving thousands of rows and one that processes a handful of rows.