Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

I have a query that took 98 seconds to execute this morning, but I can't recreate the problem now, and the EXPLAIN output isn't giving me any clues. Am I missing something?

Here's the SQL:

SELECT `a`.`name`        AS `ap_name`, 
       AVG(`s3`.`value`) AS `sas_value` 
FROM   `student` `s` 
       LEFT JOIN `student_assessment` `s2` 
              ON `s`.`id` = `s2`.`student_id` 
       LEFT JOIN `assessment_period` `a` 
              ON `s2`.`assessment_period_id` = `a`.`id` 
       LEFT JOIN `student_assessment_score` `s3` 
              ON `s2`.`id` = `s3`.`student_assessment_id` 
       LEFT JOIN `hierarchy_value_attribute_type` `h` 
              ON `s3`.`hierarchy_value_attribute_type_id` = `h`.`id` 
       LEFT JOIN `hierarchy_value` `h2` 
              ON `h`.`hierarchy_value_id` = `h2`.`id` 
       LEFT JOIN `hierarchy_type` `h3` 
              ON `h2`.`hierarchy_type_id` = `h3`.`id` 
       LEFT JOIN `assessment_type` `a2` 
              ON `a`.`assessment_type_id` = `a2`.`id` 
       LEFT JOIN `assessment_type_grade_level` `a3` 
              ON `s2`.`assessment_type_grade_level_id` = `a3`.`id` 
       LEFT JOIN `school_year` `s4` 
              ON `a`.`school_year_id` = `s4`.`id` 
WHERE  `a2`.`abbreviated_name` = 'PSS' 
       AND `h3`.`name` = 'Subject' 
       AND `h`.`name` = 'Scaled Score' 
       AND h2.name = 'Reading' 
       AND s.school_id = '112' 
       AND `a3`.`grade_level_id` = '8' 
GROUP  BY `h`.`name`, 
          `a`.`name` 
ORDER  BY `a`.`start_date`; 

Here's the explain output:

*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: a3
         type: ref
possible_keys: PRIMARY,assessment_type_grade_level_grade_level_id_grade_level_id
          key: assessment_type_grade_level_grade_level_id_grade_level_id
      key_len: 4
          ref: const
         rows: 3
        Extra: Using where; Using index; Using temporary; Using filesort
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: a2
         type: ALL
possible_keys: PRIMARY
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 2
        Extra: Using where; Using join buffer
*************************** 3. row ***************************
           id: 1
  select_type: SIMPLE
        table: a
         type: ref
possible_keys: PRIMARY,assessment_period_assessment_type_id_assessment_type_id
          key: assessment_period_assessment_type_id_assessment_type_id
      key_len: 8
          ref: db.a2.id
         rows: 32
        Extra: Using where
*************************** 4. row ***************************
           id: 1
  select_type: SIMPLE
        table: s4
         type: eq_ref
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 8
          ref: db.a.school_year_id
         rows: 1
        Extra: Using index
*************************** 5. row ***************************
           id: 1
  select_type: SIMPLE
        table: s2
         type: ref
possible_keys: PRIMARY,student_assessment_student_id_student_id,student_assessment_assessment_period_id_assessment_period_id,saai_3
          key: student_assessment_assessment_period_id_assessment_period_id
      key_len: 8
          ref: db.a.id
         rows: 733
        Extra: Using where
*************************** 6. row ***************************
           id: 1
  select_type: SIMPLE
        table: s
         type: eq_ref
possible_keys: PRIMARY,student_school_id_school_id
          key: PRIMARY
      key_len: 8
          ref: db.s2.student_id
         rows: 1
        Extra: Using where
*************************** 7. row ***************************
           id: 1
  select_type: SIMPLE
        table: s3
         type: ref
possible_keys: shhi_1,sssi_17
          key: sssi_17
      key_len: 8
          ref: db.s2.id
         rows: 5
        Extra: Using where
*************************** 8. row ***************************
           id: 1
  select_type: SIMPLE
        table: h
         type: eq_ref
possible_keys: PRIMARY,idx_hvat_name_idx,hhhi
          key: PRIMARY
      key_len: 8
          ref: db.s3.hierarchy_value_attribute_type_id
         rows: 1
        Extra: Using where
*************************** 9. row ***************************
           id: 1
  select_type: SIMPLE
        table: h2
         type: eq_ref
