MySQL query took 98 seconds to run but EXPLAIN looks okay

Question

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`;

Answer 1

For a 10 tables query, 98 seconds could actually be OK.

Please note that under mysql your where clause:

       `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' 

is implicitly canceling the LEFT JOINS, since each time you ask for "column=value", it means "column IS NOT NULL". Use INNER JOINS instead of LEFT JOINS for the tables a2, h3, h, h2, s and a3, and add theses respective filters within the ON part of their respective INNER JOIN.

rgds.

PS: By the way, would you mind showing your SHOW PROFILE result?