慢查询的环境变量
slow_query_log: 是否启用慢查询日志，ON=启用，OFF=禁用；
slow_query_log_file: 慢查询日志的存放文件；
> show variables like '%slow_query%';
+---------------------+-----------------+
| Variable_name | Value |
+---------------------+-----------------+
| slow_query_log | ON |
| slow_query_log_file | armpvm-slow.log |
+---------------------+-----------------+
2 rows in set (0.001 sec)long_query_time: 慢查询的时间阈值，单位s；
> show variables like '%long_query%';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.001 sec)log_queries_not_using_indexes：是否记录未使用索引的sql语句，记录=ON，不记录=OFF；
> show variables like '%log_queries%';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF |
+-------------------------------+-------+
1 row in set (0.001 sec)慢查询日志的统计分析
使用mysqldumpslow工具进行慢查询的统计分析：
# mysqldumpslow --help
Parse and summarize the MySQL slow query log. Options are
--verbose verbose
--debug debug
--help write this text to standard output
-v verbose
-d debug
-s ORDER what to sort by (aa, ae, al, ar, at, a, c, e, l, r, t), 'at' is default
aa: average rows affected
ae: aggregated rows examined
al: average lock time
ar: average rows sent
at: average query time
a: rows affected
c: count
e: rows examined
l: lock time
r: rows sent
t: query time
-r reverse the sort order (largest last instead of first)
-t NUM just show the top n queries
-a don't abstract all numbers to N and strings to 'S'
-n NUM abstract numbers with at least n digits within names
-g PATTERN grep: only consider stmts that include this string
-h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard),
default is '*', i.e. match all
-i NAME name of server instance (if using mysql.server startup script)
-l don't subtract lock time from total time按执行总时间，统计top 10的sql语句：
# mysqldumpslow -s t -t 10 armpvm-slow.log
.......慢查询的查询计划分析
从慢查询日志中提取出sql语句，然后在环境上执行：
> explain select id from articles where title='One Life';
+------+-------------+----------+------+---------------+------+---------+------+------+-------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+------+-------------+----------+------+---------------+------+---------+------+------+-------------+
| 1 | SIMPLE | articles | ALL | NULL | NULL | NULL | NULL | 4 | Using where |
+------+-------------+----------+------+---------------+------+---------+------+------+-------------+
1 row in set (0.001 sec)查询计划中重点关注：
- key：使用的索引，若未使用则为null；
- rows：扫描的行数
- Extra: 额外的信息；
慢查询的各阶段时间消耗
一条查询语句：
- 首先经过查询缓存，若缓存命中，则直接返回；(查询缓存已Deprecated)
- 然后经过分析器，进行词法分析和语法分析；
- 然后经过优化器，生成执行计划，选择合适的索引；
- 最后经过执行器，调用存储引擎，返回结果。
使用profile查询各阶段时间消耗：
- 首先，set profiling=1，启动profile，这是一个session级别的配置；
- 然后，执行查询sql语句；
- 然后，show profiles，查看每一个查询所消耗的总时间信息；
- 最后，show profile for query N，查询某个sql语句详细的各阶段执行时间；
mysql> set session profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| have_profiling | YES |
| profiling | ON |
| profiling_history_size | 15 |
+------------------------+-------+
3 rows in set (0.01 sec)
mysql> select count(*) from film;
+----------+
| count(*) |
+----------+
| 1000 |
+----------+
1 row in set (0.01 sec)
mysql> show profiles;
+----------+------------+--------------------------------+
| Query_ID | Duration | Query |
+----------+------------+--------------------------------+
| 1 | 0.00449100 | show variables like '%profil%' |
| 2 | 0.00254800 | select count(*) from film |
+----------+------------+--------------------------------+
2 rows in set, 1 warning (0.00 sec)
mysql>
mysql> show profile for query 1;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.001785 |
| checking permissions | 0.000020 |
| Opening tables | 0.000019 |
| init | 0.000071 |
| System lock | 0.000032 |
| optimizing | 0.000007 |
| optimizing | 0.000003 |
| statistics | 0.000014 |
| preparing | 0.000020 |
| statistics | 0.000010 |
| preparing | 0.000008 |
| executing | 0.000010 |
| Sending data | 0.000009 |
| executing | 0.000004 |
| Sending data | 0.002355 |
| end | 0.000030 |
| query end | 0.000009 |
| closing tables | 0.000005 |
| removing tmp table | 0.000015 |
| closing tables | 0.000011 |
| freeing items | 0.000037 |
| cleaning up | 0.000017 |
+----------------------+----------+
22 rows in set, 1 warning (0.00 sec)
mysql>从上面的profile可以看出，耗时最长的是sending data，即server向client发送数据的过程。
