SpringBoot线上服务假死解决，CPU内存正常

太过爱你忘了你带给我的痛 2024-04-01 16:12 31阅读 0赞

## 背景 ##

> 开发小伙伴都知道线上服务挂掉，基本都是因为cpu或者内存不足，出现GC频繁OOM之类的情况。本篇文章区别以上的情况给小伙伴们  
> 带来不一样的服务挂掉。

还记得哔哩哔哩713事故中那场**诡计多端的0**吗？  
![在这里插入图片描述][9ffd4d23089647208d4f907bc4434fd7.png]  
对就是这个0，和本次事故没关系，但三省同学深受学习。  
相关阅读：  
[2021.07.13 我们是这样崩的][2021.07.13]  
[线上服务假死解决][Link 1]  
[IDEA插件JProfiler安装使用][IDEA_JProfiler]　  
[Tomcat10下载安装及各个线程作用详解][Tomcat10]

## 问题排查 ##

老规矩在集群环境中同一个服务几个节点无响应。如不及时解决会可能形成雪崩效应。  
优先查看服务日志是否有报错，礼貌习惯性查看服务cpu及内存情况。先复习下，若服务无报错。cpu或内存出现异常,按如下步骤排查。

### 常规排查 ###

#### **1、查看服务进程中线程情况** ####

top -H -p pid
    或
    ps -mp pid -o THREAD,tid,time

#### 2、查看系统异常线程16进制 ####

printf “%x\n” nid

#### 3、查看异常线程堆栈信息 ####

jstack pid | grep number

查看占用最大内存对象前一百

jmap -histo pid|head -100

导出到文件

jstack -l PID >> a.log

或dump信息使用工具Mat或JProfiler查看

jmap -dump:live,format=b,file=/dump.bin pid

经过上面一通手法操作，足以解决此类常规报错了，通常大多是原因各种循环递归、或数据库慢查询等。

#### Mat使用 ####

在MAT中，会有两种大小表示：

> **Shallow Size：表示对象自身占用的内存大小，不包括它引用的对象。  
> Retained size：当前对象内存大小+当前对象直接或间接引用的对象大小，全部的总和，简单理解，就是当前对象被GC后，总共能释放的内存大小。**

**Histogram视图**

> 以Class Name为维度，分别展示各个类的对象数量。它默认是以byte为单位的，

![请添加图片描述][d3150869d6a64e4fb614287f19766f94.jpeg]

要显示让单位展示出来，点击**Window->Preferences**选择最后一项，点击**Apply and Close**  
再重新打开Histogram视图，就会生效了。  
![请添加图片描述][d0e871fa8c654bdc8de267a07557a2c0.jpeg]

**Leak Suspects**

> 报表很直观地展现了一个饼图，图中颜色深的部分表示可能存在内存泄漏的嫌疑。

通过这个指标可以快速定位内存泄漏地方出现在哪个类方法里的哪行代码。

### 本次问题排查 ###

#### 1、 信息收集分析 ####

因服务健康监测无响应，cpu及内存情况正常，直接查看堆栈信息，看看线程都在干什么

jstack -l PID >> a.log

Jstack的输出中，Java线程状态主要是以下几种：

> RUNNABLE 线程运行中或I/O等待
> 
> BLOCKED 线程在等待monitor锁(synchronized关键字)
> 
> TIMED\_WAITING 线程在等待唤醒，但设置了时限
> 
> WAITING 线程在无限等待唤醒

发现都是WAITING线程。

"http-nio-8888-exec-6666" #8833 daemon prio=5 os_prio=0 tid=0x00001f2f0016e100 nid=0x667d waiting on condition [0x00002f1de3c5200]
    java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000007156a29c8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1897)
    at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1458)
    at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1253)
    at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4619)
    at com.alibaba.druid.filter.stat.StatFilter.dataSource_getConnection(StatFilter.java:680)
    at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4615)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1231)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1223)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:90)
    at com.baomidou.dynamic.datasource.ds.ItemDataSource.getConnection(ItemDataSource.java:56)
    at com.baomidou.dynamic.datasource.ds.AbstractRoutingDataSource.getConnection(AbstractRoutingDataSource.java:48)
    at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
    at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:82)
    at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:68)
    at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336)
    at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:84)
    at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)
    at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
    at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
    at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
    at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:143)
    at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
    at com.sun.proxy.$Proxy571.query(Unknown Source)

### 2、定位关键信息，追踪源代码 ###

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
      at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1897)

