log-queries-not-using-indexes logs results using index

I’m having a weird problem where one of my queries that’s using an index gets logged when the “log-queries-not-using-indexes” option is used in my.ini.

The query:

mysql> explain select data.img_url from data,popular where data.model_no= popular.model_no order by popular.popularity desc,popular.y_popularity desc limit 80;±—±------------±--------±------±--------------±----------±--------±-------------------------------±------±------------+| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |±—±------------±--------±------±--------------±----------±--------±-------------------------------±------±------------+| 1 | SIMPLE | popular | index | PRIMARY,icode | iboth | 10 | NULL | 12139 | Using index || 1 | SIMPLE | data | ref | imodel_no | imodel_no | 130 | odata.popular.model_no | 1 | |±—±------------±--------±------±--------------±----------±--------±-------------------------------±------±------------+2 rows in set

In the log:

Query_time: 0 Lock_time: 0 Rows_sent: 80 Rows_examined: 160select data.img_url from data,popular where data.model_no= popular.model_no order by popular.popularity desc,popular.y_popularity desc limit 80;

Also, what’s weird is under EXPLAIN is states PRIMARY,icode as possible keys, but uses iboth (iboth is a normal index on popularity,y_popularity)

I am using MYSQL 5.0.45

Any ideas what’s going on here?

[B]Quote:[/B]

(iboth is a normal index on popularity,y_popularity)

that's impossible, it must contain popular.model_no also for this explain output to appear. And that's where the order is important: popularity,y_popularity should be a prefix for this query.

These are the indexes on popular:

mysql> show indexes from popular;±--------±-----------±---------±-------------±-------------±----------±------------±---------±-------±-----±-----------±--------+| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment |±--------±-----------±---------±-------------±-------------±----------±------------±---------±-------±-----±-----------±--------+| popular | 0 | PRIMARY | 1 | model_no | A | 14583 | NULL | NULL | | BTREE | || popular | 1 | icode | 1 | model_no | A | 14583 | NULL | NULL | | BTREE | || popular | 1 | ipop | 1 | popularity | A | 1 | NULL | NULL | YES | BTREE | || popular | 1 | iypop | 1 | y_popularity | A | 441 | NULL | NULL | YES | BTREE | || popular | 1 | iboth | 1 | popularity | A | 123 | NULL | NULL | YES | BTREE | || popular | 1 | iboth | 2 | y_popularity | A | 1041 | NULL | NULL | YES | BTREE | |±--------±-----------±---------±-------------±-------------±----------±------------±---------±-------±-----±-----------±--------+6 rows in set

When you enable log-queries-not-using-indexes, MySQL logs queries that do not use an index to restrict the result set, which is the case here. The “Using Index” in your explain results just means that the table in question (popularity) is not being read at all, and instead everything that is needed from it (model_no, popularity, y_popularity) is in in the index and may be retrieved with an index scan. For this explain to make sense given your indexes, you must be using InnoDB, since all secondary indexes must also contain the primary key. That’s why the iboth index can be used to satisfy the popularity table’s role in this query.

Thanks for your replies

vgatto - I am guessing that this is the fastest solution as popular is not read at all? (even though an index is not being used to refine the results?)

gmouse - thanks for highlighting the redundant indexes, I’ve removed these now

I have these additional comments:

This option actually logs queries that don’t use any index, and queries that don’t use a “good” index. Also, it’s quite possible for MySQL to use a different query plan at the time of execution than the one you see later with EXPLAIN. Just some things to keep in mind.

Are you saying the query is inefficient, that’s why it’s coming up in the log?

What he is saying, is that the EXPLAIN output might not show the actual execution plan. The only way you can be sure, is by looking at the “Rows_sent: 80 Rows_examined: 160” part.