服务器性能剖析
3.3 剖析MySQL查询
3.3.1 剖析服务器负载
服务器端的剖析很有价值，因为在服务器端可以有效的审计效率低下的查询。
捕获MySQL的查询到日志文件中
在MySQL的当前版本中，慢查询日志是开销最低、精度最高的测量查询时间的工具。在I/O密集的场景下，慢查询日志带来的开销也可以忽略不计。更需要担心的是日志可能消耗大量的磁盘空间。如果长期开启慢查询日志，注意要部署日志轮转工具。
有时候因为某些原因如权限不足等，无法在服务器上记录查询，可以使用pt-query-digest工具，通过--processlist选项不断查看SHOW FULL PROCESSLIST的输出，记录查询等一次出现的时间和消失的时间。也可以通过抓取TCP网络包，根据MySQL客户端和服务端通信协议进行解析。
分析查询日志
从慢查询日志中生成剖析报告建议使用pt-query-digest。
3.3.2 剖析单条查询
使用SHOW PROFILE
可以通过服务器变量在会话级别动态修改：
mysql> SET PROFILING = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> SELECT * FROM employees;
+----+-----------+---------------------+---------+
| id | last_name | email | dept_id |
+----+-----------+---------------------+---------+
| 2 | Jerry | jerry@qq.com | 2 |
...
| 37 | new | test@test.com | 2 |
+----+-----------+---------------------+---------+
21 rows in set (0.00 sec)
mysql> SHOW PROFILES;
+----------+------------+-------------------------+
| Query_ID | Duration | Query |
+----------+------------+-------------------------+
| 1 | 0.00031200 | SELECT * FROM employees |
+----------+------------+-------------------------+
1 row in set, 1 warning (0.01 sec)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
首先可以看到的是以很高的精度显示了查询的响应时间，继续。
mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000054 |
| checking permissions | 0.000010 |
| Opening tables | 0.000019 |
| init | 0.000021 |
| System lock | 0.000011 |
| optimizing | 0.000006 |
| statistics | 0.000013 |
| preparing | 0.000014 |
| executing | 0.000004 |
| Sending data | 0.000068 |
| end | 0.000007 |
| query end | 0.000037 |
| closing tables | 0.000010 |
| freeing items | 0.000024 |
| cleaning up | 0.000014 |
+----------------------+----------+
15 rows in set, 1 warning (0.00 sec)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
剖析报告给出了查询的每个步骤及其花费的时间。但不幸的是无法通过诸如ORDER BY之类的命令重新排序。继续：
mysql> SET @query_id = 1;
Query OK, 0 rows affected (0.00 sec)
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.000068 | 21.79 | 1 | 0.0000680000 |
| starting | 0.000054 | 17.31 | 1 | 0.0000540000 |
| query end | 0.000037 | 11.86 | 1 | 0.0000370000 |
| freeing items | 0.000024 | 7.69 | 1 | 0.0000240000 |
| init | 0.000021 | 6.73 | 1 | 0.0000210000 |
| Opening tables | 0.000019 | 6.09 | 1 | 0.0000190000 |
| preparing | 0.000014 | 4.49 | 1 | 0.0000140000 |
| cleaning up | 0.000014 | 4.49 | 1 | 0.0000140000 |
| statistics | 0.000013 | 4.17 | 1 | 0.0000130000 |
| System lock | 0.000011 | 3.53 | 1 | 0.0000110000 |
| closing tables | 0.000010 | 3.21 | 1 | 0.0000100000 |
| checking permissions | 0.000010 | 3.21 | 1 | 0.0000100000 |
| end | 0.000007 | 2.24 | 1 | 0.0000070000 |
| optimizing | 0.000006 | 1.92 | 1 | 0.0000060000 |
| executing | 0.000004 | 1.28 | 1 | 0.0000040000 |
+----------------------+----------+-------+-------+--------------+
15 rows in set, 16 warnings (0.02 sec)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
上面我们没有使用SHOW PROFILE命令而是直接查询INFORMATION_SCHEMA中对用的表，可以按照需求格式化输出。
SET @query_id = 1;
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;
1
2
2
使用SHOW STATUS
SHOW STATUS命令返回了一些计数器，它是一个有用的工具，但并不是一款剖析工具，可以显示某些活动如读索引的频繁程度，但是无法给出消耗了多少时间。
mysql> FLUSH STATUS;
Query OK, 0 rows affected (0.01 sec)
mysql> select * from employees;
[query results omitted]
21 rows in set (0.00 sec)
mysql> SHOW STATUS WHERE Variable_name LIKE 'Handler%' OR Variable_name LIKE 'Created%';
+----------------------------+-------+
| Variable_name | Value |
+----------------------------+-------+
| Created_tmp_disk_tables | 0 |
| Created_tmp_files | 0 |
| Created_tmp_tables | 0 |
| Handler_commit | 1 |
| Handler_delete | 0 |
| Handler_discover | 0 |
| Handler_external_lock | 2 |
| Handler_mrr_init | 0 |
| Handler_prepare | 0 |
| Handler_read_first | 1 |
| Handler_read_key | 1 |
| Handler_read_last | 0 |
| Handler_read_next | 0 |
| Handler_read_prev | 0 |
| Handler_read_rnd | 0 |
| Handler_read_rnd_next | 22 |
| Handler_rollback | 0 |
| Handler_savepoint | 0 |
| Handler_savepoint_rollback | 0 |
| Handler_update | 0 |
| Handler_write | 0 |
+----------------------------+-------+
21 rows in set (0.01 sec)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
通过EXPLAIN查看查询的执行计划也可以或得大部分相同的信息，但是EXPLAIN是通过估计得到的结果，而通过计数器则是实际的测量结果。例如：EXPLAIN无法告诉你临时表是否是磁盘表，这和内存临时表的性能的差别是很大的。
使用慢查询日志
使用Performance Schema
3.4 诊断间歇性问题
3.4.1 单条查询问题还是服务器问题
使用 SHOW GLOBAL STATUS
以较高的频率（比如1秒一次）执行SHOW GLOBAL STATUS命令捕获数据，问题出现时，则可以通过某些计数器(比如Threads_running, Threads_connected, Questions和Queries)的“尖刺”或者“凹陷”来发现。
mysqladmin ext -i1 |awk '
/Queries/{q=$4-qp;qp=$4}
/Threads_connected/{tc=$4}
/Threads_running/{printf "%5d %5d %5d\n", q, tc, $4}'
1
2
3
4
2
3
4
使用 SHOW PROCESSLIST
mysql -u root -p -e 'SHOW PROCESSLIST\G'
1