记录:一次应用假死排查.md

记录:一次应用假死排查

起因:

最近几天,发现测试环境经常假死。复现需要很久的时间,一般得过一个晚上。

现象:

正常情况,应用会每隔几秒注册到Redis上。异常后发现Redis上没有注册信息,但是有一些其他的工作线程会有正常的工作信息输出。
代码逻辑为,新建一个线程,然后线程中会注册到Redis。
伪代码如下

1
2
3
4
5
6
7
Thread th = new Thread(){
while(true){
register();
// 一些业务处理
Thread.sleep();
}
}

这段假死的代码已经在线上运行了一年了,改动极少,按理来说应该很问题了,而且业务逻辑很简单。

排查:

第一反应,先看看CPU,内存等信息是否正常。经检查,服务器的CPU,内存并无异常。
然后使用 arthas 连接应用,看应用工作情况
dashboard如下
步骤
如图所示,gc、内存、CPU占用都极其正常。但是有大量 TIMED_WAITING 的线程。
使用 thead -b 未发现死锁的情况。

这时想到看一下我关注的线程到底在干嘛,堆栈信息如下
步骤
发现是在从 Redis 连接池获取 Connection。
但是一直在这里没有动静,没有超时。这里随后查看了配置,发现这里设置的是 -1,也就是永不超时。事实上这里设置超时时间也不能解决问题。
随后查看了Redis服务器的信息,发现也没有什么异常。
而且其他应用也都在使用这台Redis服务,所以推断还是应用的问题。在应用服务器使用 netstat 查看连接信息,发现有100个 redis 的连接处于 established。数量和我们配置的数量是匹配的。

内心OS:连接池获取连接一直阻塞,说明连接池没有就绪的连接,但是实际上已经创建到上限了,说明连接一直没有归还,难道有慢查询?但是从Redis服务端来看,并没有发现慢查询,而且我确定这里设置了超时时间3s。
暂时没有发现,但是我们能确定这次不是玄学问题,肯定和Redis连接池有关系。

我们是使用的 RedisTemplate,按理来说这种框架无数人验证过了,不应该会有连接使用完不归还的情况。

然后开始看源码,发现 RedisTemplate 大部分命令都是有释放的。
但是 scan 命令不会。
使用 scan 命令切记关闭 Cursor !!!,否则连接不会释放,导致异常(Could not get a resource from the pool)
事实上我们的代码也有调用 cursor.close() 方法,但是没有在finally 块中,然后中间如果抛出异常就没有运行 close 代码。到最后就出现了连接池耗尽,然后一直阻塞等待的假死现象。


本博客所有文章除特别声明外,均采用 CC BY-SA 4.0 协议 ,转载请注明出处!