Example blog

How to Enable MySQL Slow Query Log

Unexpectedly slow queries are one of the most common MySQL performance issues. A query that performs acceptably in development may fail when stressed by a production workload.

Large applications can execute hundreds of unique database queries each time an endpoint is hit. This makes it difficult to identify requests that are causing delays in server response. The MySQL Slow Query Log is a debugging option that can help you identify suspicious SQL statements, providing a starting point for your investigations.

Enabling Slow Query Log

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

Slow query logging is disabled by default. You can enable it on your server by running the following command from a MySQL administration shell:

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

The change applies immediately. Slow queries will now be logged in /var/log/mysql/mysql-slow.log. You can review this file periodically to identify poorly performing queries.

MySQL considers a query “slow” if it takes longer than 10 seconds to complete. This limit is generally too loose for user-facing web applications where near-instantaneous responses are expected. You can change the limit by setting the long_query_time variable:

SET GLOBAL long_query_time=1;

The value defines the minimum duration for slow queries. It is important to find a balance that suits your own application. Too high a threshold will exclude queries that actually have a performance impact. Conversely, very low values ​​can cause too many requests to be captured, creating an excessively noisy log.

Use MySQL configuration file

You should enable slow query logging in your MySQL configuration file if you plan to use it long term. This will ensure that logging resumes automatically after the MySQL server restarts.

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

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

Restart MySQL to apply your changes:

$ sudo service mysql restart

The slow query log will now be active each time the MySQL server is started.

Customizing Log Content

The log normally only includes SQL queries that exclude the “slow” threshold and that were submitted by client applications. This excludes any slow administrative operations that may occur, such as index creations and table optimizations, as well as queries that have the potential be slow in the future.

You can extend the log to include this information by making the following changes to your 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 because these operations are usually performed during maintenance and migration scripts. However, this parameter can be useful if your application also performs these tasks dynamically.
  • log_slow_replica_statements = 1 – This setting enables slow query logging for replicated queries on replica servers. This is disabled by default. Use log_slow_slave_statements instead for MySQL versions 8.0.26 and earlier.
  • log_queries_not_using_indexes = 1 – When this setting is enabled, queries that are supposed to retrieve all records from the target table or view will be logged, even if they have not excluded the slow query threshold. This can help identify when a query is missing an index or unable to use it. Queries that have an available index will still be logged if they lack constraints that limit the number of rows fetched.

Logging queries that don’t use indexes can increase verbosity significantly. There may be situations where a full index scan is expected or necessary. These queries will continue to appear in the log even if they cannot be resolved.

You can evaluate limit queries without indexes by setting the parameter log_throttle_queries_not_using_indexes variable. This sets the maximum number of logs that will be written in a 60 second period. A value of 10 means that up to 10 queries will be logged per minute. After the tenth event, no more queries will be logged until the next 60-second window opens.

Interpreting the Slow Query Log

Each query entering the slow query log will show a set of lines similar to the following:

# Time: 2022-07-12T19:00:00.000000Z
# [email protected]: 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 time it ran, the MySQL user the client connected with, and statistics providing the duration and number of rows sent. The example above took 3.5 seconds and examined over 320,000 rows, before sending only 5,143 to the client. This could be an indication that missing indexes cause MySQL to inspect too many records.

You can optionally include more information in the log by setting the parameter log_slow_extra = 1 system variable in your configuration file. This will add the thread ID, number of bytes received and sent, and number of rows considered for sorting, as well as the number of statement-specific queries that provide visibility into how MySQL processed the query .

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

Query logging and slow backups

A common frustration with the slow query log occurs when you also use MySQLDump to create database backups. Long term SELECT * FROM ... queries will be executed to retrieve data from your tables and feed it into your backup. They will be included in the slow query log like any other SQL statement. This can pollute the log if you make backups regularly.

You can fix this problem by temporarily disabling the slow query log before running mysqldump. You can re-enable the journal after the backup is complete. Adjust your backup script to look like 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 keep MySQLDump activity out of the slow query log, making it easier for you to focus on the SQL your application runs.

Summary

The MySQL Slow Query Log is one of the most effective ways to identify the cause of performance issues. Start by estimating the delay you are experiencing and use this value as your long_query_time. Reduce the value if nothing appears in the log after reproducing the issue.

The slow query log won’t tell you exactly how to fix the slowdown. However, the ability to view the exact SQL received by the server allows you to repeat poorly performing statements and then evaluate the effect of optimizations. Adding a missing index or constraint can be the difference between a query that hits thousands of rows and one that works with a handful.


Source link