MySQL slow query log logging all queries

Question

We have a MySQL 5.1.52 Percona Server 11.6 instance that suddenly started logging every single query to the slow query log. The long_query_time configuration is set to 1, yet, suddenly we're seeing every single query (e.g. just saw one that took 0.000563s!). As a result, our log files are growing at an insane pace. We just had to truncate a 180G slow query log file.

I tried setting the long_query_time variable to a really large number to see if it stopped altogether (1000000), but same result.

show global variables like 'general_log%';
+------------------+--------------------------+
| Variable_name    | Value                    |
+------------------+--------------------------+
| general_log      | OFF                      |
| general_log_file | /usr2/mysql/data/db4.log |
+------------------+--------------------------+
2 rows in set (0.00 sec)

show global variables like 'slow_query_log%';
+---------------------------------------+-------------------------------+
| Variable_name                         | Value                         |
+---------------------------------------+-------------------------------+
| slow_query_log                        | ON                            |
| slow_query_log_file                   | /usr2/mysql/data/db4-slow.log |
| slow_query_log_microseconds_timestamp | OFF                           |
+---------------------------------------+-------------------------------+
3 rows in set (0.00 sec)

show global variables like 'long%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)

Solution

It sounds like log_queries_not_using_indexes is enabled.

Check it by doing:

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

Turn it off with:

mysql> set global log_queries_not_using_indexes = 'off';
Query OK, 0 rows affected (0.00 sec)

Comments

[Blanka]

That's it, thank you! setting the variable to off did it.

[Greg Petersen]

I recommend you turn it on and use EXPLAIN to find out why the query doesn't use index.

[Savage Garden]

In my case it is OFF, but slow query log still records 1+ sec queries. Interval is correctly configured as 10

[Anse]

Exactly what happened to me. Looks a bit inconsistent to me. Probably these non-indexed queries should get their own log file, plus their own non_indexed_queries_log_file variable probably.