Welcome, Guest. [ Log In ]
Question   MySQL Optimization: Slow Query Logs and Indexes
Search KBase


Top 3 in this Area:
1. MySQL Optimization: Slow Query Logs and Indexes
2. Process Accounting (to find and remove the cause of slowness)
3. General MySQL Optimization Tips

 
MySQL Optimization: Slow Query Logs and Indexes
Alll this should be done over an ssh session (preferable) or a telnet session (less preferable).

Check /dh/mysql/logs/mysql.composer.slow (where "composer" is replaced with the composer on your machine). (Note, you'll probably have to request that DreamHost makes these files accessible to you; please provide us with a username, preferably an ssh and non-ftp user - this service is only available to dedicated server customers). This is the mysql slowlog, and it contains a log of every query that has been run which has performed without an index (ie doing a table scan). If you are doing table scans, you are most likely hitting the disk heavily, a very slow operation. You'd be much better off performing your queries with an index.

Not every query in the slow query logs is necessary a bad one. Look for queries where some of the following criteria are met:
A) "Rows_examined" is more than 2000
B) "Rows_examined" is less than 2000 but that query is being run 20 times a second.
C) "Rows_examined" is three times bigger than "Rows_sent"

(Note that these are rough criteria. Your mileage may vary depending upon your situation.)

Focus on the two or three worst queries at first. Once you've found a few, utilize the EXPLAIN statement to find a better way to restructure your query. See this link for an explanation and walkthrough of the EXPLAIN statement.

This approach is extremely useful, and is the same tactic DreamHost uses internally.

Here is a real life example to get you excited.
(The names have been changed to protect the innocent).

# ssh to your machine to open a secure shell:
ssh exampledomain.com
# ( you can use the PuTTY, which is a good free windows ssh client )

# Familiarize yourself with the slow log file
# Examine the entire slow log:
# (Note, you may have to ask DreamHost to provide you with access to this file.)
less /dh/mysql/logs/mysql.composer.slow
# Or examine just the slow file as it happens
tail -f /dh/mysql/logs/mysql.composer.slow
# hit ctrl-C to exit the tail

# Now find some of the worst offenders, here one way to do that:
[machinename]$ grep Rows_examined /dh/mysql/logs/mysql.composer.slow | sort -g -k9 -r |head -5
# Query_time: 1  Lock_time: 0  Rows_sent: 630  Rows_examined: 44241
# Query_time: 0  Lock_time: 0  Rows_sent: 630  Rows_examined: 44233
# Query_time: 2  Lock_time: 0  Rows_sent: 529  Rows_examined: 44034
# Query_time: 0  Lock_time: 0  Rows_sent: 528  Rows_examined: 44030
# Query_time: 0  Lock_time: 0  Rows_sent: 526  Rows_examined: 44030
[machinename]$

# search for the worst offender, here's one way to do that:
[machinename]$ grep -A 1 -B 2 44241 /dh/mysql/logs/mysql.composer.slow
# Time: 030610  8:49:05
# User@Host: dbusername[dbusername] @ composer.machinename.dreamservers.com [66.33.215.222]
# Query_time: 1  Lock_time: 0  Rows_sent: 630  Rows_examined: 44241
SELECT msgs.*, username AS sender_username FROM msgs INNER JOIN users ON (users.id = msgs.sender_id) WHERE user_id=939 AND msgs.status != 1 AND del != 2 ORDER BY date DESC;
[machinename]$
# You might also consider using the text browser `less'

# i don't know what database it's on, let me check:
[machinename]$ grep -A 1 -B 10000 44241 /dh/mysql/logs/mysql.composer.slow |grep -i ^use |tail -1
use dbname;
[machinename]$
# it's on dbname
# you might just recognize what database it's on from the query itself.

# Open up a mysql shell to fix the problem:
[machinename]$ mysql -h mysql.exampledomain.com -u dbusername -pYOURPASSWORDHERENOSPACES dbname

[[--SNIP--]]

# EXPLAIN statement to show you how bad the query is.
# Notice that 42000 rows rows of data are examined.
mysql> EXPLAIN SELECT msgs.*, username AS sender_username FROM msgs INNER JOIN users ON (users.id = msgs.sender_id) WHERE user_id=939 AND msgs.status != 1 AND del != 2 ORDER BY date DESC;
+-------+--------+---------------+---------+---------+----------------+-------+----------------------------+
| table | type   | possible_keys | key     | key_len | ref            | rows  | Extra                      |
+-------+--------+---------------+---------+---------+----------------+-------+----------------------------+
| msgs  | ALL    | NULL          | NULL    |    NULL | NULL           | 42845 | where used; Using filesort |
| users | eq_ref | PRIMARY       | PRIMARY |       8 | msgs.sender_id |     1 |                            |
+-------+--------+---------------+---------+---------+----------------+-------+----------------------------+
2 rows in set (0.00 sec)

