Capture Slow Queries

MySQL Tutorials - Herong's Tutorial Examples

∟Capture Slow Queries

This section provides a tutorial example on setup MySQL server to capture slow queries based on given conditions on execution time and number of rows examined.

If users are reporting slow response time from your MySQL server, you may follow this tutorial to capture some slow queries and analyze them.

1. Turn on "slow_query_log" flag.

mysql> set global slow_query_log = ON;

mysql> select @@slow_query_log;
+------------------+
| @@slow_query_log |
+------------------+
|                1 |
+------------------+

mysql> show variables like 'slow_query_log';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| slow_query_log | ON    |
+----------------+-------+

2. Change 'long_query_time' to adjust the logging criteria on execution time. The following command sets it to 10 seconds in the global scope.

mysql> set global long_query_time = 1000;

mysql> show global variables like 'long_query_time';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 1000.0000 |
+-----------------+-----------+

3. Change 'min_examined_row_limit' to adjust the logging criteria on number of rows examined.

mysql> set global min_examined_row_limit = 100000;

mysql> show global variables like 'min_examined_row_limit';
+------------------------+--------+
| Variable_name          | Value  |
+------------------------+--------+
| min_examined_row_limit | 100000 |
+------------------------+--------+

4. Turn on 'log_queries_not_using_indexes' to log queries that do full table or index scans.

mysql> set global log_queries_not_using_indexes = ON;

mysql> show global variables like 'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | ON    |
+-------------------------------+-------+

5. Change 'log_throttle_queries_not_using_indexes' to adjust logging criteria on the number of not_using_indexes queries per minute.

mysql> set global log_throttle_queries_not_using_indexes = 5;

mysql> show global variables like 'log_throttle_queries_not_using_indexes';
+----------------------------------------+-------+
| Variable_name                          | Value |
+----------------------------------------+-------+
| log_throttle_queries_not_using_indexes | 5     |
+----------------------------------------+-------+

6. Understand how slow query logging criteria are applied. According to MySQL documentation, a query is logged, if it meets one of conditions listed below:

The query must either not be an administrative statement, or log_slow_admin_statements must be enabled.
The query must have taken at least long_query_time seconds, or log_queries_not_using_indexes must be enabled and the query used no indexes for row lookups.
The query must have examined at least min_examined_row_limit rows.
The query must not be suppressed according to the log_throttle_queries_not_using_indexes setting.

7. Disconnect and reconnect to the MySQL server. Then run some slow queries.

8. Check to see how many slow queries are logged so far at the system (global) level:

mysql> show global status like 'slow_queries';

+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 55    |
+---------------+-------+

9. Find out where the slow query log file is located.

mysql> show variables like 'slow_query_log_file';
+---------------------+------------------------------------+
| Variable_name       | Value                              |
+---------------------+------------------------------------+
| slow_query_log_file | /usr/lib/mysql/localhost-slow.log  |
+---------------------+------------------------------------+

10. Take a peek at the log file:

herong$ sudo head -20 /usr/lib/mysql/localhost-slow.log

/usr/libexec/mysqld, Version: 8.0.21 (Source distribution). started with:
Tcp port: 3306  Unix socket: /usr/lib/mysql/mysql.sock
Time                 Id Command    Argument

# Time: 2021-11-04T08:23:20.632423Z
# User@Host: herong[herong] @ localhost [127.0.0.1]  Id:  1753
# Query_time: 0.817586  Lock_time: 0.000043 Rows_sent: 0  Rows_examined: 1301718
SET timestamp=1636014199;
SELECT ID FROM Products WHERE Name LIKE ...

# Time: 2021-11-04T08:23:36.279800Z
# User@Host: herong[herong] @ localhost [127.0.0.1]  Id:  1753
# Query_time: 0.389617  Lock_time: 0.000046 Rows_sent: 1  Rows_examined: 1301720
SET timestamp=1636014215;
SELECT ID FROM Products WHERE Name LIKE ...

...