11

I'm having an issue where MySQL seems to be logging queries in the slow query log that are faster than the time specified. I've configured MySQL to log the following:

Server version: 5.1.54-1ubuntu4-log

+---------------------+-------------------------------+
| Variable_name       | Value                         |
+---------------------+-------------------------------+
| log_slow_queries    | ON                            |
| long_query_time     | 2.000000                      |
| slow_query_log      | ON                            |
| slow_query_log_file | /var/log/mysql/mysql-slow.log |
+---------------------+-------------------------------+
4 rows in set (0.00 sec)

However, in my slow query log I can see that it's logging sub-second queries:

# Time: 121116 17:09:00
# User@Host: user[user] @ ip-10-x-x-x.ec2.internal [x.x.x.x]
# Query_time: 0.007098  Lock_time: 0.000075 Rows_sent: 50  Rows_examined: 2693

I've set the above variable dynamically using 'SET GLOBAL ...', but even before that the long_query_time was set to 1.000000 seconds.

Any idea why MySQL could be logging queries that are faster then what is specified?

wrangler
  • 1,995
  • 2
  • 19
  • 22
  • 3
    Have you specified `log_queries_not_using_indexes` by any chance? – Ja͢ck Nov 16 '12 at 17:20
  • Yes! That was it. Thanks for the quick response. If you want to submit an official answer, I'll select it as accepted. Thanks again! – wrangler Nov 16 '12 at 17:22

1 Answers1

31

According to the documentation, there's another option that could cause queries to get logged in the slow query log:

log_queries_not_using_indexes

Ja͢ck
  • 170,779
  • 38
  • 263
  • 309