mysql>

# How long does the query take before fixing?  About 1 second.
# (slightly modified for demostration purposes, but same result still).
mysql> SELECT count(*) FROM msgs INNER JOIN users ON (users.id = msgs.sender_id) WHERE user_id=939 AND msgs.status != 1 AND del != 2 ORDER BY date DESC;
+----------+
| count(*) |
+----------+
|      631 |
+----------+
1 row in set (1.03 sec)

# You want to be indexing on stuff in your WHERE and JOIN statements.
# specifically, where there is lots of uniqueness or "cardinality".
# user_id from above is really good, because there are lots of unique values
# for user_id.  Same thing goes for users.id and msgs.sender_id
# msgs.status won't help that much (but won't hurt) because mostly its values are
# 0 and 1.  same thing goes for "del".

# Add an index on the user_id, and msgs.sender_id columns.
# users.id is already indexed
# Note: always try to add a key of length 10 first, it's better (if possible).
mysql> create index user_id_index on msgs(user_id(10));
ERROR 1089: Incorrect sub part key. The used key part isn't a string, the used length is longer than the key part or the table handler doesn't support unique sub keys
mysql> create index user_id_index on msgs(user_id);
Query OK, 42857 rows affected (1.59 sec)
Records: 42857  Duplicates: 0  Warnings: 0

mysql>
mysql> create index sender_id_index on msgs(sender_id(10));ERROR 1089: Incorrect sub part key. The used key part isn't a string, the used length is longer than the key part or the table handler doesn't support unique sub keys
mysql> create index sender_id_index on msgs(sender_id);
Query OK, 42858 rows affected (1.16 sec)
Records: 42858  Duplicates: 0  Warnings: 0

mysql>


# Check the indices, see if they look good.
# They do look good.  Notice the high cardinatlity (uniqueness) of all three keys.
mysql> show index from msgs;
+-------+------------+-----------------+--------------+-------------+-----------+-------------+----------+--------+---------+
| Table | Non_unique | Key_name        | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Comment |
+-------+------------+-----------------+--------------+-------------+-----------+-------------+----------+--------+---------+
| msgs  |          0 | PRIMARY         |            1 | id          | A         |       42855 |     NULL | NULL   |         |
| msgs  |          1 | user_id_index   |            1 | user_id     | A         |        1224 |     NULL | NULL   |         |
| msgs  |          1 | sender_id_index |            1 | sender_id   | A         |        1071 |     NULL | NULL   |         |
+-------+------------+-----------------+--------------+-------------+-----------+-------------+----------+--------+---------+
3 rows in set (0.00 sec)

mysql>

# Very good.
# Now, check to see if your index actually improved anything.
# First, check with the EXPLAIN statement.  Much better!
mysql> EXPLAIN SELECT msgs.*, username AS sender_username FROM msgs INNER JOIN users ON (users.id = msgs.sender_id) WHERE user_id=939 AND msgs.status != 1 AND del != 2 ORDER BY date DESC;
+-------+--------+-------------------------------+---------------+---------+----------------+------+----------------------------+
| table | type   | possible_keys                 | key           | key_len | ref            | rows | Extra                      |
+-------+--------+-------------------------------+---------------+---------+----------------+------+----------------------------+
| msgs  | ref    | user_id_index,sender_id_index | user_id_index |       8 | const          |  635 | where used; Using filesort |
| users | eq_ref | PRIMARY                       | PRIMARY       |       8 | msgs.sender_id |    1 |                            |
+-------+--------+-------------------------------+---------------+---------+----------------+------+----------------------------+
2 rows in set (0.00 sec)

mysql>

# Now check the time it takes the query to complete.
# Only 0.01 seconds to complete.  Much faster.
mysql> SELECT count(*) FROM msgs INNER JOIN users ON (users.id = msgs.sender_id) WHERE user_id=939 AND msgs.status != 1 AND del != 2 ORDER BY date DESC;
+----------+
| count(*) |
+----------+
|      631 |
+----------+
1 row in set (0.01 sec)

mysql>

# Now start watching tail -f /dh/mysql/logs/mysql.composer.slow
# to find out more tables that should be indexed
tail -f /dh/mysql/logs/mysql.composer.slow

Last updated: Oct 05, 2005.

User Post (2003-09-17 07:36:18 by vantag)
Beautifully done. I've been slogging through the manual trying to get the gist of EXPLAIN and indices, and this helped me a lot more.