MySQL's "slow query" log: strange "Query_time"

Question

I need some help understanding what's going on with my "slow query" log in MySQL. I have set

 set global long_query_time=3

and yet this is what I see in the slow query log:

# Time: 120723  9:04:38
# User@Host: root[root] @  [111.111.111.205]
# Query_time: 0.017508  Lock_time: 0.000111 Rows_sent: 2884  Rows_examined: 9132
SET timestamp=1343027078;
SELECT [...]
# User@Host: root[root] @  [111.111.111.202]
# Query_time: 0.030282  Lock_time: 0.000102 Rows_sent: 0  Rows_examined: 12323
SET timestamp=1343027078;
SELECT [...]
# Time: 120723  9:04:41
# User@Host: root[root] @  [111.111.111.202]
# Query_time: 0.004416  Lock_time: 0.000104 Rows_sent: 18  Rows_examined: 6266
SET timestamp=1343027081;
SELECT [...]
# User@Host: root[root] @ hostname [111.111.111.199]
# Query_time: 0.029399  Lock_time: 0.000116 Rows_sent: 0  Rows_examined: 12323
SET timestamp=1343027088;
SELECT [...]
# Time: 120723  9:04:53
# User@Host: root[root] @  [111.111.111.201]
# Query_time: 0.004470  Lock_time: 0.000080 Rows_sent: 0  Rows_examined: 6248
SET timestamp=1343027093;
SELECT [...]
# Time: 120723  9:04:55
# User@Host: root[root] @  [111.111.111.198]
# Query_time: 0.042627  Lock_time: 0.000087 Rows_sent: 0  Rows_examined: 0
use [...];
SET timestamp=1343027095;
UPDATE [...]
# User@Host: root[root] @  [111.111.111.198]
# Query_time: 0.029115  Lock_time: 0.000124 Rows_sent: 0  Rows_examined: 0

where the time in Query_time is significantly lower than my prevously specified 3 seconds. Why's that? Where is the missing time?

MySQL 5.1.41, Ubuntu 10.04

Answer 1

Ah, I should have checked that first:

log_queries_not_using_indexes has been turned on, so a whole number of queries has been logged because they were not using indexes.

Apparently, a query "not using indexes" is not marked in any way in the slow query log, so one has to guess whether an entry has been logged because of an execution time exceeding the long_query_time threshold or because of indexes.