MySQL_14_用explain来定位并解决慢SQL问题

一、前言

SQL中，广义的查询就是crud操作，狭义的查询仅仅是select查询操作，慢查询就是指广义的查询，否则为什么不叫慢查询、慢更新、慢删除。

慢查询就是那些执行慢的sql语句，包括crud，一般是查询，所以称为慢查询

问题1：怎么一定一个sql语句是慢的？
回答：根据实际需要，如果前端反馈，执行3s是慢的，就是在my.ini中（Windows是my.ini，Linux是my.conf）中设置long_query_time=3，表示操作3s的查询就是慢查询，要记录下来，好好分析。

问题：为什么这些sql语句会慢呢？为什么这些sql语句满足long_query_time设置的时间？
回答：执行慢的sql语句不满足我们的要求，
（1）找到原因 explain + profile；
（2）要想办法解决，这就是SQL优化。

二、慢查询概要

2.1 第一步，慢查询分析之前的配置

2.1.1 方式一：修改my.ini

修改配置文件 在 my.ini 增加几行:

[mysqld]
long_query_time=2   // 慢查询的定义时间（超过2秒就是慢查询）

// 慢查询log日志记录（ slow_query_log）
## 5.5 版本以下配置
log-slow-queries="mysql-slow-query.log"
## 5.5 版本及以上配置
slow-query-log=on
slow_query_log_file="mysql-slow-query.log"

//记录没有使用索引的query
log-query-not-using-indexes

2.1.2 方式二：修改数据库

mysql > set global slow_query_log=ON
mysql > set global long_query_time = 3600;
mysql > set global long_queries_not_using_indexes=ON;

2.2 第二步，找到执行慢的sql语句

1. 找到慢查询日志文件路径：

mysql > show variables like 'slow_query_log_file

2. 使用msql提供的日志分析工具mysqldumpslow分析找出查询时间最慢的十条sql：

mysql > mysqldumpslow -s 10 /mysql/mysql01_slow.log

2.3 第三步，找到原因两种方式之一，explain分析，explain各个字段的解释

问题：为什么使用explain来做慢查询分析？
回答：explain关键字可以模拟优化器执行SQL查询语句，所以用来分析sql慢查询语句

使用explain分析这10条sql：

explain SQL_NO_CACHE select * from emp where name = 'Jefabc'

注意：mysql8.0以下，SQL_NO_CACHE 指明了该查询不走缓存，避免了查询速度时高时低，影响判断。
ps：使用explain一般看一看索引使用是否正确，尽量避免回表。


explain各个字段解释
id：每个执行计划都有一个 id，如果是一个联合查询union，这里还将有多个 id。
select_type：表示 SELECT 查询类型，常见的有四种
SIMPLE（普通查询，即没有联合查询、子查询）、
PRIMARY（主查询）、UNION（UNION 中后面的查询）、SUBQUERY（子查询）等。
table：当前执行计划查询的表，如果给表起别名了，则显示别名信息。
partitions：访问的分区表信息。
type：这是重要的列，显示连接使用了何种类型。从最好到最差的连接类型为：system > const > eq_ref > ref > range > index > ALL。
system/const：表中只有一行数据匹配，此时根据索引查询一次就能找到对应的数据。如果是 B + 树索引，我们知道此时索引构造成了多个层级的树，当查询的索引在树的底层时，查询效率就越低。const 表示此时索引在第一层，只需访问一层便能得到数据。
eq_ref：使用唯一索引扫描，常见于多表连接中使用主键和唯一索引作为关联条件。
ref：非唯一索引扫描，还可见于唯一索引最左原则匹配扫描。
range：索引范围扫描，比如，<，>，between 等操作。
index：索引全表扫描，此时遍历整个索引树。
ALL：表示全表扫描，需要遍历全表来找到对应的行。
possible_keys：可能使用到的索引。
key：实际使用到的索引。
key_len：实际使用的索引的长度。
ref：关联 id 等信息。
rows：查找到记录所扫描的行数。
filtered：查找到所需记录占总扫描记录数的比例。
Extra：额外的信息。

2.4 第四步，找到原因两种方式之一，profile分析，找到慢查询的本质原因，profile各个字段的解释

问题：为什么使用profile做慢查询分析？
回答：Show profile 是mysql 提供可以用来分析当前会话中语句执行的资源消耗情况。

以下四个中若出现一个或多个，表示sql 语句 必须优化。
1、converting HEAP to MyISAM ： 查询结果太大，内存都不够用了，往磁盘上搬了；
2、creating tmp table ：创建临时表，拷贝数据到临时表，然后再删除；
3、copying to tmp table on disk ：把内存中临时表复制到磁盘，危险！！！
4、 locked

2.4.1 explain制造慢sql语句，profile找到慢的sql语句

