2019-08-16 MySQL

MySQL慢查询与SQL问题排查

1. 查看是否开启慢查询

master >show variables like 'slow_query%';	# 是否开启
+---------------------+---------------------------------------------+
| Variable_name       | Value                                       |
+---------------------+---------------------------------------------+
| slow_query_log      | ON                                          |
| slow_query_log_file | /data1/mysql_root/data/20124/slow_query.log |
+---------------------+---------------------------------------------+
2 rows in set (0.01 sec)

master >show variables like 'long%';	# 慢查询时间
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)

master >show global status like '%Slow_queries%';	# 查看有多少慢查询
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 4903  |
+---------------+-------+
1 row in set (0.01 sec)

# 设置开启慢查询
mysql>set global slow_query_log = ON；
mysql>set global long_query_time = 1;

2. 显示正在运行的进程数

show processlist 是显示用户正在运行的线程

使用下面的查询语句可以获得相同的结果：

select * from information_schema.processlist

下面是常用到的SQL，用于排查mysql 问题。

按客户端 IP 分组，看哪个客户端的链接数最多：

select client_ip,count(client_ip) as client_num from (select substring_index(host,':' ,1) as client_ip from processlist ) as connect_info group by client_ip order by client_num desc;

查看正在执行的线程，并按 Time 倒排序，看看有没有执行时间特别长的线程

select * from information_schema.processlist where Command != 'Sleep' order by Time desc;

找出所有执行时间超过 5 分钟的线程，拼凑出 kill 语句，方便后面查杀

select concat('kill ', id, ';') from information_schema.processlist where Command != 'Sleep' and Time > 300 order by Time desc;

3. Explain 语句详解

EXPLAIN列的解释：

列	描述
`table`	显示这一行的数据是关于哪张表的。
`type`	这是重要的列，显示连接使用了何种类型。从最好到最差的连接类型为 `const`、`eq_ref`、`ref`、`range`、`index`和`ALL`。
`possible_keys`	显示可能应用在这张表中的索引。如果为空，没有可能的索引。可以为相关的域从`WHERE`语句中选择一个合适的语句。
`key`	实际使用的索引。如果为`NULL`，则没有使用索引。很少的情况下，MySQL会选择优化不足的索引。这种情况下，可以在`SELECT`语句中使用`USE INDEX（indexname）` 来强制使用一个索引或者用`IGNORE INDEX（indexname）`来强制MySQL忽略索引。
`key_len`	使用的索引的长度。在不损失精确性的情况下，长度越短越好。
`ref`	显示索引的哪一列被使用了，如果可能的话，是一个常数。
`rows`	MySQL认为必须检查的用来返回请求数据的行数。
`Extra`	关于MySQL如何解析查询的额外信息。将在表4.3中讨论，但这里可以看到的坏的例子是`Using temporary`和`Using filesort`，意思MySQL根本不能使用索引，结果是检索会很慢。

extra列返回的描述的意义：

值	意义
`Distinct`	一旦MySQL找到了与行相联合匹配的行，就不再搜索了。
`Not exists`	MySQL优化了`LEFT JOIN`，一旦它找到了匹配`LEFT JOIN`标准的行，就不再搜索了。
`Range checked for each Record（index map:#）`	没有找到理想的索引，因此对于从前面表中来的每一个行组合，MySQL检查使用哪个索引，并用它来从表中返回行。这是使用索引的最慢的连接之一。
`Using filesort`	看到这个的时候，查询就需要优化了。MySQL需要进行额外的步骤来发现如何对返回的行排序。它根据连接类型以及存储排序键值和匹配条件的全部行的行指针来排序全部行。
`Using index`	列数据是从仅仅使用了索引中的信息而没有读取实际的行动的表返回的，这发生在对表的全部的请求列都是同一个索引的部分的时候。
`Using temporary`	看到这个的时候，查询需要优化了。这里，MySQL需要创建一个临时表来存储结果，这通常发生在对不同的列集进行`ORDER BY`上，而不是`GROUP BY`上。
`Where used`	使用了`WHERE`从句来限制哪些行将与下一张表匹配或者是返回给用户。如果不想返回表中的全部行，并且连接类型`ALL`或`index`，这就会发生，或者是查询有问题不同连接类型的解释（按照效率高低的顺序排序）。
`system`	表只有一行 `system` 表。这是const连接类型的特殊情况。
`const`	表中的一个记录的最大值能够匹配这个查询（索引可以是主键或惟一索引）。因为只有一行，这个值实际就是常数，因为MySQL先读这个值然后把它当做常数来对待。
`eq_ref`	在连接中，MySQL在查询时，从前面的表中，对每一个记录的联合都从表中读取一个记录，它在查询使用了索引为主键或惟一键的全部时使用。
`ref`	这个连接类型只有在查询使用了不是惟一或主键的键或者是这些类型的部分（比如，利用最左边前缀）时发生。对于之前的表的每一个行联合，全部记录都将从表中读出。这个类型严重依赖于根据索引匹配的记录多少—越少越好。
`range`	这个连接类型使用索引返回一个范围中的行，比如使用>或<查找东西时发生的情况。
`index`	这个连接类型对前面的表中的每一个记录联合进行完全扫描（比`ALL`更好，因为索引一般小于表数据）。
`ALL`	这个连接类型对于前面的每一个记录联合进行完全扫描，这一般比较糟糕，应该尽量避免。

