下班前的一个CPU负载过高问题

Nov,2019

今天是星期一，也是双十一，问了一圈周边的人，好像没有买东西的居多，大家都是不知道该买啥好，看来像我一样的老年人变多了，工作了一天，累了，写完早点休息了。。。

下班前的一个CPU负载过高问题

背景介绍：

今天双十一，公司的某个业务在7:00钟有个活动。

问题现象：

下午大概6点40下班的时候，服务器开始频繁报警，报警的内容是"存在未使用索引的慢日志"。

7:00前几分钟，服务器开始出现卡顿，查看CPU使用率100%，每个核都是100%左右。

解决的过程：

第一阶段：

6:40查看监控，发现CPU的使用率已经有点高了，但是没有到达100%，大概60%~70%左右。登录到服务器上看了一眼，进入到慢日志的目录，使用tail -f的命令查看了一下慢日志的文件，发现刷新的速度非常快，经过分析，10分钟的时间内已经出现了2个G的慢日志。

到这里，我推测是由于慢日志的报警比较多，导致CPU要不停的进行处理，并进行大量的IO操作，于是先暂时关闭了没有使用索引的慢日志，也就是设置参数log_queries_not_using_indexes的值为off，这个参数是MySQL用来控制是否将未使用索引的SQL记录到慢日志文件中的。关闭这个参数，那么慢日志中的记录就只包含查询超过设置的时间阈值的SQL。

经过关闭这个日志，慢日志的数量增长明显减少，CPU的压力也瞬间下来。一切恢复正常，整个过程持续时间大概10分钟左右。

询问业务方为何慢日志的数量那么多，最终得到的反馈是业务方之前使用了一个工具，会自动生成相关表的索引，这次换了个工具，没有了自动生成表索引的功能，每张表只有一个主键，但是在查询的过程中，会查询到表中的一些字段。

由于牵扯的表比较多，表的数据量也不是特别大，马上又到了活动的时间，所以就没有临时在线上做变更，。到这里，问题已经比较明显了，此处已经埋下了祸根。

第二阶段：

7:00前几分钟，大概06:58分左右，收到业务方反馈，前段页面刷新速度非常慢，应用服务入口点击进去之后出现卡顿。于是先查看监控，发现CPU使用率已经又开始上升到60%左右，并且一直在往上升。登录服务器查看CPU真实使用率，已经上升到90%左右，服务器又出现明显卡顿。

接下来的处理过程，分为两步，第一、DBA查询相关数据库的问题，第二、业务方开始扩充应用服务器(这一步我们无法干预)，说说DBA方向问题排查的过程。

1、首先查看了数据库的buffer pool的值，buffer pool的值是4G，看着问题不大；

2、磁盘空间空余很多，也排除磁盘问题。

3、重新审视当前的状况，还是把目标定位在了慢查询上，因为上一步仅仅是关掉了慢查询的一个报警机制，没有从本质上解决慢查询的问题。

4、从slowquery.log中查询最近几分钟的慢查询，大概有那么6~7类吧，和业务方约定暂时停服。停服之后逐一解决，使用explain查看执行计划，并添加相关索引，由于涉及的慢查询SQL过多，处理了那么几类之后，耗时大概20分钟左右吧，此时已经延误了正常的活动时间，所以准备先开服看看情况有没有缓解。

5、添加完索引之后，重新启动应用服务，发现这个CPU的使用率有所下降，但是还是比较高，没有彻底的降下来，页面还是刷不进去。

6、再次停服、使用show processlist查看当前的数据库连接，发现连接中有大量的select count(1) from tbl_name where col_name=xxx;这类SQL，所有的线程的状态都是Sending data；据此判断，应该是这个表tbl_name的索引出现了问题，导致where条件没有走索引，出现了全表扫描的情况。

7、于是同事立马在上面添加了相关的索引，添加完索引之后，问题立即得到了彻底的解决，监控的数据也下来了，CPU的使用率下降到20%以内。

8、查看这个表tbl_name的记录数，大概有13w条左右吧，相当于这条SQL每次都要过滤这13w的记录，然后从中取出想要的几条，由于sending data包含收集+发送两个步骤，这一步需要耗费一定的时间，于是所有的SQL都卡在这一步了，瞬间打满了所有的CPU。

时间关系，先简单记录一下过程，后面好好分析原因。