此博客为记录今天在线上发现分布式缓存服务的一个BUG的过程与相关解决。
问题:
收到线上服务报警,有更新失败的操作,与是上线环境查看相应日志(服务由于并发的原因,偶尔性失败,没有影响)
但是发现服务所占资源比平时高一些,进行了一些排查!
确认服务线程:
top –c 指令查看如下:
进程13603服务,使用CPU与MEM都比较大,保存其相应的堆栈信息快照:
jstack 13603 > test.log
由于进程比较多,需要查看当前服务所占资源比较高的PID。
top –Hs指定如下显示:
发现13729线程所占资源一直在90%以上,奇怪了。有什么线程会一直占用如此高的CPU。
通过本机的计算器快速查出13729对应的十六进制为:35a1
然后less test.log日志,查看35a1线程的堆栈信息,发现正在运行的a.run线程(a为问题线程的代号)。
此时大概发现问题在哪个线程上了,a线程是我们分布式redis服务的一个维护线程,正常来说,此线程应该一直是在wait状态,怎么会在运行状态,且一直运行。
仔细查看此线程相关逻辑,逻辑本身没有问题,但是如果会导致死循环的话,只有整个服务reload时并且此服务相关配制没有修改。
此时查看线上相关BUG日志,确定在前几天有buffer reload的相关操作,自己也记起来有这么一次事件。
结合以上环境,稍微整理下思路,发现这是reload服务,此维护进程没有reInited引起的BUG,由于reload此操作比较少,且出现影响后,由于维护线程也是单线程服务,所以BUG运行了很长时间了。
之所以会出现这样的BUG,也是不应该。需要好好检查!
以上为一次线上BUG的查证与相应的解决的流程,记录下,希望对别人也有点帮忙,如何去发现问题,并验证问题。
(ps:对于通过jstack能解决的问题,是比较幸运的,怕的是有些问题jstack都定位不到)