记一次生产环境CPU飙升100%的排查经历

爱被打了一巴掌 2023-07-11 05:52 2阅读 0赞

## 一、前言 ##

是这样的，我的项目是使用传统的`Spring`\+`SpringMVC`\+`Mybatis`架构的，有`PC`端后台管理系统，也有微信端`H5`网页，也就是一个微信公众号项目；项目部署采用`Windows Server2008`服务器，数据库使用·Mysql5.7·，最开始运行都非常的稳定，自动上线了一款功能：`“微信打卡”` 之后，规定每天只能打卡一次，并且规定时间点为`6:00-9:00` 这个时间段才能打卡，不在这个时间段则无法打卡，我的微信公众号用户有`10`万多，具体每天打卡量没有去具体的统计。

## 二、并发场景下产生的现象 ##

在`6:00-9:00` 这个时间段内，大量用户集中打卡，难免产生并发，服务器`CPU`持续飙升为`100%`，远程连接`Windows`服务器，鼠标卡死，无法操作，感觉整个系统瘫痪了，起初是以为生成的日志文件过多，于是每个月定时去删除上一个月的日志，最后发现不是，除了在`6:00-9:00` 这个时间段内外的其他时间，访问微信公众号H5网页，非常的流畅和稳定，页面响应也非常的快，只有在这个时间段内大量页面卡死，等待服务器响应，于是就有了后面的三次排查经历；

## 三、排查经历 ##

#### 1. 第1次CPU飙升100%的排查经历(未定位到核心) ####

第一次遇到这个问题，查看日志： `Data source rejected establishment of connection, message from server : "Too many connections"` 大概意思是连接数太多，于是我调整了`mysql`默认的连接数，调整至`500`，之前是`150`；

> 并 发量过高，请求数过多，导致mysql连接数超过了最大连接数的阀值，现在是150，我先把阀值由150加到500

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70]  
但是这个不是核心根本问题，于是开始了第二次排查

#### 2. 第2次CPU飙升100%的排查经历(未定位到核心) ####

异常日志如下图：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 1]  
通过查询资料，网上说是连接池的问题，修改对空闲连接池回收的时间，最开始默认为每3分钟回收一次，最后修改为没30分钟回收一次

<property name="removeAbandonedTimeout" value="180" />

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 2]

#### 3. 第3次CPU飙升100%的排查经历(SQL语句优化) ####

这次，服务器整个功能瘫痪了，点击都无法响应，大量请求阻塞，于是又开始了第三次的排次，这次排查以先定位慢查询为思路，然后挑出哪些慢查询`SQL`语句存在问题，然后对`SQL`语句进行优化处理。

*  **执行查询计划：**

show full processlist; -- 列出全部SQL执行计划

查出有大量的SQL存在慢查询等待，`state`一直为`Sending data`  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 3]  
**参数说明：**

<table> 
 <thead> 
  <tr> 
   <th>字段</th> 
   <th>解释</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td>id</td> 
   <td>ID标识，要kill一个语句的时候很有用</td> 
  </tr> 
  <tr> 
   <td>use</td> 
   <td>当前连接用户</td> 
  </tr> 
  <tr> 
   <td>host</td> 
   <td>显示这个连接从哪个ip的哪个端口上发出</td> 
  </tr> 
  <tr> 
   <td>db</td> 
   <td>链接哪个数据库</td> 
  </tr> 
  <tr> 
   <td>command</td> 
   <td>连接状态，一般是休眠（sleep），查询（query），连接（connect）</td> 
  </tr> 
  <tr> 
   <td>time</td> 
   <td>连接持续时间，单位是秒</td> 
  </tr> 
  <tr> 
   <td>state</td> 
   <td>显示当前sql语句的状态</td> 
  </tr> 
  <tr> 
   <td>info</td> 
   <td>显示这个sql语句</td> 
  </tr> 
 </tbody> 
</table>

其中`state`的状态十分关键，下表列出`state`主要状态和描述，这里只列举常见的几个，详细请百度：

<table> 
 <thead> 
  <tr> 
   <th>字段</th> 
   <th>描述</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td>Locked</td> 
   <td>被其他查询锁住了</td> 
  </tr> 
  <tr> 
   <td>Sending data</td> 
   <td>正在处理SELECT查询的记录，同时正在把结果发送给客户端。</td> 
  </tr> 
  <tr> 
   <td></td> 
   <td></td> 
  </tr> 
  <tr> 
   <td>Sleeping</td> 
   <td>正在等待客户端发送新请求.</td> 
  </tr> 
 </tbody> 
