From: spameden
Date: October 15 2012 8:41pm
Subject: mysql logs query with indexes used to the slow-log and not logging if
 there is index in reverse order
List-Archive: http://lists.mysql.com/mysql/228395
Message-Id: <CAHCALexfVp=yYY3wBZjsyRSJQmzXogxp5REn3OzbQezvab48aA@mail.gmail.com>
MIME-Version: 1.0
Content-Type: multipart/alternative; boundary=047d7b2e4e34c0f15804cc1f1051

--047d7b2e4e34c0f15804cc1f1051
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

Hi, list.

Sorry for the long subject, but I'm really interested in solving this and
need a help:

I've got a table:

mysql> show create table send_sms_test;
+---------------+----------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
------------------------------+
| Table         | Create
Table
|
+---------------+----------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
------------------------------+
| send_sms_test | CREATE TABLE `send_sms_test` (
  `sql_id` bigint(20) NOT NULL AUTO_INCREMENT,
  `momt` enum('MO','MT') DEFAULT NULL,
  `sender` varchar(20) DEFAULT NULL,
  `receiver` varchar(20) DEFAULT NULL,
  `udhdata` blob,
  `msgdata` text,
  `time` bigint(20) NOT NULL,
  `smsc_id` varchar(255) DEFAULT 'main',
  `service` varchar(255) DEFAULT NULL,
  `account` varchar(255) DEFAULT NULL,
  `id` bigint(20) DEFAULT NULL,
  `sms_type` tinyint(1) DEFAULT '2',
  `mclass` bigint(20) DEFAULT NULL,
  `mwi` bigint(20) DEFAULT NULL,
  `coding` bigint(20) DEFAULT NULL,
  `compress` bigint(20) DEFAULT NULL,
  `validity` bigint(20) DEFAULT NULL,
  `deferred` bigint(20) DEFAULT NULL,
  `dlr_mask` bigint(20) DEFAULT NULL,
  `dlr_url` varchar(255) DEFAULT NULL,
  `pid` bigint(20) DEFAULT NULL,
  `alt_dcs` bigint(20) DEFAULT NULL,
  `rpi` bigint(20) DEFAULT NULL,
  `charset` varchar(255) DEFAULT NULL,
  `boxc_id` varchar(255) DEFAULT NULL,
  `binfo` varchar(255) DEFAULT NULL,
  `meta_data` text,
  `task_id` bigint(20) DEFAULT NULL,
  `msgid` bigint(20) DEFAULT NULL,
  `priority` int(3) unsigned NOT NULL DEFAULT '500',
  PRIMARY KEY (`sql_id`),
  KEY `task_id` (`task_id`),
  KEY `receiver` (`receiver`),
  KEY `msgid` (`msgid`),
  KEY `priority_time` (`priority`,`time`)
) ENGINE=3DInnoDB AUTO_INCREMENT=3D7806318 DEFAULT CHARSET=3Dutf8

Slow-queries turned on with an option:
| log_queries_not_using_indexes | ON    |

mysqld --version
mysqld  Ver 5.1.65-rel14.0 for debian-linux-gnu on x86_64 ((Percona Server
(GPL), 14.0, Revision 475))

If I check with EXPLAIN MySQL says it would use the index:
mysql> *desc select * from send_sms_test where time<=3DUNIX_TIMESTAMP(NOW()=
)
order by priority limit 0,11;*
+----+-------------+---------------+-------+---------------+---------------=
+---------+------+------+-------------+
| id | select_type | table         | type  | possible_keys | key
| key_len | ref  | rows | Extra       |
+----+-------------+---------------+-------+---------------+---------------=
+---------+------+------+-------------+
|  1 | SIMPLE      | send_sms_test | index | NULL          | priority_time
| 12      | NULL |  * 11* | Using where |
+----+-------------+---------------+-------+---------------+---------------=
+---------+------+------+-------------+
1 row in set (0.00 sec)

But If I issue the query I see in the mysql-slow.log:
select * from send_sms_test where time<=3DUNIX_TIMESTAMP(NOW()) order by
priority limit 0,11;

If I do create INDEX time,priority (in reverse order instead of
priority,time) I get still the same usage of priority_time key with the
same length, but rows now are doubled):
mysql> *create index time_priority ON send_sms_test (time,priority);*
Query OK, 0 rows affected (0.67 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> *desc select * from send_sms_test where time<=3DUNIX_TIMESTAMP(NOW()=
)
order by priority limit 0,11;*
+----+-------------+---------------+-------+---------------+---------------=
+---------+------+------+-------------+
| id | select_type | table         | type  | possible_keys | key
| key_len | ref  | rows | Extra       |
+----+-------------+---------------+-------+---------------+---------------=
+---------+------+------+-------------+
|  1 | SIMPLE      | send_sms_test | index | time_priority | priority_time
| 12      | NULL |   *22* | Using where |
+----+-------------+---------------+-------+---------------+---------------=
+---------+------+------+-------------+

And if both indexes created I do not have anymore this query in the
slow-log.

Of course If I disable log_queries_not_using_indexes I get none of the
queries.

So is it a bug inside Percona's implementation or it's generally MySQL
behavior?

Thanks

--047d7b2e4e34c0f15804cc1f1051--