DruidConnectionHolder takeLast() throws InterruptedException, SQLException {
        
      try {
        
      while (poolingCount == 0) {
        
      emptySignal(); // send signal to CreateThread create connection
    
                    if (failFast && isFailContinuous()) {
        
                        throw new DataSourceNotAvailableException(createError);
                    }
    
                    notEmptyWaitThreadCount++;
                    if (notEmptyWaitThreadCount > notEmptyWaitThreadPeak) {
        
                        notEmptyWaitThreadPeak = notEmptyWaitThreadCount;
                    }
                    try {
        
                        // 数据库的连接都没有释放且被占用，连接池中无可用连接，导致请求被阻塞
                        notEmpty.await(); // signal by recycle or creator
                    } finally {
        
                        notEmptyWaitThreadCount--;
                    }
                    notEmptyWaitCount++;
    
                    if (!enable) {
        
                        connectErrorCountUpdater.incrementAndGet(this);
                        throw new DataSourceDisableException();
                    }
                }
            } catch (InterruptedException ie) {
        
                notEmpty.signal(); // propagate to non-interrupted thread
                notEmptySignalCount++;
                throw ie;
            }
    
            decrementPoolingCount();
            DruidConnectionHolder last = connections[poolingCount];
            connections[poolingCount] = null;
    
            return last;
      }

结合日志报错定位到问题代码。因报错可用连接没有正常释放，导致一直await卡死。  
问题代码如下：

try {
        
    	  SqlSession sqlSession = sqlSessionFactory.openSession(ExecutorType.BATCH);
    	  TestMapper mapper = sqlSession.getMapper(TestMapper.class);
    	  mapper.insetList(list);
    	  sqlSession.flushStatements();
      } catch (Exception e) {
        
      	  e.printStackTrace();
      }

## 问题复现 ##

**按照以上信息在多活环境复现。因线程被打满且都在等待导致监控检查无响应。**

**tomcat线程被打满：**  
![在这里插入图片描述][d2d226f2758c4fd1bf09e0472c0163b0.png]

**tomcat默认参数：**

> 最大工作线程数，默认200。  
> server.tomcat.max-threads=200  
> 最大连接数默认是10000  
> server.tomcat.max-connections=10000  
> 等待队列长度，默认100。  
> server.tomcat.accept-count=100
> 
> 最小工作空闲线程数，默认10。  
> server.tomcat.min-spare-threads=100

**Druid连接池的默认参数如下：**  
![请添加图片描述][b3b1562a33304a6e9263a26933fb5755.jpeg]  
**Druid连接池的配置参数如下：**

