Mysql剖析单条查询(高性能mySql学习笔记)
Mysql剖析单条查询的方法: (以mysql官网提供的sakila数据库演示)
方式1.通过show profile工具(show profile是Mysql5.1版本之后引入的功能)
工作原理：show profile是一个工具, 当一条查询提交给服务器时,该工具会将记录剖析信息到一张临时表，并且给查询赋予一个从1开始的整数标志符.
使用举例：
Mysql> SET profiling=1; (默认是禁用的)
Mysql>SELECT * from sakila.nicer_but_slower_film_list;
Mysql> show profiles;
+----------+------------+--------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+--------------------------------------------------+
| 1 | 0.12766825 | SELECT * from sakila.nicer_but_slower_film_list |
+----------+------------+--------------------------------------------------+
可以看到该语句执行时间,但是不够详细,此时可以使用 show profile for query queryId进一步查看更加详细的
mysql> show profile for query 1; +----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 7.5E-5 | | checking permissions | 5E-6 | | Opening tables | 0.000431 | | System lock | 1.5E-5 | | checking permissions | 2E-6 | | checking permissions | 2E-6 | | checking permissions | 1E-6 | | checking permissions | 1E-6 | | checking permissions | 0.002143 | | optimizing | 1.6E-5 | | statistics | 7.3E-5 | | preparing | 1.8E-5 | | Creating tmp table | 0.001932 | | executing | 4E-6 | | Copying to tmp table | 0.052056 | | Sorting result | 0.008785 | | Sending data | 0.05388 | | removing tmp table | 0.002344 | | Sending data | 1.3E-5 | | init | 1.8E-5 | | optimizing | 4E-6 | | statistics | 8E-6 | | preparing | 1E-5 | | executing | 1E-6 | | Sending data | 0.003856 | | end | 9E-6 | | query end | 5E-6 | | closing tables | 2E-6 | | removing tmp table | 0.001827 | | closing tables | 1.8E-5 | | freeing items | 1.3E-5 | | removing tmp table | 7E-6 | | freeing items | 9E-5 | | logging slow query | 3E-6 | | cleaning up | 5E-6 | +----------------------+----------+ 35 rows in set
这个剖析报告给出了查询中每个步骤所花费的时间,但是这个报告是按照执行顺序进行排序的,但是我们更多的是关注花费时间最多的步骤, 此时我们如果不用show profile命令,还可以查询information_schema.PROFILING表
Mysql>SET @query_id = 9;
Mysql> SELECT STATE, sum(DURATION) AS Total_R, ROUND( 100*sum(DURATION)/(SELECT sum(DURATION) FROM information_schema.PROFILING WHERE QUERY_ID = @query_id),2 ) AS PCT_R, count(*) AS calls, sum(DURATION)/count(*) AS "R/CALL" FROM information_schema.PROFILING WHERE QUERY_ID = @query_id GROUP BY STATE ORDER BY Total_R DESC;
+----------------------+----------+-------+-------+--------------+ | STATE | Total_R | PCT_R | calls | R/CALL | +----------------------+----------+-------+-------+--------------+ | Sending data | 0.053959 | 44.97 | 3 | 0.0179863333 | | Copying to tmp table | 0.048336 | 40.29 | 1 | 0.0483360000 | | Sorting result | 0.008770 | 7.31 | 1 | 0.0087700000 | | removing tmp table | 0.004025 | 3.35 | 3 | 0.0013416667 | | checking permissions | 0.002216 | 1.85 | 6 | 0.0003693333 | | Creating tmp table | 0.001866 | 1.56 | 1 | 0.0018660000 | | Opening tables | 0.000437 | 0.36 | 1 | 0.0004370000 | | freeing items | 0.000094 | 0.08 | 2 | 0.0000470000 | | starting | 0.000079 | 0.07 | 1 | 0.0000790000 | | statistics | 0.000072 | 0.06 | 2 | 0.0000360000 | | preparing | 0.000022 | 0.02 | 2 | 0.0000110000 | | optimizing | 0.000021 | 0.02 | 2 | 0.0000105000 | | System lock | 0.000020 | 0.02 | 1 | 0.0000200000 | | closing tables | 0.000018 | 0.02 | 2 | 0.0000090000 | | init | 0.000016 | 0.01 | 1 | 0.0000160000 | | end | 0.000008 | 0.01 | 1 | 0.0000080000 | | executing | 0.000006 | 0.01 | 2 | 0.0000030000 | | query end | 0.000004 | 0.00 | 1 | 0.0000040000 | | cleaning up | 0.000004 | 0.00 | 1 | 0.0000040000 | | logging slow query | 0.000003 | 0.00 | 1 | 0.0000030000 |
从这个结果可以看到,sending data和Copying to tmp table花费时间最多,就可以进一步分析优化了.
方式2.通过show status方式剖析单条查询
原理:
show status大部分结果都只是一个计数器,可以显示某些活动如读索引的频繁程度,但无法给出消耗了多长时间.
尽管show status无法提供基于时间的统计,但是执行完成后观察执行结果,还是 有帮助的,最有用的计数器包括:
句柄计数器(handler counter),临时文件,表计数器
我们可以通过将会话级别的计数器清零,然后查询前面的视图,再检查计数器结果
mysql> FLUSH statu; mysql> SELECT * from nicer_but_slower_film_list; mysql> show status where Variable_name like 'Handler%' or Variable_name Like 'Created%'; +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | Created_tmp_disk_tables | 10 | | Created_tmp_files | 5 | | Created_tmp_tables | 28 | | Handler_commit | 5 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_prepare | 0 | | Handler_read_first | 5 | | Handler_read_key | 37425 | | Handler_read_last | 0 | | Handler_read_next | 32310 | | Handler_read_prev | 0 | | Handler_read_rnd | 27330 | | Handler_read_rnd_next | 37788 | | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | Handler_update | 15 | | Handler_write | 37664 | +----------------------------+-------+
从这个结果可以看到,该查询创建了10张磁盘临时表, 而且有很多没有用到索引的多操作(Handler_read_rnd_next),假设我们不知道该视图的结构,仅从结果我们可以推测到该视图使用了多表关联查询,而且没有使用合适的索引,可能是其中一个子查询创建了临时表,和其他表做关联查询, 而保存子查询结果的临时表没有合适的索引.
注意：通过explain 命令也可以得到大部分结果，但是explain是通过估计得到的结果,而通过计数器则是实际的测量结果.