1

I'm trying to understand a slow query. The SELECT has been running (at this moment) for almost 18000 seconds (output from a SELECT on PROCESSLIST):

           id: 22
         time: 17870
        state: Sending data
left(info,20): SELECT data.object,

It's spent all that time (as far as I can tell) in Sending data state.

What should I be looking at in the EXPLAIN to tell me about what this query is doing?

Here's the table itself; at last count there are approximately 87 million rows.

CREATE TABLE `node` (
  `id` bigint(20) NOT NULL AUTO_INCREMENT,
  `graph` varchar(100) CHARACTER SET latin1 DEFAULT NULL,
  `subject` varchar(200) NOT NULL,
  `predicate` varchar(200) NOT NULL,
  `object` mediumtext NOT NULL,
  PRIMARY KEY (`id`),
  UNIQUE KEY `nodeindex` (`graph`(20),`subject`(100),`predicate`(100),`object`(100)),
  KEY `ix_node_subject` (`subject`),
  KEY `ix_node_graph` (`graph`),
  KEY `ix_node_object` (`object`(255)),
  KEY `ix_node_predicate` (`predicate`),
  KEY `node_po` (`predicate`,`object`(130)),
  KEY `node_so` (`subject`,`object`(130)),
  KEY `node_sp` (`subject`,`predicate`(130)),
  FULLTEXT KEY `node_search` (`object`)
) ENGINE=MyISAM AUTO_INCREMENT=473374387 DEFAULT CHARSET=utf8

Here's a slightly sanitized version of the query

SELECT data.object, profile.object, profile_name.object, profile_email.object, profile_url.object, profile_username.object
FROM node AS source
JOIN node AS profile ON (source.object = profile.subject)
LEFT JOIN node AS data ON (profile.object = data.subject)
LEFT JOIN node AS profile_name ON (source.object = profile_name.subject AND profile_name.predicate = "name")
LEFT JOIN node AS profile_email ON (source.object = profile_email.subject AND profile_email.predicate = "email")
LEFT JOIN node AS profile_url ON (source.object = profile_url.subject AND profile_url.predicate = "public_url")
LEFT JOIN node AS profile_username ON (source.object = profile_username.subject AND profile_username.predicate = "username")
WHERE source.subject IN ('141819225850615', '150915932479', '178191330369', '191338370463', 
    '589223984441662', '102140504', '103344560', '103565169', '104222894', 
    '106144676', '106946824', '10818722', '108248748', '108979621', 
       ... 50 lines deleted 
    '83569262', '85273841', '85358898', '87037156', '87287360', 
    '88146181', '890372000', '89261234', '89517005', '89784593', 
    '90492894', '90718122', '91220992', '943151972', '943946328', 
    '9460682', '9461422', '94616097', '94633116', '95524371', 
    '95699292', '960546007', '96565646', '97054674', '97196051', 
    '98339494', '99746916') AND
source.predicate IN ("string1", "string2", "string3", "string4") AND
profile.predicate NOT IN ("string1", "string2", "string3", "string4") AND
((MATCH(profile.object) AGAINST("'string6'") 
    OR MATCH(data.object) AGAINST("'string6'")) 
OR (MATCH(profile.object) AGAINST("'string7'") OR MATCH(data.object) AGAINST("'string7'")))

And here's the output of explain extended:

*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: source
         type: range
possible_keys: ix_node_subject,ix_node_object,ix_node_predicate,node_po,node_so,node_sp,node_search
          key: node_sp
      key_len: 994
          ref: NULL
         rows: 878644
     filtered: 100.00
        Extra: Using where
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: profile
         type: ref
possible_keys: ix_node_subject,ix_node_predicate,node_po,node_so,node_sp
          key: ix_node_subject
      key_len: 602
          ref: sumazi_prdf.source.object
         rows: 11
     filtered: 100.00
        Extra: Using where
*************************** 3. row ***************************
           id: 1
  select_type: SIMPLE
        table: data
         type: ref
possible_keys: ix_node_subject,node_so,node_sp
          key: ix_node_subject
      key_len: 602
          ref: sumazi_prdf.profile.object
         rows: 11
     filtered: 100.00
        Extra: Using where
*************************** 4. row ***************************
           id: 1
  select_type: SIMPLE
        table: profile_name
         type: ref
