List:General Discussion« Previous MessageNext Message »
From:Darryle Steplight Date:July 16 2009 3:53am
Subject:Re: Slow query Performance
View as plain text  
Can you show us the output of DESCRIBE score and SHOW INDEX FROM score?

On Wed, Jul 15, 2009 at 6:44 PM, Tachu®<tachu1+mysql@stripped> wrote:
> I'm having random query slowness that i can only reproduce once. My main
> question is that the query runs faster the second time around but i dont
> have query cache enabled here is some info from mysql profiler;
>
> The time is spent mostly on the sending data step
> first time around
>
> 63 rows in set (0.51 sec)
>
> show profile all;
>
> +--------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
> | Status             | Duration | CPU_user | CPU_system
> | Context_voluntary
> | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent |
> Messages_received | Page_faults_major | Page_faults_minor | Swaps |
> Source_function       | Source_file   | Source_line |
>
> +--------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
> | starting           | 0.000165 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> NULL                  | NULL  
>        |        NULL |
> | Opening tables     | 0.000033 | 0.000000 |   0.000000 |  
>               0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> open_tables           | sql_base.cc   |    
>    4450 |
> | System lock        | 0.000020 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_lock_tables     | lock.cc       |      
>   258 |
> | Table lock         | 0.000028 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_lock_tables     | lock.cc       |      
>   269 |
> | init               | 0.000052 | 0.000000 |
>   0.000000 |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_select          | sql_select.cc |      
>  2337 |
> | optimizing         | 0.000036 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> optimize              | sql_select.cc |  
>       762 |
> | statistics         | 0.000233 | 0.001000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> optimize              | sql_select.cc |  
>       944 |
> | preparing          | 0.000031 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> optimize              | sql_select.cc |  
>       954 |
> | executing          | 0.000017 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> exec                  | sql_select.cc |
>        1638 |
> | Sending data       | 0.504797 | 0.129980 |   0.012998 |  
>             429
> |                  38 |    
>     2456 |            64 |      
>       0
> |                 0 |      
>           0 |              
>   0 |     0 |
> exec                  | sql_select.cc |
>        2177 |
> | end                | 0.000054 | 0.000000 |
>   0.000000 |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_select          | sql_select.cc |      
>  2382 |
> | query end          | 0.000023 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_execute_command | sql_parse.cc  |        4799 |
> | freeing items      | 0.000063 | 0.000000 |   0.000999 |  
>               0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_parse           | sql_parse.cc  |    
>    5805 |
> | logging slow query | 0.000018 | 0.000000 |   0.000000 |      
>           0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> log_slow_statement    | sql_parse.cc  |      
>  1608 |
> | cleaning up        | 0.000020 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> dispatch_command      | sql_parse.cc  |      
>  1575 |
>
> +--------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
> 15 rows in set (0.00 sec)
>
> Second time around
>
> 63 rows in set (0.00 sec)
>
> mysql> show profile
>
> all;+--------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+|
> Status             | Duration | CPU_user | CPU_system |
> Context_voluntary |
> Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent |
> Messages_received | Page_faults_major | Page_faults_minor | Swaps |
> Source_function       | Source_file   | Source_line |
>
> +--------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
> | starting           | 0.000142 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> NULL                  | NULL  
>        |        NULL |
> | Opening tables     | 0.000028 | 0.000000 |   0.000000 |  
>               0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> open_tables           | sql_base.cc   |    
>    4450 |
> | System lock        | 0.000023 | 0.000000 |   0.001000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_lock_tables     | lock.cc       |      
>   258 |
> | Table lock         | 0.000030 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_lock_tables     | lock.cc       |      
>   269 |
> | init               | 0.000040 | 0.000000 |
>   0.000000 |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_select          | sql_select.cc |      
>  2337 |
> | optimizing         | 0.000030 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> optimize              | sql_select.cc |  
>       762 |
> | statistics         | 0.000217 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> optimize              | sql_select.cc |  
>       944 |
> | preparing          | 0.000029 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> optimize              | sql_select.cc |  
>       954 |
> | executing          | 0.000018 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> exec                  | sql_select.cc |
>        1638 |
> | Sending data       | 0.000936 | 0.000999 |   0.000000 |  
>               0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> exec                  | sql_select.cc |
>        2177 |
> | end                | 0.000026 | 0.000000 |
>   0.000000 |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_select          | sql_select.cc |      
>  2382 |
> | query end          | 0.000020 | 0.000000 |   0.000000
> |                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_execute_command | sql_parse.cc  |        4799 |
> | freeing items      | 0.000046 | 0.000000 |   0.000000 |  
>               0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> mysql_parse           | sql_parse.cc  |    
>    5805 |
> | logging slow query | 0.000018 | 0.000000 |   0.000000 |      
>           0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> log_slow_statement    | sql_parse.cc  |      
>  1608 |
> | cleaning up        | 0.000019 | 0.000000 |   0.000000 |
>                 0
> |                   0 |    
>        0 |             0 |    
>         0
> |                 0 |      
>           0 |              
>   0 |     0 |
> dispatch_command      | sql_parse.cc  |      
>  1575 |
>
> +--------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
> 15 rows in set (0.00 sec)
>
> Any ideas how i can improve the performance of the query. the explain
>
> explain select user_id,result_id from score where quiz_id='495536' and
> user_id in
>
> (594939703,641833475,648583496,663932271,791002140,844089643,1014189359,1014996058,1021011357,1035297313,1043753292,1103136802,1107070131,1114628916,1129457032,1133091309,1188705251,1211995704,1219452575,1219631303,1239604246,1241474238,1266412488,1266549868,1288719892,1289732597,1317205736,1346089661,1350738033,1354967647,1356046070,1369391720,1374076904,1406156780,1407302487,1414151928,1425275210,1457839666,1466635900,1484315366,1493410149,1536834812,1544094394,1572354290,1575139632,1578136049,1587129534,1592996678,1594617334,1615538051,1615906710,1621733854,1622940529,1646693120,1674002418,1684166314,1684535294,1701864533,1703227082,1711823847,1713353427,1732903860,1752595138,1758240924,1813245914,1815724221,1839942291,100000015406640);
>
> +----+-------------+-------+-------+-----------------+---------+---------+------+------+-------------+
> | id | select_type | table | type  | possible_keys   | key     |
> key_len |
> ref  | rows | Extra       |
>
> +----+-------------+-------+-------+-----------------+---------+---------+------+------+-------------+
> |  1 | SIMPLE      | score | range | user_id,quiz_id | user_id |
> 12      |
> NULL |   68 | Using where |
>
> +----+-------------+-------+-------+-----------------+---------+---------+------+------+-------------+
> 1 row in set (0.02 sec)
>
>  UNIQUE KEY `user_id` (`user_id`,`quiz_id`),
>



-- 
A: It reverses the normal flow of conversation.
Q: What's wrong with top-posting?
A: Top-posting.
Q: What's the biggest scourge on plain text email discussions?
Thread
Slow query PerformanceTachu®16 Jul
  • Re: Slow query PerformanceDarryle Steplight16 Jul
    • Re: Slow query PerformanceDon Read16 Jul
      • RE: Slow query PerformanceMartin Gainty16 Jul
  • Re: Slow query PerformanceDan Nelson16 Jul