如果英文不好的话,可以参考 searchdoc 翻译的中文版本
http://www.searchdoc.cn/rdbms/mysql/dev.mysql.com/doc/refman/5.7/en/index.com.coder114.cn.html
要弄清楚这个问题,需要知道MySQL处理SQL请求的过程, 我们来看下
对于一个读写很频发的的系统,使用查询缓存很可能会降低查询处理的效率,建议不是用查询缓存,可以将query_cache_type 设置为OFF,query_cache_size 设置为0
接着上一步说,查询缓存未启用,或者 未命中查询缓存 , 服务器进行SQL解析、预处理,再由优化器生成对应的执行计划 。 MySQL会依赖这个执行计划和存储引擎进行交互 .
包括以下过程
当然了还有 查询CPU等信息 的命令
比如 show profile cpu for query 1
演示
mysql> set profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> select * from t_order;
+------+-----------------+
| id | product |
+------+-----------------+
| 1 | artisan-prod-01 |
+------+-----------------+
1 row in set (0.00 sec)
mysql> show profiles; # 每条SQL的执行汇总信息
+----------+------------+-----------------------+
| Query_ID | Duration | Query |
+----------+------------+-----------------------+
| 1 | 0.00067725 | select * from t_order |
+----------+------------+-----------------------+
1 row in set, 1 warning (0.00 sec)
mysql> show profile for query 1; # m每个阶段的耗时
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000169 |
| checking permissions | 0.000054 |
| Opening tables | 0.000041 |
| init | 0.000028 |
| System lock | 0.000034 |
| optimizing | 0.000009 |
| statistics | 0.000023 |
| preparing | 0.000020 |
| executing | 0.000009 |
| Sending data | 0.000218 |
| end | 0.000010 |
| query end | 0.000013 |
| closing tables | 0.000013 |
| freeing items | 0.000021 |
| cleaning up | 0.000018 |
+----------------------+----------+
15 rows in set, 1 warning (0.00 sec)
mysql>
查询CPU的使用情况
mysql> show profile cpu for query 1;
+----------------------+----------+----------+------------+
| Status | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| starting | 0.000169 | 0.000066 | 0.000103 |
| checking permissions | 0.000054 | 0.000021 | 0.000033 |
| Opening tables | 0.000041 | 0.000015 | 0.000025 |
| init | 0.000028 | 0.000011 | 0.000016 |
| System lock | 0.000034 | 0.000013 | 0.000021 |
| optimizing | 0.000009 | 0.000003 | 0.000005 |
| statistics | 0.000023 | 0.000009 | 0.000014 |
| preparing | 0.000020 | 0.000008 | 0.000012 |
| executing | 0.000009 | 0.000003 | 0.000005 |
| Sending data | 0.000218 | 0.002785 | 0.000000 |
| end | 0.000010 | 0.000000 | 0.000000 |
| query end | 0.000013 | 0.000000 | 0.000000 |
| closing tables | 0.000013 | 0.000000 | 0.000000 |
| freeing items | 0.000021 | 0.000000 | 0.000000 |
| cleaning up | 0.000018 | 0.000000 | 0.000000 |
+----------------------+----------+----------+------------+
15 rows in set, 1 warning (0.00 sec)
mysql>
看到有一个 1 warning ,看看是啥
mysql> show warnings;
+---------+------+-------------------------------------------------------------------------------------------------------------+
| Level | Code | Message |
+---------+------+-------------------------------------------------------------------------------------------------------------+
| Warning | 1287 | 'SHOW PROFILE' is deprecated and will be removed in a future release. Please use Performance Schema instead |
+---------+------+-------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
mysql>
‘SHOW PROFILE’ is deprecated and will be removed in a future release. Please use Performance Schema instead , 很明白了,看看官方推荐的 Performance Schema 吧
5.5引入的 . performance_schema在5.7.x及其以上版本中默认启用(5.6.x及其以下版本默认关闭),如果要显式启用或关闭时,我们需要使用参数performance_schema=ON|OFF设置
performance_schema可以记录数据库所有线程执行过的SQL, 而上面的profile是session级别的,仅能记录当前session 的。
mysql> show variables like 'performance_schema';
+--------------------+-------+
| Variable_name | Value |
+--------------------+-------+
| performance_schema | ON |
+--------------------+-------+
1 row in set (0.00 sec)
mysql>
mysql> use performance_schema ; # 使用performance_schema
Database changed
mysql> update setup_instruments set enabled = 'YES', timed = 'YES' where name like 'stage%'; # Step1
Query OK, 120 rows affected (0.00 sec)
Rows matched: 129 Changed: 120 Warnings: 0
mysql> update setup_consumers set enabled = 'YES' where name like 'events%'; # Step2
Query OK, 10 rows affected (0.31 sec)
Rows matched: 12 Changed: 10 Warnings: 0
mysql> select * from artisan.t_order; # 随便执行点啥 以便观察效果
+------+-----------------+
| id | product |
+------+-----------------+
| 1 | artisan-prod-01 |
+------+-----------------+
1 row in set (0.00 sec)
mysql>
查看耗时的SQL
SELECT
a.thread_id,
sql_text,
c.event_name,
(c.timer_end - c.timer_start) / 1000000000 AS 'duration (ms)'
FROM
`performance_schema`.events_statements_history_long a
JOIN `performance_schema`.threads b ON a.thread_id = b.thread_id
JOIN `performance_schema`.events_stages_history_long c ON c.thread_id = b.thread_id
AND c.event_id BETWEEN a.event_id
AND a.end_event_id
WHERE
b.processlist_id = connection_id()
AND a.event_name = 'statement/sql/select'
ORDER BY
a.thread_id,
c.event_id;