MySQL调优三步曲(慢查询、explain profile)

mysql profile explain slow_query_log分析优化查询

在做性能测试中经常会遇到一些sql的问题，其实做性能测试这几年遇到问题最多还是数据库这块，要么就是IO高要么就是cpu高，所以对数据的优化在性能测试过程中占据着很重要的地方，下面我就介绍一些msyql性能调优过程中经常用到的三件利器：

• 慢查询 （分析出现出问题的sql）

• Explain （显示了mysql如何使用索引来处理select语句以及连接表。可以帮助选择更好的索引和写出更优化的查询语句）

• Profile（查询到 SQL 会执行多少时间, 并看出 CPU/Memory 使用量, 执行过程中 Systemlock, Table lock 花多少时间等等.）

mysql的慢查询

1，配置开启

Linux:

在mysql配置文件my.cnf中增加

log-slow-queries = /var/lib/mysql/slowquery.log (指定日志文件存放位置，可以为空，系统会给一个缺省的文件host_name-slow.log)

long_query_time=2 (记录超过的时间，默认为10s)

log-queries-not-using-indexes (log下来没有使用索引的query,可以根据情况决定是否开启)

log-long-format (如果设置了，所有没有使用索引的查询也将被记录)

Windows:

在 my.ini 的 [mysqld] 添加如下语句：

log-slow-queries = E:\web\mysql\log\mysqlslowquery.log

long_query_time = 2(其他参数如上)

2,查看方式

Linux:

使用mysql自带命令mysqldumpslow查看

常用命令

-s ORDER what to sort by (t, at, l, al, r, aretc), 'at’ is default

-t NUM just show the top n queries

-g PATTERN grep: only consider stmts that includethis string

eg:

s，是order的顺序，说明写的不够详细，俺用下来，包括看了代码，主要有 c,t,l,r和ac,at,al,ar，分别是按照query次数，时间，lock的时间和返回的记录数来排序，前面加了a的时倒序 -t，是top n的意思，即为返回前面多少条的数据 -g，后边可以写一个正则匹配模式，大小写不敏感的

mysqldumpslow -s c -t 20 host-slow.log

mysqldumpslow -s r -t 20 host-slow.log

上述命令可以看出访问次数最多的20个sql语句和返回记录集最多的20个sql。

mysqldumpslow -t 10 -s t -g “left join” host-slow.log

这个是按照时间返回前10条里面含有左连接的sql语句。

explain

使用方法：

执行EXPLAIN SELECT * FROM res_user ORDER BYmodifiedtime LIMIT 0,1000 得到如下结果：

显示结果分析：

table | type | possible_keys | key |key_len | ref | rows | Extra

EXPLAIN列的解释：

• table
  显示这一行的数据是关于哪张表的

• type
  这是重要的列，显示连接使用了何种类型。从最好到最差的连接类型为const、eq_reg、ref、range、indexhe和ALL

• possible_keys
  显示可能应用在这张表中的索引。如果为空，没有可能的索引。可以为相关的域从WHERE语句中选择一个合适的语句

• key
  实际使用的索引。如果为NULL，则没有使用索引。很少的情况下，MYSQL会选择优化不足的索引。这种情况下，可以在SELECT语句中使用USE INDEX（indexname）来强制使用一个索引或者用IGNORE INDEX（indexname）来强制MYSQL忽略索引

• key_len
  使用的索引的长度。在不损失精确性的情况下，长度越短越好

• ref
  显示索引的哪一列被使用了，如果可能的话，是一个常数

• rows
  MYSQL认为必须检查的用来返回请求数据的行数

• Extra
  关于MYSQL如何解析查询的额外信息。将在表4.3中讨论，但这里可以看到的坏的例子是Using temporary和Using filesort，意思MYSQL根本不能使用索引，结果是检索会很慢

extra列返回的描述的意义

• Distinct
  一旦MYSQL找到了与行相联合匹配的行，就不再搜索了

• Not exists
  MYSQL优化了LEFT JOIN，一旦它找到了匹配LEFT JOIN标准的行， 就不再搜索了

• Range checked for each
  Record（index map:#）
  没有找到理想的索引，因此对于从前面表中来的每一个行组合，MYSQL检查使用哪个索引，并用它来从表中返回行。这是使用索引的最慢的连接之一

• Using filesort
  看到这个的时候，查询就需要优化了。MYSQL需要进行额外的步骤来发现如何对返回的行排序。它根据连接类型以及存储排序键值和匹配条件的全部行的行指针来排序全部行

• Using index
  列数据是从仅仅使用了索引中的信息而没有读取实际的行动的表返回的，这发生在对表的全部的请求列都是同一个索引的部分的时候

• Using temporary
  看到这个的时候，查询需要优化了。这里，MYSQL需要创建一个临时表来存储结果，这通常发生在对不同的列集进行ORDER BY上，而不是GROUP BY上

