1.问题出现场景
在接手项目后,发现原系统长连接项目的心跳机制,是在Channel注册后,加入到系统的定时任务,然后由服务端主动发起心跳检测。但重新定义线程池,单独执行心跳任务,而且需要每10秒执行一次,当连接数上来时,会因单纯的心跳任务把CPU打满。后面考虑到后端是使用Netty框架,每个Channel都会注册到EventGroup,考虑到可以在每个Channel的注册的线程上,绑定一个10秒执行的异步任务。
想好就开干,功能一切正常。但发布线上后,到下午,发现服务器监控CPU飙升至80%。平时长连接服务器连接数上了,CPU占用才20%,很明显重构,是导致CPU飙升的根本原因,但这个设计思路是没问题的,所以得排除具体是那个业务逻辑出错了。
2.线上排查
首先在服务器上执行top命令,得到CPU占用最高的进程,如下图(非异常出现时的截图)
获取该进程下cpu占用最高的线程。执行命令:ps -mp 9994 -o THREAD,tid,time
将线程号转换成16进制,执行:printf "%x\n" 9996
使用jstack命令查看堆栈日志,执行:jstack 9994 | grep 270c -A60
3.问题解决
通过堆栈日志排除问题,发现占用CPU最高的是Netty的 WorkEventGroup,一直在执行心跳任务,跟踪线上当前连接数,并没有很多。为什么连接数减少,还在一直执行任务?发现,当Channel close后,Channel从绑定的线程上注销,但心跳任务还在继续执行,发现问题后,排查代码,确实,每个Channel在close的时候,没有将其从任务队列中移除,将代码修正后,发布线上,再次监测CPU占用,OK,一切正常。
任它岁月流逝,前方也定会海阔天空!