<table> 
 <thead> 
  <tr> 
   <th>属性</th> 
   <th>说明</th> 
   <th>建议值</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td>username</td> 
   <td>登录数据库的用户名</td> 
   <td></td> 
  </tr> 
  <tr> 
   <td>password</td> 
   <td>登录数据库的用户密码</td> 
   <td></td> 
  </tr> 
  <tr> 
   <td>initialSize</td> 
   <td>默认0，启动程序时，在连接池中初始化多少个连接</td> 
   <td>10-50足够</td> 
  </tr> 
  <tr> 
   <td>maxActive</td> 
   <td>默认8，连接池中最多支持多少个活动会话</td> 
   <td></td> 
  </tr> 
  <tr> 
   <td>maxWait</td> 
   <td>默认-1，程序向连接池中请求连接时,超过maxWait的值后，认为本次请求失败，即连接池， 没有可用连接，单位毫秒，设置-1时表示无限等待</td> 
   <td>100</td> 
  </tr> 
  <tr> 
   <td>minEvictableIdleTimeMillis</td> 
   <td>池中某个连接的空闲时长达到 N 毫秒后, 连接池在下次检查空闲连接时，将回收该连接,要小于防火墙超时设置 net.netfilter.nf_conntrack_tcp_timeout_established</td> 
   <td>见说明部分</td> 
  </tr> 
  <tr> 
   <td>timeBetweenEvictionRunsMillis</td> 
   <td> 检查空闲连接的频率，单位毫秒, 非正整数时表示不进行检查</td> 
   <td></td> 
  </tr> 
  <tr> 
   <td>keepAlive</td> 
   <td>程序没有close连接且空闲时长超过 minEvictableIdleTimeMillis,则会执 行validationQuery指定的SQL,以保证该程序连接不会池kill掉,其范围不超过minIdle指定的连接个数</td> 
   <td>true</td> 
  </tr> 
  <tr> 
   <td>minIdle</td> 
   <td>默认8，回收空闲连接时，将保证至少有minIdle个连接.</td> 
   <td>与initialSize相同</td> 
  </tr> 
  <tr> 
   <td>removeAbandoned</td> 
   <td>要求程序从池中get到连接后, N 秒后必须close,否则druid 会强制回收该连接,不管该连接中是活动还是空闲, 以防止进程不会进行close而霸占连接。</td> 
   <td>false,当发现程序有未正常close连接时设置为true</td> 
  </tr> 
  <tr> 
   <td>removeAbandonedTimeout</td> 
   <td>设置druid 强制回收连接的时限，当程序从池中get到连接开始算起，超过此 值后，druid将强制回收该连接，单位秒。</td> 
   <td>应大于业务运行最长时间</td> 
  </tr> 
  <tr> 
   <td>logAbandoned</td> 
   <td>当druid强制回收连接后，是否将stack trace 记录到日志中</td> 
   <td>true</td> 
  </tr> 
  <tr> 
   <td>testWhileIdle</td> 
   <td>当程序请求连接，池在分配连接时，是否先检查该连接是否有效。(高效)</td> 
   <td>true</td> 
  </tr> 
  <tr> 
   <td>validationQuery</td> 
   <td>检查池中的连接是否仍可用的 SQL 语句,drui会连接到数据库执行该SQL, 如果 正常返回，则表示连接可用，否则表示连接不可用</td> 
   <td></td> 
  </tr> 
  <tr> 
   <td>testOnBorrow</td> 
   <td>程序申请连接时,进行连接有效性检查（低效，影响性能）</td> 
   <td>false</td> 
  </tr> 
  <tr> 
   <td>testOnReturn</td> 
   <td>程序返还连接时,进行连接有效性检查（低效，影响性能）</td> 
   <td>false</td> 
  </tr> 
  <tr> 
   <td>poolPreparedStatements</td> 
   <td>缓存通过以下两个方法发起的SQL: public PreparedStatement prepareStatement(String sql) public PreparedStatement prepareStatement(String sql,int resultSetType, int resultSetConcurrency)</td> 
   <td>true</td> 
  </tr> 
  <tr> 
   <td>maxPoolPrepareStatementPerConnectionSize</td> 
   <td>每个连接最多缓存多少个SQL</td> 
   <td>20</td> 
  </tr> 
  <tr> 
   <td>filters</td> 
   <td>这里配置的是插件,常用的插件有:监控统计: filter:stat 日志监控: filter:log4j 或者 slf4j 防御SQL注入: filter:wall</td> 
   <td>stat,wall,slf4j</td> 
  </tr> 
  <tr> 
   <td>connectProperties</td> 
   <td>连接属性。比如设置一些连接池统计方面的配置。 druid.stat.mergeSql=true;druid.stat.slowSqlMillis=5000 比如设置一些数据库连接属性</td> 
   <td></td> 
  </tr> 
 </tbody> 
</table>

## 解决 ##

### 1、Druid连接池的配置超时参数 ###

spring: 
      redis:
        host: localhost
        port: 6379
        password: 
      datasource:
        druid:
          stat-view-servlet:
            enabled: true
            loginUsername: admin
            loginPassword: 123456
        dynamic:
          druid:
            initial-size: 5
            min-idle: 5
            maxActive: 20
            maxWait: 60000
            timeBetweenEvictionRunsMillis: 60000
            minEvictableIdleTimeMillis: 300000
            validationQuery: SELECT 1 FROM DUAL
            testWhileIdle: true
            testOnBorrow: false
            testOnReturn: false
            poolPreparedStatements: true
            maxPoolPreparedStatementPerConnectionSize: 20
            filters: stat,slf4j,wall
            connectionProperties: druid.stat.mergeSql\=true;druid.stat.slowSqlMillis\=5000

### 2、异常及时关闭连接 ###

sqlSession.close();

[9ffd4d23089647208d4f907bc4434fd7.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/04/01/6f8f5843d11840dcb2bb57d60ad84d1d.png
[2021.07.13]: https://mp.weixin.qq.com/s/nGtC5lBX_Iaj57HIdXq3Qg
[Link 1]: http://t.csdn.cn/LBO1L
[IDEA_JProfiler]: http://t.csdn.cn/uQjaa
[Tomcat10]: http://t.csdn.cn/1I5XH
[d3150869d6a64e4fb614287f19766f94.jpeg]: https://image.dandelioncloud.cn/pgy_files/images/2024/04/01/0336e9d1bc9f4688b3efedf2f3e63c71.jpeg
[d0e871fa8c654bdc8de267a07557a2c0.jpeg]: https://image.dandelioncloud.cn/pgy_files/images/2024/04/01/3d43a7d8f4c7414eb7293f8f0e8fb35c.jpeg
[d2d226f2758c4fd1bf09e0472c0163b0.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/04/01/3429cfe835334d4e9386a88ff294b7b9.png
[b3b1562a33304a6e9263a26933fb5755.jpeg]: https://image.dandelioncloud.cn/pgy_files/images/2024/04/01/6f0ffd15f2d64eebbd99147787c7072f.jpeg