• Where used
  使用了WHERE从句来限制哪些行将与下一张表匹配或者是返回给用户。如果不想返回表中的全部行，并且连接类型ALL或index，这就会发生，或者是查询有问题

不同连接类型的解释(按照效率高低的顺序排序)

• system
  表只有一行：system表。这是const连接类型的特殊情况

• const
  表中的一个记录的最大值能够匹配这个查询（索引可以是主键或惟一索引）。因为只有一行，这个值实际就是常数，因为MYSQL先读这个值然后把它当做常数来对待

• eq_ref
  在连接中，MYSQL在查询时，从前面的表中，对每一个记录的联合都从表中读取一个记录，它在查询使用了索引为主键或惟一键的全部时使用

• ref
  这个连接类型只有在查询使用了不是惟一或主键的键或者是这些类型的部分（比如，利用最左边前缀）时发生。对于之前的表的每一个行联合，全部记录都将从表中读出。这个类型严重依赖于根据索引匹配的记录多少—越少越好

• range
  这个连接类型使用索引返回一个范围中的行，比如使用>或<查找东西时发生的情况

• index
  这个连接类型对前面的表中的每一个记录联合进行完全扫描（比ALL更好，因为索引一般小于表数据）

• ALL
  这个连接类型对于前面的每一个记录联合进行完全扫描，这一般比较糟糕，应该尽量避免

profile

我们可以先使用

mysql> SELECT @@profiling;
±------------+
| @@profiling |
±------------+
| 0 |
±------------+

1 row in set (0.00 sec)来查看是否已经启用profile，如果profilng值为0，可以通过

mysql> SET profiling = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT @@profiling;
±------------+
| @@profiling |
±------------+
| 1 |
±------------+

1 row in set (0.00 sec)

来启用。启用profiling之后，我们执行一条查询语句，比如：

SELECT * FROM res_user ORDER BY modifiedtimeLIMIT 0,1000

mysql> show profiles;
±---------±-----------±------------------------------------------------------------+
| Query_ID | Duration | Query |
±---------±-----------±------------------------------------------------------------+
| 1| 0.00012200 | SELECT @@profiling |
| 2| 1.54582000 | SELECT res_id FROM res_user ORDER BY modifiedtime LIMIT 0,3 |
±---------±-----------±------------------------------------------------------------+

2 rows in set (0.00 sec) 注意：Query_ID表示刚执行的查询语句

mysql> show profile for query 2;
±-------------------------------±---------+
| Status | Duration |
±-------------------------------±---------+
| starting | 0.000013 |
| checking query cache for query | 0.000035 |
| Opening tables | 0.000009 |
| System lock | 0.000002 |
| Table lock | 0.000015 |
| init | 0.000011 |
| optimizing | 0.000003 |
| statistics | 0.000006 |
| preparing | 0.000006 |
| executing | 0.000001 |
| Sorting result | 1.545565 |
| Sending data | 0.000038 |
| end | 0.000003 |
| query end | 0.000003 |
| freeing items | 0.000069 |
| storing result in query cache | 0.000004 |
| logging slow query | 0.000001 |
| logging slow query | 0.000033 |
| cleaning up | 0.000003 |
±-------------------------------±---------+

19 rows in set (0.00 sec)

结论：可以看出此条查询语句的执行过程及执行时间，总的时间约为1.545s。这时候我们再执行一次。

mysql> SELECT res_id FROM res_user ORDERBY modifiedtime LIMIT 0,3;
±--------+
| res_id |
±--------+
| 1000305 |
| 1000322 |
| 1000323 |
±--------+

3 rows in set (0.00 sec)

mysql> show profiles;
±---------±-----------±------------------------------------------------------------+
| Query_ID | Duration | Query |
±---------±-----------±------------------------------------------------------------+
| 1 | 0.00012200 | SELECT @@profiling |
| 2 | 1.54582000 | SELECT res_id FROM res_userORDER BY modifiedtime LIMIT 0,3 |
| 3 | 0.00006500 | SELECT res_id FROMres_user ORDER BY modifiedtime LIMIT 0,3 |
±---------±-----------±------------------------------------------------------------+

3 rows in set (0.00 sec)

mysql> show profile for query 3;
±-------------------------------±---------+
| Status | Duration |
±-------------------------------±---------+
| starting | 0.000013 |
| checking query cache for query | 0.000005|
| checking privileges on cached | 0.000003 |
| sending cached result to clien | 0.000040|
| logging slow query | 0.000002 |
| cleaning up | 0.000002 |
±-------------------------------±---------+
6 rows in set (0.00 sec) (注意黄色标记的地方)

结论：可以看出此次第二次查询因为前一次的查询生成了cache，所以这次无需从数据库文件中再次读取数据而是直接从缓存中读取，结果查询时间比第一次快多了（第一次查询用了1.5秒而本次用了不到5毫秒）。