possible_keys: PRIMARY,indx_hierarchy_value_name_idx,hierarchy_value_hierarchy_type_id_hierarchy_type_id
          key: PRIMARY
      key_len: 8
          ref: db.h.hierarchy_value_id
         rows: 1
        Extra: Using where
*************************** 10. row ***************************
           id: 1
  select_type: SIMPLE
        table: h3
         type: eq_ref
possible_keys: PRIMARY,idx_hierarchy_type_name_idx
          key: PRIMARY
      key_len: 8
          ref: db.h2.hierarchy_type_id
         rows: 1
        Extra: Using where
10 rows in set (0.00 sec)

Here's the entry in the slow query log:

# Time: 120601  7:22:01
# User@Host: #####
# Query_time: 98.279940  Lock_time: 0.000139 Rows_sent: 0  Rows_examined: 0
SET timestamp=1338549721;
SELECT  
`a`.`name` AS `ap_name`, AVG(`s3`.`value`) AS `sas_value` 
FROM `student` `s` 
LEFT JOIN `student_assessment` `s2` ON `s`.`id` = `s2`.`student_id` 
LEFT JOIN `assessment_period` `a` ON `s2`.`assessment_period_id` = `a`.`id` 
LEFT JOIN `student_assessment_score` `s3` ON `s2`.`id` = `s3`.`student_assessment_id` 
LEFT JOIN `hierarchy_value_attribute_type` `h` ON `s3`.`hierarchy_value_attribute_type_id` = `h`.`id` 
LEFT JOIN `hierarchy_value` `h2` ON `h`.`hierarchy_value_id` = `h2`.`id` 
LEFT JOIN `hierarchy_type` `h3` ON `h2`.`hierarchy_type_id` = `h3`.`id` 
LEFT JOIN `assessment_type` `a2` ON `a`.`assessment_type_id` = `a2`.`id` 
LEFT JOIN `assessment_type_grade_level` `a3` ON `s2`.`assessment_type_grade_level_id` = `a3`.`id` 
LEFT JOIN `school_year` `s4` ON `a`.`school_year_id` = `s4`.`id`WHERE `a2`.`abbreviated_name` = 'PSS' 
AND `h3`.`name` = 'Subject' 
AND `h`.`name` = 'Scaled Score' 
 AND h2.name = 'Reading'  AND s.school_id = '112'  AND `a3`.`grade_level_id` = '8'  GROUP BY `h`.`name`, `a`.`name` ORDER BY `a`.`start_date`;

Here are the table counts:

   66,336 student
  170,479 student_assessment
      503 assessment_period
1,850,779 student_assessment_score
  207,348 hierarchy_value_attribute_type
   53,038 hierarchy_value
       24 hierarchy_type
        2 assessment_type
       53 assessment_type_grade_level
       13 school_year
share|improve this question
add comment

1 Answer

up vote 2 down vote accepted

It's interesting that the slow-query log entry states no rows were examined, and no rows were returned. I wonder if MySQL determined the query produced no results by looking only at indexes.

When you say you can't recreate the problem, do you mean MySQL returns the expected results for the query in much less time on subsequent attempts? That's often an indication that the first execution induced a lot of file IO to load data into buffers or cache. Subsequent executions of the same query against the same data benefit from faster access to the data.

share|improve this answer
    
Even when I disable the query cache, the query runs in less than a second. –  Matt Alexander Jun 1 '12 at 20:46
    
Sorry, I should have been more clear. If you're using the InnoDB storage engine, the data necessary to satisfy the query might be on disk, but not in the InnoDB buffer pool. The first execution will cause InnoDB to load this data from file into the pool, and subsequent exuections will not induce that expensive file IO. Even with MyISAM, you might see similar behavior with data getting cached by the filesystem, although I'm not as well-informed on OS-level details like that. –  Eric Rath Jun 1 '12 at 21:33
    
It's an InnoDB table. How do I disable that cache? I still haven't recreated this long running query. –  Matt Alexander Jun 8 '12 at 15:18
    
The size of the buffer pool is controlled by the innodb_buffer_pool_size ( dev.mysql.com/doc/refman/5.5/en/… ). But I think you might want to keep it around, and if you have enough memory, adjust the size of the buffer pool to accomodate the "active set" of your data. –  Eric Rath Jun 8 '12 at 15:32
    
It's also possible that the original query took a long time due to other activity on the server at the time. I.e. MySQL may have been contending with another process for some shared resource like CPU or disk IO. –  Eric Rath Jun 8 '12 at 15:33
show 4 more comments

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

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