一条MySQL报警的分析思路

这是学习笔记的第 1903 篇文章

今天带着同事一起分析了一个常见的MySQL慢日志报警，从分析的过程希望带给大家一些启示和反思。

报警信息类似：

PROBLEM P5 Endpoint:xxxx Metric:mysql.slow_queries Tags:idc=IDC1,port=4306,service=test diff(#1): 335>300 Note:[[warning]SQL语句执行效率慢] Max:3, .....

看到这条报警信息，可以明确一个任务，此时数据库中存在大量的慢日志，条数为335，超出了阈值设置的300

当然打开日志来分析的时候，会发现比想象的要复杂一些，因为慢日志文件可能有几百兆甚至更大，要分析整个文件显然是不可行的，所以我们需要过滤条件，把慢日志限定在一个较小的范围内来分析。

这里我们可以使用mysqldumpslow来做一个简单的分析，推荐更好的一款工具是pt-query-digest。

如下是慢日志的头部：

可以明显看到在1分钟的时间里SQL执行的整体情况，1分钟内有400多的SQL执行。但是仔细看指标“Exec time”会有一个明显的问题，那就是这个时长指标其实很低，总数才881ms,显然是不符合我们理解中的慢日志阈值的。

所以我们可以得到一个基本的印象，这个指标是和一个慢日志相关的参数：log_queries_not_using_indexes 相关，这个参数意思是如果SQL没有使用索引则会计入慢日志。

为了做进一步验证，我们往下看profile.

看profile信息的时候我们要按照重点来把握，即那些明显的性能SQL占比通常很高。如果检查前两个表会发现，根据现在的条件，这两条SQL的where条件部分是没有相关的索引的。

第一个SQL有点意思。

UPDATE SELECT dic_push_dao_assistant tem_selectAssDAO。。。

这是什么意思，我们可以详细的Query ID的解析来得到。对于update语句会转义成等价的select语句

update `dic_push_dao_assistant`
    set `state` = 1
    where `id` in 
    (
select `id`
        from `tem_selectAssDAO`
    )\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  `state` = 1 from `dic_push_dao_assistant` where  `id` in 
    (
select `id`
        from `tem_selectAssDAO`
    )\G

当然这个语句本身是有些粗糙，完全可以进一步优化。

我们再分析一下第2条SQL，问题是很明显的，即相关的SQL缺少索引而走了全表扫描。

但是建议还是做下补充，可能这些信息是在慢日志之外，就是建表语句：

从这里我们可以清晰的看出，这个表只有2190条记录，目前的扫描基本就是少数几个页就搞定了，但是自增列已经到了1000万左右，可以看出这个表的变更是极为频繁的，那么是否存在碎片呢。验证的方式我们可以直接查看对应的物理文件，可以看到2000条记录大概占用了20M左右的空间，这能不能说明有碎片呢。

# ll *cccd*

-rw-r----- 1 mysql mysql 70494 Nov 20 09:37 dic_fsm_cccd_info.frm

-rw-r----- 1 mysql mysql 26214400 Feb 27 17:50 dic_fsm_cccd_info.ibd

验证方式其实也不难，我们在另外一个库中模拟创建一个表补充数据即可，大概是10M左右。

# ll *cccd*

-rw-r----- 1 mysql mysql 70494 Feb 27 23:47 dic_fsm_cccd_info.frm

-rw-r----- 1 mysql mysql 10485760 Feb 27 23:48 dic_fsm_cccd_info.ibd

所以目前来看这个表是存在碎片的，说明大量的数据是写入了库中，然后很可能做了delete操作，导致数据总量变化不大，按照这种方式是存在隐患的。

从自增列来看，很可能数据会出现较大的增长，就会导致这个操作马上成为瓶颈，这条SQL一分钟执行了144次，算是比较频繁了,所以从目前的情况来看，这个表很可能成为性能的瓶颈，所以需要建议业务评估添加相关的索引。而之前根据业务的反馈，说这个库经常会有一些操作的延迟，也不难理解了。

我们在这里处理应该得出什么结论呢？

1）关闭参数log_queries_not_using_indexes

2）对相关的表进行分析，根据条件和频率创建相应的索引

其实到了这里，我们的分析还是不够深入，我们可以发掘出更多的信息，那就是可以提供给业务方一个更全面的信息列表，比如那些表中的索引是冗余索引，那些表走了全表扫描需要考虑添加索引。

这里需要正确引用sys schema,比如：

通过如上的信息可以发现我们需要重点考虑前面的几个表，走了全表扫描，产生了较大的延迟。

而稍后的解决方法，其实是通过对于业务的反馈优化，在业务添加了相关索引之后，还是建议打开参数：log_queries_not_using_indexes ，这对于一些业务场景的监控其实也是有效的。

如此一来，我们对慢日志的分析也告一段落，如果对于每条报警信息我们都认真对待，其实相应技术能力的提升也会很快。

其实行业里有一个常见的“伪需求“，就是开发同学经常需要关注慢日志，从工作的角色和分工来看，他们得到慢日志之后的分析和处理常常和问题的本质相左，换句话说，他们得到慢日志，是希望通过分析日志来发现一些明显的性能问题，通过这种信息检索的方式，来快速定位问题，但是实际上得到日志之后的分析结果是不可控的，可能10分钟，可能分析不出来。

而这个工作其实是应该作为运维的前置工作来完成的，既然开发对于慢日志的处理不专业，势必需要DBA来提供专业的建议，而如果我们能够通过一种透明自助的方式来提供分析和有效建议，对于开发同学来说，其实他们需要的不是慢日志，而是你的数据服务能力。