作者:hareleemu_699 | 来源:互联网 | 2024-11-08 21:18
近日,技术学院负责人委托我负责维护包括大讲堂和积分管理系统在内的几个平台。尽管这些系统的功能已经相当成熟且不再进行新功能的开发,但大讲堂系统自上线以来,每隔一段时间就会出现故障,影响了学员的学习体验。为了解决这一问题,我们将从多个角度深入分析其原因,并探讨有效的解决方案。
1. 问题背景
前不久技术学院负责人让我帮助维护下⼤讲堂、积分管理等⼏个系统。这些系统功能都已经很稳定,也不会再有新的功能开发,但是⼤讲堂系统自上线后,每过⼀段时间就会出错,导致学员⽆法报名课程,希望我帮助解决下。这种累积下来的问题解决起来⽐较难,但是对能⼒提升帮助很大,我欣然接受了,所以就有了这次“艰苦”的问题排查和解决之旅。
2. 解决思路
本人未参加过大讲堂和积分系统的开发,解决问题⾸先要最⼤化的了解系统背景、问题发⽣时的系统表现等信息。技术学院的同事和我说,负责系统的开发⼈员已经换过⼏波了,现在基本已经找不到了解系统的开发⼈员了,但是也反馈了以下信息:
1、系统是16年公司应届⽣培训时做的项⽬。2、其他系统运⾏良好,就是⼤讲堂系统偶尔会报错,导致学员⽆法报名,重启下就好了,果然是“重启⼤法”好啊。3、系统出错的频率不⾼,但是貌似很有规律,⼤半个⽉左右出现⼀次。根据以上描述,特别是出错后“重启⼤法”特别有效,出错频率基本固定,通过这两点基本上可以断定是资源泄露导致的问题。既然确定是资源泄露问题,对于 Java 应⽤来说排查⽅向也就确定为以下2个⽅向:1、对象泄露2、线程泄露
3. 处理过程
前文提过本人并未参与项目开发,所以整个排查大部分是通过 linux 和 jvm 的⼀些命令行辅助功能来进行的,下面是整个排查过程:1、 首先通过 jps 确定 Java 应用的进程 idsudo -u tomcat jps -lv | grep qtscore
2、 排查内存泄露
通过持续观察 GC 日志文件 /home/q/www/qtscore/log/gc.log 文件,发现 GC 执行频率正常,特别是 Full GC 执行也并不频繁,虽然内存使用量在持续增长,但是并不明显。
为了确认业务代码是否存在泄漏,通过 jmap 查看了堆内对象分布情况,切记此命令会导致进程暂停,如果是 qps 高或者响应时间要求高的应用慎用:sudo -u tomcat jmap –F -histo 11035
这里只截取了⼀部分,内存占用量和数量靠前的并无业务代码。到这⼀步,基本初步排除内存泄露的可能性。
3、 排查线程泄露
top -H -p 11035
通过结果可以看出线程已经高达4038,应用中dubbo线程池默认配置是200个线程,tomcat线程池配置也是200个线程,所以这个线程数明显不合理。参照另外一个同等应用,其线程数未超过500,所以可以初步判断系统存在线程泄露,下⼀步只能查看线程栈信息了:
sudo -u tomcat jstack -l 11035 > /tmp/qtscore_stack.log
系统中存在100多个“New I/O boss"线程,这个应该是 netty 线程池的 boss 线程,到这里基本上可以确认是线程池泄露引起的问题了,但是究竟是哪段代码引起的,线程栈中并无业务相关代码,只是 netty 线程池的代码,所以无法判断出引起问题的代码源头,只能先看看系统日志中是否有价值的信息了,发现系统日志中频繁报以下错误:
找到对应的源代码进行查看,发现这是⼀个 dubbo 服务接口,而 dubbo 底层用的就是 netty,种种迹象表明问题应该就出在这里。仔细分析代码后,发现这个 dubbo 接口抛出的异常 QtalkQueryException,居然没有通过 api 暴露给调用方,也就是说调用方是无法正确反序列化这个异常的。初步推测可能就是这个原因导致 dubbo 未能正确处理线程池,导致线程池泄露了。将 QtalkQueryException 改为抛出 IllegalStateException 异常,发布上线,满怀期待地等着问题被完美解决。过了一个星期后,通过 top 命令查看进程的线程数,发现线程数又飙升到1千1百多了,看来问题还是没有解决,只能再排查了,但是基本上可以确定是线程泄露问题,而且是 netty 引起的,可是线程栈中 netty 的 worker 线程栈中没有任何业务相关的代码,应该是代码间接用到了 netty 线程池,但是一时没有了头绪。只有找同事咨询一下了,和几个同事讨论后,大家都认为最有可能用到线程池的就是异步请求,特别是一些HTTP客户端,根据这个思路对代码进行排查后,发现系统中有如下代码:
这个 com.ning.http.client.AsyncHttpClient 底层用到了 netty 线程池,这个用法存在明显错误,AsyncHttpClient 实例应该重用,而不应该每次使用时都创建一个。修改代码后重新发布上线,一周后再统计应用线程数,发现线程数稳定在350个左右,确认问题得到了解决。但是故事还没有结束,个人觉得既然应用报错,日志应该有所体现才对,难道是被其他异常淹没了?所以重新排查了出错日期的日志,果然发现了以下错误信息:
通过系统命令 ulimit –a 发现系统最大用户线程数是4096,所以问题是创建的线程超过了系统最大用户线程数限制。
4. 经验总结
回顾这次问题排查经历,其实这个问题排查起来并不难,最初的排查方向也是对的,但是整个过程还是花费了很长时间。回顾整个过程,总结出以下经验和教训:
大规模使用的基础组件(例如:Dubbo)不容易有问题,即使有问题也会被及时修复,所以还是要多分析自己编写的代码。
排查问题首先要仔细分析系统日志,报错的地方⼀般也就是引起问题的源头,遵循和重视这个原则,通常可以大大提高排查问题的效率。