4. 案例- db5 问题排查

问题描述：

腾讯云查询 db5 数据库监控，cpu 一直呈锯齿状，如图：

问题分析：

初步怀疑是某些慢查询 SQL 导致的，于是去查看慢查询日志，发现确实大量同一条慢查询 SQL 在间隔执行

# Query_time: 1.612797  Lock_time: 0.000072 Rows_sent: 1  Rows_examined: 353335
SET timestamp=1565712839;
select count(distinct user_id) as cnt from body_user_plan where plan_id=9;

于是进行了优化，采用定时任务在 slave 上更新人数。优化上线后，慢查询日志减少了大半

之后观察监控，发现 CPU 监控曲线并没有明显效果。

又仔细观察了下监控，发现曲线很有规律：每半个小时会有一次 CPU 飙升，而且时间点很固定。

怀疑是某个定时任务在执行，于是蹲点排查，登录 mysql 客户端，使用 show full processlist; 或

select * from information_schema.processlist; 可查看正在执行的进程

观察到如下数据：

master >select * from information_schema.processlist where Command != 'Sleep' order by Time desc \G;
*************************** 1. row ***************************
     ID: 53670513
   USER: yuedong
   HOST: 10.104.25.120:38146
     DB: sport
COMMAND: Query
   TIME: 0
  STATE: executing
   INFO: select * from information_schema.processlist where Command != 'Sleep' order by Time desc
*************************** 2. row ***************************
     ID: 53699030
   USER: yuedong
   HOST: 10.104.11.9:59168
     DB: sport
COMMAND: Query
   TIME: 0
  STATE: updating
   INFO: update runner_top_step set city='苏州市' ,province='江苏省',district='吴江区',longitude=120.648500 ,latitude=31.185800  where user_id=129759183
2 rows in set (0.01 sec)

master >select * from information_schema.processlist where Command != 'Sleep' order by Time desc \G;
*************************** 1. row ***************************
     ID: 53670513
   USER: yuedong
   HOST: 10.104.25.120:38146
     DB: sport
COMMAND: Query
   TIME: 0
  STATE: executing
   INFO: select * from information_schema.processlist where Command != 'Sleep' order by Time desc
*************************** 2. row ***************************
     ID: 52965597
   USER: yuedong
   HOST: 10.104.59.41:50313
     DB: sport
COMMAND: Query
   TIME: 0
  STATE: statistics
   INFO: select circle_id,circle_status from circle_top_user_info
        where user_id=175746353 and status=0   limit 1
*************************** 3. row ***************************
     ID: 53699030
   USER: yuedong
   HOST: 10.104.11.9:59168
     DB: sport
COMMAND: Query
   TIME: 0
  STATE: System lock
   INFO: update runner_top_step set city='珠海市' ,province='广东省',district='香洲区',longitude=113.567000 ,latitude=22.267200  where user_id=161118311
3 rows in set (0.01 sec)

发现有大量表 runner_top_step的 update 操作。

查找发现是update_user_city.py文件里的 SQL，查看执行的脚本，发现确实是半小时执行一次，每次有大量的数据执行 update 操作

暂时注释掉 crontab 任务，观察 db5 情况：

可以看到平稳了许多，因此可以验证猜想。

排查到此结束，下一步就需要根据业务逻辑优化脚本的执行了。

关注微信公众账号「曹当家的」，订阅最新文章推送