Announcement

Announcement Module
Collapse
No announcement yet.

Highly optimized queries are sometimes taking 20s to perform?

Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • Highly optimized queries are sometimes taking 20s to perform?

    Hi all,
    I have a PhP/MySQL app running on Joyent virtual servers that has been humming along nicely for a year, but now is hitting serious problems. Queries that used to run fine are now sometimes taking 10 or 20 seconds to complete (but sometimes <1 second). Table are MyISAM, and locking is not a big issue. There are usually only a couple users at once. The user_book table has about 600k rows and the book table has about 300k rows.

    Here is output of a slow log (some info anonymized):

    # Time: ****
    # User@Host: ****[****] @ **** []
    # Query_time: 12 Lock_time: 0 Rows_sent: 22 Rows_examined: 44
    SELECT id, title, author, count, status, user_book.ranking, asin, locale, image_url, user_book.uid, review.uid as review FROM book LEFT JOIN user_book ON id=bid LEFT JOIN review ON user_book.uid=review.uid AND user_book.bid=review.bid WHERE user_book.uid=25103032;

    and here is an explain of the same query.

    +----+-------------+-----------+--------+---------------+--- ------+---------+--------------------------------------+---- --+-------------+
    | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
    +----+-------------+-----------+--------+---------------+--- ------+---------+--------------------------------------+---- --+-------------+
    | 1 | SIMPLE | user_book | ref | PRIMARY,bid | PRIMARY | 4 | const | 21 | Using where |
    | 1 | SIMPLE | review | eq_ref | PRIMARY,bid | PRIMARY | 8 | const,****.user_book.bid | 1 | Using index |
    | 1 | SIMPLE | book | eq_ref | PRIMARY | PRIMARY | 4 | ****.user_book.bid | 1 | |
    +----+-------------+-----------+--------+---------------+--- ------+---------+--------------------------------------+---- --+-------------+

    I am at a loss. I am a professional software developer, but I know only the very basics when it comes to databases. I'm guessing there is some configuration problem here, as I see no other reason why this query would take 12 seconds to evaluate.

    Any ideas?

    Thanks,
    Garth

  • #2
    It could be hardware problem. You could check RAID and hdd status.

    Comment


    • #3
      So is this not the kind of problem that appears due to MySQL configuration? Has anyone else dealt with this kind of performance issue?

      I don't have control over the hardware. I asked my hosting provider, and they said everything is ok.

      Thanks,
      Garth

      Comment


      • #4
        If you run this query twice in a row, does it take 12 seconds each time?

        Also, try breaking this up into three selects and see if any one step is slow or if all the steps are slow.

        Comment


        • #5
          Does this occurs randomly ? Or there is pattern, like "slow query every 10 minutes" ?

          Constant period will mean that something is wrong with hardware, or that there is something running in the background (cron job).

          Comment


          • #6
            The slowness seems to happen only the first time I run the query. Second and third times it is fast.

            Sorry I should have mentioned this. I guess it would suggest a caching problem of some kind?

            Comment


            • #7
              There are two main reasons why it would be faster after the first time. One is the query cache and the other is that indexes have been loaded into the key buffer.

              You can prevent MySQL from using the query cache by adding SQL_NO_CACHE to your query like so:

              SELECT SQL_NO_CACHE some_column FROM some_table;

              If you run your query several times again without the query cache and it still gets faster after the first run, it means that the index pages you need are in the key buffer and its saving you a trip to disk. If that's the case check the following:

              SHOW VARIABLES LIKE 'key_buffer_size';
              SHOW TABLE STATUS LIKE 'some_table';
              SHOW STATUS LIKE 'Key_reads';
              SHOW STATUS LIKE 'Key_read_requests';

              Comment


              • #8
                I ran the query with the SQL_NO_CACHE option.

                The first execution took 10 seconds.

                Every execution after that took <2 seconds.

                So this has something to do with the key buffer? My indexes are not being stored in memory, or something? Here is the output from the queries you mentioned. Of course I can't interpret the significance of the below. Hopefully you can help me.

                Thanks!
                Garth

                key_buffer_size: 114294784

                mysql> SHOW TABLE STATUS LIKE 'user_book';
                +-----------+--------+---------+------------+--------+------ ----------+-------------+------------------+--------------+- ----------+----------------+---------------------+---------- -----------+---------------------+-----------------+-------- --+----------------+---------+
                | Name | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time | Update_time | Check_time | Collation | Checksum | Create_options | Comment |
                +-----------+--------+---------+------------+--------+------ ----------+-------------+------------------+--------------+- ----------+----------------+---------------------+---------- -----------+---------------------+-----------------+-------- --+----------------+---------+
                | user_book | MyISAM | 10 | Fixed | 636929 | 27 | 17197083 | 7599824371187711 | 16142336 | 0 | NULL | 2009-01-20 07:01:03 | 2009-01-31 00:28:41 | 2009-01-29 00:18:10 | utf8_unicode_ci | NULL | | |
                +-----------+--------+---------+------------+--------+------ ----------+-------------+------------------+--------------+- ----------+----------------+---------------------+---------- -----------+---------------------+-----------------+-------- --+----------------+---------+

                mysql> SHOW STATUS LIKE 'Key_reads';
                +---------------+--------+
                | Variable_name | Value |
                +---------------+--------+
                | Key_reads | 175478 |
                +---------------+--------+

                mysql> SHOW STATUS LIKE 'Key_read_requests';
                +-------------------+---------+
                | Variable_name | Value |
                +-------------------+---------+
                | Key_read_requests | 9893474 |
                +-------------------+---------+

                Comment


                • #9
                  So key_reads is the number of times MySQL had to go to disk to read an index page instead of finding that page already in the key buffer. key_read_requests is the number of times it was looking for an index page. When it does have to go to disk, it will put that page into the key buffer. If there's no room, it will move something else out of the key buffer. This is why your queries are getting faster, because the key buffer contains the information you need due to your previous query. As MySQL processes many other different queries, those index pages you needed will eventually get moved out of the key buffer and your query will become slower again. So basically, you probably need a larger key_buffer_size.

                  The rule of thumb you'll hear about these metrics is that the ratio of key_reads to key_read_requests should be less than 0.01. You're at about 0.017, so you could probably gain something by increasing your key_buffer_size.

                  To double check, you should see that the count of unused key blocks is low most of the time:

                  SHOW STATUS LIKE 'Key_blocks_unused';
                  SHOW STATUS LIKE 'Key_blocks_used';

                  Comment


                  • #10
                    Ok thanks, this helps. But even if I increase my key_buffer_size I will still occasionally not have the index in memory and will have to go to disk. In those cases is it normal to take 10-20 seconds to read the index page? This seems unreasonable. Is there a way to increase the speed with which it reads the index page?

                    Comment


                    • #11
                      So looking at the explain, I'd say you need to read about 80 pages or so from disk to satisfy it. Even if it took 100ms to read a page off disk, that would only be 8 seconds. 100ms is really really slow (I've never timed it, but I'd guess average modern hardware would be around 10ms). So yes, there's something else going wrong. Either your hardware is screwed up or this query is competing for resources with something else. If this is a unix box, are you heavy into I/O wait?

                      Comment

                      Working...
                      X