</table>

*  **挑出具体的SQL语句执行执行计划EXPLAIN：**

EXPLAIN SELECT
    	f.nick_name AS nickName,
    	f.headimgurl AS headImgUrl,
    	f.open_id AS openId
    FROM
      t_member m
    LEFT JOIN t_follow f ON f.open_id = m.open_id WHERE m.green_card = '031011501705982345'
    AND f.del_flag = '0'
    AND m.del_flag = '0'

**t\_member** 表的索引是普通索引 ，索引名字为`member_openid_index`， 索引的字段为`open_id`  
**t\_follow** 表的索引是唯一索引 ， 索引名字为 `唯一`, 索引的字段为 `open_id`  
从下面的执行结果图可以看出，`t_follow`表的唯一索引并没有使用上，而是使用的全表扫描，那么这就找到问题的核心了，一是找出为什么两个表左链接时，其中一张表的唯一索引没有使用上； 二是如何让`t_follow`表的所有使用上，不去全表扫描。  
最后发现，光两张表连接字段加索引还不够，需要在m.green\_card上也加一个索引即可，我加了普通索引

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 4]  
再次执行执行计划，就使用了索引查询：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 5]

*  **执行查询计划：**

show full processlist; -- 列出全部SQL执行计划

数据库连接，都是空闲状态，等待客户端发送新的请求，没有产生慢查询的阻塞  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 6]

*  **执行计划字段说明：**

<table> 
 <thead> 
  <tr> 
   <th>字段</th> 
   <th>解释</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td>id</td> 
   <td>表示查询的类型</td> 
  </tr> 
  <tr> 
   <td>select_type</td> 
   <td>表示选择标识符</td> 
  </tr> 
  <tr> 
   <td>table</td> 
   <td>表示输出结果集的表</td> 
  </tr> 
  <tr> 
   <td>partitions</td> 
   <td>表示匹配的分区</td> 
  </tr> 
  <tr> 
   <td>type</td> 
   <td>表示表的连接类型</td> 
  </tr> 
  <tr> 
   <td>possible_keys</td> 
   <td>表示查询时可能使用的索引</td> 
  </tr> 
  <tr> 
   <td>key</td> 
   <td>表示查询时实际使用的索引</td> 
  </tr> 
  <tr> 
   <td>key_len</td> 
   <td>表示索引字段的长度</td> 
  </tr> 
  <tr> 
   <td>ref</td> 
   <td>表示列与索引的比较</td> 
  </tr> 
  <tr> 
   <td>rows</td> 
   <td>表示扫描出的行数(估算的行数)</td> 
  </tr> 
  <tr> 
   <td>filtered</td> 
   <td>表示按表条件过滤的行百分比</td> 
  </tr> 
  <tr> 
   <td>Extra</td> 
   <td>表示执行情况的描述和说明</td> 
  </tr> 
 </tbody> 
</table>

## 四、总结 ##

项目生产环境的数据库一定要建索引，这个非常重要，而且需要根据重要的SQL语句分析索引该不该建、建哪些字段、建什么类型的索引，这些工作不可以忽略，以后我也会注重这个环节；

## 五、参考 ##

1.  [Mysql left join不使用索引问题总结][Mysql left join]
2.  [查一次left join没有走索引以及原因][left join]

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70]: https://img-blog.csdnimg.cn/20200304121521587.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 1]: https://img-blog.csdnimg.cn/20200304122048434.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 2]: https://img-blog.csdnimg.cn/20200304122306268.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 3]: https://img-blog.csdnimg.cn/20200304122946198.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 4]: https://img-blog.csdnimg.cn/20200304123451796.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 5]: https://img-blog.csdnimg.cn/20200304133129524.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv_size_16_color_FFFFFF_t_70 6]: https://img-blog.csdnimg.cn/20200304133852308.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L1RoaW5raW5nY2Fv,size_16,color_FFFFFF,t_70
[Mysql left join]: https://blog.csdn.net/u012019209/article/details/102914832
[left join]: https://blog.csdn.net/qq_20009015/article/details/91405186