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

背景

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

还记得哔哩哔哩713事故中那场诡计多端的0吗？

对就是这个0，和本次事故没关系，但三省同学深受学习。
相关阅读：
2021.07.13 我们是这样崩的
线上服务假死解决
IDEA插件JProfiler安装使用　
Tomcat10下载安装及各个线程作用详解

问题排查

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

常规排查

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

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

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

printf “%x\n” nid
1

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

jstack pid | grep number
1

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

jmap -histo pid|head -100
1

导出到文件

jstack -l PID >> a.log
1

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

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

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

Mat使用

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

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

Histogram视图

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

要显示让单位展示出来，点击Window->Preferences选择最后一项，点击Apply and Close
再重新打开Histogram视图，就会生效了。

Leak Suspects

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

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

本次问题排查

1、 信息收集分析

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

jstack -l PID >> a.log
1

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)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30

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

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

  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;
  }
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38

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

  try {
	  SqlSession sqlSession = sqlSessionFactory.openSession(ExecutorType.BATCH);
	  TestMapper mapper = sqlSession.getMapper(TestMapper.class);
	  mapper.insetList(list);
	  sqlSession.flushStatements();
  } catch (Exception e) {
  	  e.printStackTrace();
  }
1
2
3
4
5
6
7
8

问题复现

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

tomcat线程被打满：

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连接池的默认参数如下：

Druid连接池的配置参数如下：

解决

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
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27

2、异常及时关闭连接

sqlSession.close();
1