possible_keys: ix_node_subject,ix_node_predicate,node_po,node_so,node_sp
          key: node_sp
      key_len: 994
          ref: sumazi_prdf.source.object,const
         rows: 1
     filtered: 100.00
        Extra: 
*************************** 5. row ***************************
           id: 1
  select_type: SIMPLE
        table: profile_email
         type: ref
possible_keys: ix_node_subject,ix_node_predicate,node_po,node_so,node_sp
          key: node_sp
      key_len: 994
          ref: sumazi_prdf.source.object,const
         rows: 1
     filtered: 100.00
        Extra: 
*************************** 6. row ***************************
           id: 1
  select_type: SIMPLE
        table: profile_url
         type: ref
possible_keys: ix_node_subject,ix_node_predicate,node_po,node_so,node_sp
          key: node_sp
      key_len: 994
          ref: sumazi_prdf.source.object,const
         rows: 1
     filtered: 100.00
        Extra: 
*************************** 7. row ***************************
           id: 1
  select_type: SIMPLE
        table: profile_username
         type: ref
possible_keys: ix_node_subject,ix_node_predicate,node_po,node_so,node_sp
          key: node_sp
      key_len: 994
          ref: sumazi_prdf.source.object,const
         rows: 1
     filtered: 100.00
        Extra: 
7 rows in set, 1 warning (1.34 sec)

1 Answer 1

1

sending data in SHOW FULL PROCESSLIST output most likely indicates bad indexing or unused indexes and also the using where in the column extra in the explain output is indicating this.

It looks like lots off random disk I/O lookup needs to be done on your MYD an MYI files based on your range scan type: ref in the explain output can indicate this.

Can you provide the outputs off the queries below> and can you so also provide basis information about your hard disk like make and model and also an MysQL version number?

SET PROFILING = 1;

SELECT data.object, profile.object, profile_name.object, profile_email.object, profile_url.object, profile_username.object
FROM node AS source
JOIN node AS profile ON (source.object = profile.subject)
LEFT JOIN node AS data ON (profile.object = data.subject)
LEFT JOIN node AS profile_name ON (source.object = profile_name.subject AND profile_name.predicate = "name")
LEFT JOIN node AS profile_email ON (source.object = profile_email.subject AND profile_email.predicate = "email")
LEFT JOIN node AS profile_url ON (source.object = profile_url.subject AND profile_url.predicate = "public_url")
LEFT JOIN node AS profile_username ON (source.object = profile_username.subject AND profile_username.predicate = "username")
WHERE source.subject IN ('141819225850615', '150915932479', '178191330369', '191338370463', 
    '589223984441662', '102140504', '103344560', '103565169', '104222894', 
    '106144676', '106946824', '10818722', '108248748', '108979621', 
       ... 50 lines deleted 
    '83569262', '85273841', '85358898', '87037156', '87287360', 
    '88146181', '890372000', '89261234', '89517005', '89784593', 
    '90492894', '90718122', '91220992', '943151972', '943946328', 
    '9460682', '9461422', '94616097', '94633116', '95524371', 
    '95699292', '960546007', '96565646', '97054674', '97196051', 
    '98339494', '99746916') AND
source.predicate IN ("string1", "string2", "string3", "string4") AND
profile.predicate NOT IN ("string1", "string2", "string3", "string4") AND
((MATCH(profile.object) AGAINST("'string6'") 
    OR MATCH(data.object) AGAINST("'string6'")) 
OR (MATCH(profile.object) AGAINST("'string7'") OR MATCH(data.object) AGAINST("'string7'")))

SHOW PROFILES; 

SHOW PROFILE ALL FOR QUERY [query_id from show profile your select query]

Note: I also see an object mediumtext NOT NULL in your create table statement! Are you known with the fact MySQL is always is creating an MyISAM disk based temporary table if an TEXT data type is used within the query this is because memory engine cant store TEXT data types

3
  • Thanks for the reply. Yes, I'm aware of that; this is a database put together on the simplest-thang-that-could-work basis that I inherited, I'm trying to work through making it work with 100 million rows. I'll get the process query output for you. It's mysql 5.1.62 btw. Dec 11, 2013 at 21:06
  • @Charlie Martin i hope the query is not running all this time?? Dec 28, 2013 at 19:55
  • ROFL No I stopped it. :-) Actually it never completed in a reasonable time (like days). I've done some further profiling and it's clear the text table is eating my lunch -- I think it's actually copying the table multiple times. Dec 28, 2013 at 21:05

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.