第一步，查看一下我的数据库版本

Show profiles是5.0.37之后添加的，要想使用此功能，要确保版本在5.0.37之后。

mysql> Select  version();

| version()           |
| 5.0.82-community-nt |

版本是支持show profiles功能的。接下来进入mysql性能跟踪诊断的世界

第二步，查看是否打开了profiles功能,默认是关闭的

mysql> use test;

Database changed

mysql> show profiles;

Empty set (0.00 sec)

显示为空，说明profiles功能是关闭的。

第三步，开启profile

mysql> set profiling=1;

Query OK, 0 rows affected (0.00 sec)

第四步，explain执行下面的查询

mysql> explain select distinct player_idfrom task limit 20;

mysql> select distinct player_id from task ;

第五步，执行 show profiles

mysql> show profiles;

| Query_ID | Duration   | Query                                               |

|       1 | 0.00035225 | explain select distinct player_id from task limit 20 |
|       2 | 1.91772775 | select distinct player_id from task                  |

Query_ID 这个需要就是给show profile for query 具体id来用的。

此时可以看到执行select distinct player_id from task 用了1.91772775秒的时间

2.4.2 show profile for query 具体id

2.4.2.1 sending data发送数据慢，就是网络IO

根据prifile进一步分析，

show profile for query 具体id

可以清楚的看到该sql的所有执行阶段，如锁等待、执行、优化、发送数据、内存排序，在下图中可以看到Sending data发送数据耗时1.39s。慢查询主要原因是网络IO。

2.4.2.2 Copying to tmp table临时表慢

**根据query_id 查看某个查询的详细时间耗费，是Copying to tmp table **

mysql> show profile for query 2;

| Status               | Duration |

| starting             | 0.000052 |
| Opening tables       | 0.000009 |
| System lock          | 0.000003 |
| Table lock           | 0.000007 |
| init                 | 0.000013 |
| optimizing           | 0.000003 |
| statistics           | 0.000009 |
| preparing            | 0.000008 |
| Creating tmp table   | 0.000074 |
| executing            | 0.000002 |
| Copying to tmp table |1.916551 |    // 大量时间   四条中第三条，很严重，临时表到
| Sending data         | 0.000667 |
| end                  | 0.000004 |
| removing tmp table   | 0.000065 |
| end                  | 0.000002 |
| end                  | 0.000002 |
| query end            | 0.000003 |
| freeing items        | 0.000245 |
| closing tables       | 0.000006 |
| logging slow query   | 0.000002 |
| cleaning up          | 0.000003 |

可以看到 Copying to tmp table 部分耗费了大量时间，这是因为distinct查看会用到临时表

2.4.3 查看cpu、内存和IO信息

那么可不可以查看占用cpu、 io等信息呢

 mysql> show profile block io,cpu for query2;

| Status | Duration | CPU_user |CPU_system | Block_ops_in | Block_ops_out |

| starting | 0.000052 |     NULL |       NULL |         NULL |   NULL |
| Opening tables  | 0.000009 |     NULL |       NULL |         NULL |   NULL |
| System lock   | 0.000003 |     NULL |       NULL |         NULL | NULL |
| Table lock   | 0.000007 |     NULL |       NULL |         NULL | NULL |
| init     | 0.000013 |     NULL |       NULL |         NULL | NULL |
| optimizing   | 0.000003 |     NULL |       NULL |         NULL |   NULL |
| statistics           | 0.000009 |     NULL |       NULL |         NULL |  NULL |
| preparing            | 0.000008 |     NULL |       NULL |        NULL | NULL |
| Creating tmp table   | 0.000074 |     NULL |       NULL |         NULL |  NULL |
| executing            | 0.000002 |     NULL |       NULL |         NULL |  NULL |
| Copying to tmp table（耗时） | 1.916551 |     NULL |       NULL |    NULL |NULL |
| Sending data         | 0.000667 |     NULL |       NULL |         NULL |  NULL |
| end                  | 0.000004 |     NULL |       NULL |         NULL |   NULL |
| removing tmp table   | 0.000065 |     NULL |       NULL |         NULL | NULL |
| end                  | 0.000002 |     NULL |       NULL |         NULL |  NULL |
| end                  | 0.000002 |     NULL |       NULL |         NULL | NULL |
| query end            | 0.000003 |     NULL |       NULL |         NULL | NULL |
| freeing items        | 0.000245 |     NULL |       NULL |         NULL |  NULL |
| closing tables       | 0.000006 |     NULL |       NULL |         NULL | NULL |
| logging slow query   | 0.000002 |     NULL |       NULL |         NULL | NULL |
| cleaning up          | 0.000003 |     NULL |       NULL |         NULL | NULL |

另外还可以看到memory,swaps,context switches,source 等信息

四、尾声

天天打码，天天进步！！！