Why does mysql slow log reports these non-slow queries

Question

My mysql server has long_query_time = 2 configured but I still see these queries reported in slow query log that seem fast:

# Time: 120730  5:06:41
# User@Host: <user> @ <Host> [<IP>] 
# Query_time: 0.000412  Lock_time: 0.000060 Rows_sent: 5  Rows_examined: 5
SET timestamp=1343639201;
SELECT album_id FROM `TB_albums` where album_id!='res_4fe4333271bda7.42833845' and deleted is NULL order by `created_time` desc limit 5;

As you can see Query_time: 0.000412 Lock_time: 0.000060 seems way below 2 seconds

Do you have any Idea why these "fast" queries are reported?

Answer 1

MySQL also logs queries which do not use an index

The option log-queries-not-using-indexes in my.cnf is used to control this. Mine is turned off (by commenting out) as you can see from this snippet of my.cnf

# Here you can see queries with especially long duration
log_slow_queries        = /var/log/mysql/mysql-slow.log
long_query_time = 2
#log-queries-not-using-indexes

If you don't have access to the my.cnf, you can check using SQL

mysql> show variables like 'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF   |
+-------------------------------+-------+
1 row in set (0.00 sec)

Hope that helps!

Chris