Slow query log logs queries that are fast during testing

Question

My slow query log is full of queries with following query time and rows examined:

# Query_time: 26.370100  Lock_time: 0.000213  Rows_sent: 0  Rows_examined: 30976475

If I copy and paste the exact query from the log into phpmyadmin and run it, result comes instantly, even trying EXPLAIN upon that query reveals no flaws in indexes or bad structure.

As far as I can tell, for some reason a small fraction of queries fail to use indexes and trying to reproduce that event is next to impossible during testing.

How should I prevent these occasional slow queries which in vast majority of cases work as intended?

--- EDIT #1 ---

My create tables are:

CREATE TABLE msgs (
  id bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  sender text NOT NULL,
  receiver text NOT NULL,
  cont blob NOT NULL,
  img text NOT NULL,
  orient text NOT NULL,
  d_t datetime NOT NULL,
  convo text NOT NULL,
  u_code text NOT NULL,
  viewed datetime NOT NULL,
  stat int(11) NOT NULL,
  device text NOT NULL,
  addr text NOT NULL,
  PRIMARY KEY (id),
  KEY msg_u_code (`u_code`(24)),
  KEY receiver (`receiver`(24)),
  KEY sender (`sender`(24)),
  KEY img (`img`(28)),
  KEY convo (`convo`(49))
) ENGINE=InnoDB  DEFAULT CHARSET=utf8;

CREATE TABLE usrs (
  id bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  usr_name text NOT NULL,
  img text NOT NULL,
  orient text NOT NULL,
  `password` text NOT NULL,
  u_code text NOT NULL,
  d_t datetime NOT NULL,
  stat int(11) NOT NULL,
  device text NOT NULL,
  addr text NOT NULL,
  PRIMARY KEY (id),
  KEY img (`img`(28)),
  KEY usr_code (`u_code`(24))
) ENGINE=InnoDB  DEFAULT CHARSET=utf8;

And my slow query log entry is:

 # Time: 171115  6:26:37
 # User@Host: xxx[xxx] @ localhost []
 # Thread_id: 25524888  Schema: xxx  QC_hit: No
 # Query_time: 32.423430  Lock_time: 0.000425  Rows_sent: 1  Rows_examined: 30998008
 # Rows_affected: 0
 use xxx;
 SET timestamp=1510723597;
 select msg_cont, msg_u_code, msg_d_t, msg_viewed, usr_u_code, usr_name from
        (select
            msgs.id as msg_id,
            msgs.cont as msg_cont,
            msgs.u_code as msg_u_code,
            msgs.d_t as msg_d_t,
            msgs.viewed as msg_viewed,
            usrs.u_code as usr_u_code,
            usrs.usr_name as usr_name
            from msgs
            left join usrs on msgs.sender = usrs.u_code
    where  msgs.convo = 'aaaaaaaaaabfbaghdgcigfid_aaaaaaaaaabeiaccjfhjfach'
      and  (msgs.sender = 'aaaaaaaaaabfbaghdgcigfid'
              or  msgs.receiver = 'aaaaaaaaaabfbaghdgcigfid'
           )
      and  msgs.stat = '1'
      and  usrs.stat = '1'
      and  usrs.u_code not in('aaaaaaaaaabfaagfbgggiejh',
                              'aaaaaaaaaabfabgbjdfjigbd',
                ...... !!!!![here go 400 more usr_u_codes]!!!!!
                          )
      and  msgs.id > 30997997
        ) a order by msg_id asc;

Caution, this query shall contain on average 400 elements in the not in function.

--- EDIT #2 ---

Answer 1

While I am unable to explain why MySQL occasionally decided not to use index on a very obvious and very common query, the solution was to simply force the index.

In my particular case:

select msg_cont, msg_u_code, msg_d_t, msg_viewed, usr_u_code, usr_name from
        (select
            msgs.id as msg_id,
            msgs.cont as msg_cont,
            msgs.u_code as msg_u_code,
            msgs.d_t as msg_d_t,
            msgs.viewed as msg_viewed,
            usrs.u_code as usr_u_code,
            usrs.usr_name as usr_name
            from msgs FORCE INDEX (convo)
            left join usrs FORCE INDEX (u_code) on msgs.sender = usrs.u_code
    where  msgs.convo = 'aaaaaaaaaabfbaghdgcigfid_aaaaaaaaaabeiaccjfhjfach'
      and  (msgs.sender = 'aaaaaaaaaabfbaghdgcigfid'
              or  msgs.receiver = 'aaaaaaaaaabfbaghdgcigfid'
           )
      and  msgs.stat = '1'
      and  usrs.stat = '1'
      and  usrs.u_code not in('aaaaaaaaaabfaagfbgggiejh',
                              'aaaaaaaaaabfabgbjdfjigbd',
                ...... !!!!![here go 400 more usr_u_codes]!!!!!
                          )
      and  msgs.id > 30997997
        ) a order by msg_id asc;

Slow query log proved this solution to be effective as no new slow entries emerge.

Answer 2

You probably have the "Query cache" turned on. It captures queries and their resultsets. When you run exactly the same query again, it simply echos the saved resultset, instead of re-evaluating it.

The QC can be avoided by adding as little as a single space in the statement, or by saying SELECT SQL_NO_CACHE ....

To further discuss why the query needs to look at 31M rows, let's see the query and SHOW CREATE TABLE.

After seing query

I want to start by focusing on ON msgs.sender = usrs.u_code and the "prefix" indexes.

Based on the sample values, it seems that sender, u_code and several other columns might always be under some small length? If this is true, then

• Change from TEXT to VARCHAR(nn) where nn is some realistic limit;
• Get rid of the prefixing (eg: KEY sender (sender(24)) --> KEY (sender).

These changes should make the JOIN much more efficient, thereby improving performance. If that is not adequate, come back for more advice.