转载信息:
作者: 小码农叔叔
来源: CSDN
原文链接: SpringBoot线上服务假死, CPU内存正常, 什么情况？
版权声明: 本文为 CSDN 博主「小码农叔叔」的原创文章, 遵循 CC 4.0 BY-SA 版权协议, 转载请附上原文出处链接及本声明。
1 背景
开发小伙伴都知道线上服务挂掉, 基本都是因为 CPU 或者内存不足, 出现 GC 频繁 OOM 之类的情况。本篇文章区别以上的情况给小伙伴们带来不一样的服务挂掉。
还记得哔哩哔哩 713 事故中那场诡计多端的 0 吗？
对就是这个0, 和本次事故没关系, 但深受启发。
2 问题排查
老规矩在集群环境中同一个服务几个节点无响应。如不及时解决会可能形成雪崩效应。
优先查看服务日志是否有报错, 礼貌习惯性查看服务 CPU 及内存情况。先复习下, 若服务无报错。CPU 或内存出现异常, 按如下步骤排查。
2.1 常规排查
1、 查看服务进程中线程情况
top -H -p pid
或
ps -mp pid -o THREAD,tid,time2、 查看系统异常线程 16 进制
printf “%x\n” nid3、查看异常线程堆栈信息
jstack pid | grep number4、查看占用最大内存对象前一百
jmap -histo pid|head -1005、导出到文件
jstack -l PID >> a.log6、或 dump 信息使用工具 Mat 或 JProfiler 查看
jmap -dump:live,format=b,file=/dump.bin pid经过上面一通手法操作, 足以解决此类常规报错了, 通常大多是原因各种循环递归、或数据库慢查询等。
2.2 Mat 使用
在 MAT 中, 会有两种大小表示：
Shallow Size：表示对象自身占用的内存大小, 不包括它引用的对象。
Retained size：当前对象内存大小 + 当前对象直接或间接引用的对象大小, 全部的总和, 简单理解, 就是当前对象被 GC 后, 总共能释放的内存大小。
Histogram 视图
以 Class Name 为维度, 分别展示各个类的对象数量。它默认是以 byte 为单位的
要显示让单位展示出来, 点击 Window -> Preferences 选择最后一项, 点击 Apply and Close。
再重新打开 Histogram 视图, 就会生效了。
Leak Suspects
报表很直观地展现了一个饼图, 图中颜色深的部分表示可能存在内存泄漏的嫌疑。
通过这个指标可以快速定位内存泄漏地方出现在哪个类方法里的哪行代码。
2.3 本次问题排查
1、 信息收集分析
因服务健康监测无响应, CPU 及内存情况正常, 直接查看堆栈信息, 看看线程都在干什么
jstack -l PID >> a.logJstack 的输出中, 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();
}3 问题复现
按照以上信息在多活环境复现。因线程被打满且都在等待导致监控检查无响应。
Tomcat 线程被打满:
Tomcat 默认参数:
server.tomcat.max-threads=200最大连接数默认是 10000
server.tomcat.max-connections=10000等待队列长度, 默认 100。
server.tomcat.accept-count=100最小工作空闲线程数, 默认 10。
server.tomcat.min-spare-threads=100Druid 连接池的默认参数如下:
Druid 连接池的配置参数如下:
| 属性 | 说明 | 建议值 |
|---|---|---|
| username | 登录数据库的用户名 | |
| password | 登录数据库的用户密码 | |
| initialSize | 默认 0, 启动程序时, 在连接池中初始化多少个连接 | 10-50 足够 |
| maxActive | 默认 8, 连接池中最多支持多少个活动会话 | |
| maxWait | 默认 -1, 程序向连接池中请求连接时, 超过 maxWait 的值后, 认为本次请求失败, 即连接池, 没有可用连接, 单位毫秒, 设置 -1 时表示无限等待 | 100 |
| minEvictableldleTimeMillis | 池中某个连接的空闲时长达到 N 毫秒后, 连接池在下次检查空闲连接时, 将回收该连接, 要小于防火墙超时设置 net.netflter.nf_conntrack_tcp_timeout_established | 见说明部分 |
| timeBetweenEvictionRunsMillis | 检查空闲连接的频率, 单位毫秒, 非正整数时表示不进行检查 | |
| keepAlive | 程序没有 close 连接且空闲时长超过 minEvictableldleTimeMillis, 则会执, 行validationQuery 指定的 SQL, 以保证该程序连接不会池 kill 掉, 其范围不超过 minldle 指定的连接个数 | true |
| minidle | 默认 8, 回收空闲连接时, 将保证至少有 minldle 个连接 | 与 initialSize 相同 |
| removeAbandoned | 要求程序从池中 get 到连接后, N 秒后必须 close, 否则 druid 会强制回收该连接, 不管该连接中是活动还是空闲, 以防止进程不会进行 close 而霸占连接 | false, 当发现程序有未正常 close 连接时设置为 true |
| removeAbandonedTimeout | 设置 druid 强制回收连接的时限, 当程序从池中 get 到连接开始算起, 超过此值后, druid 将强制回收该连接, 单位秒 | 应大于业务运行最长时间 |
| logAbandoned | 当 druid 强制回收连接后, 是否将 stack trace 记录到日志中 | true |
| testWhileldle | 当程序请求连接, 池在分配连接时, 是否先检查该连接是否有效。（高效） | true |
| validationQuery | 检查池中的连接是否仍可用的 SQL 语句, druid 会连接到数据库执行该 SQL, 如果正常返回, 则表示连接可用, 否则表示连接不可用 | |
| testOnBorrow | 程序申请连接时, 进行连接有效性检查（低效, 影响性能） | false |
| testOnReturn | 程序返还连接时, 进行连接有效性检查（低效, 影响性能） | false |
| poolPreparedStatements | 缓存通过以下两个方法发起的 SQL: public PreparedStatement prepareStatement(String sql) 和 public PreparedStatement prepareStatement（String sql, int resultSetType, int resultSetConcurrency） | true |
| maxPoolPrepareStatementPerConnectionSize | 每个连接最多缓存多少个 SQL | 20 |
| filters | 这里配置的是插件, 常用的插件有: 监控统计: flter: stat, 日志监控: flter: log4j 或者 slf4j, 防御 SQL 注入: flter: wall | stat, wall, slf4j |
| connectProperties | 连接属性。比如设置一些连接池統计方面的配置。druid.stat.mergeSql=true;druid.stat.slowSqIMillis=5000 比如设置一些数据库连接庽性 |
4 解决
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\=50002、异常及时关闭连接
sqlSession.close();
