MySQL "Sending data" horribly slow

Question

I have a modest-sized table, 277k records at the moment, which I am trying to do a FULLTEXT search on. The search seems to be very quick until it gets to the Sending data phase.

The Table:

CREATE TABLE `sqinquiries_inquiry` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `ts` datetime NOT NULL,
  `names` longtext NOT NULL,
  `emails` longtext NOT NULL,
  PRIMARY KEY (`id`),
  FULLTEXT KEY `sqinquiries_inquiry_search` (`names`,`emails`)
) ENGINE=MyISAM AUTO_INCREMENT=305560 DEFAULT CHARSET=latin1

The Query:

SELECT * FROM `sqinquiries_inquiry` WHERE (
  MATCH (`sqinquiries_inquiry`.`names`) AGAINST ('smith' IN BOOLEAN MODE) OR
  MATCH (`sqinquiries_inquiry`.`emails`) AGAINST ('smith' IN BOOLEAN MODE)
) ORDER BY `sqinquiries_inquiry`.`id` DESC LIMIT 100

The Profile: (I snipped out seemingly useless info)

+-------------------------+----------+
| Status                  | Duration |
+-------------------------+----------+
| preparing               | 0.000014 | 
| FULLTEXT initialization | 0.000015 | 
| executing               | 0.000004 | 
| Sorting result          | 0.000008 | 
| Sending data            | 2.247934 | 
| end                     | 0.000011 | 
| query end               | 0.000003 | 
+-------------------------+----------+

The DESCRIBE looks great, a simple one liner: The Describe:

id: 1
select_type: SIMPLE
table: sqinquiries_inquiry
type: index
possible_keys: NULL
key: PRIMARY
key_len: 4 
ref: NULL
rows: 100
Extra: Using where

So what I don't understand is where the 2.25 seconds of Sending data is coming from? I'm seeing similar performance in Python and in the console mysql app, both connecting to localhost.

Updates:

• Per comment requesting the average row size, it is: 53.8485
• Per comment, here is the DESCRIBE above.

Answer 1

The DESCRIBE looks great, a simple one liner.

Since you are using only one table in your query it cannot be anything other than a one-liner.

However, your query does not use the FULLTEXT index.

For the index to be usable, you should rewrite the query a little:

SELECT  *
FROM    sqinquiries_inquiry
WHERE   MATCH (names, emails) AGAINST ('smith' IN BOOLEAN MODE)
ORDER BY
        id DESC
LIMIT 100

MATCH only uses the index if the you match against the exact set of columns the index is defined on.

So your query uses the index scan on id: Using index; Using where at the very end of your DESCRIBE.

Sending data is quite misleading: this is actually time elapsed between the end of the previous operation and the end of the current operation.

For instance, I just ran this query:

SET profiling = 1;

SELECT  *
FROM    t_source
WHERE   id + 1 = 999999;

SHOW PROFILE FOR QUERY 39;

which returned a single row and this profile:

'starting', 0.000106
'Opening tables', 0.000017
'System lock', 0.000005
'Table lock', 0.000014
'init', 0.000033
'optimizing', 0.000009
'statistics', 0.000013
'preparing', 0.000010
'executing', 0.000003
'Sending data', 0.126565
'end', 0.000007
'query end', 0.000004
'freeing items', 0.000053
'logging slow query', 0.000002
'cleaning up', 0.000005

Since the index is not usable, MySQL needs to perform the full table scan.

0.126565 seconds are the time from the beginning of the execution (the time the first row was read) and the end on the execution (the time the last row was sent to the client).

This last row is at the very end of the table and it took a long time to find and send it.

P. S. Edited to remove the downvote :)