问题介绍
最近公司的项目出现了一次惊险的崩溃,用户只要点击审批归档就会发生服务器cpu飙升,继而OOM的现象,最后解决了是因为历史错误数据未及时清理,导致时间值不满足现在的判断条件导致的问题,上一下源代码:
Date date = application.getStartTime();
List<Date> dateList = Lists.newArrayList(date);
while (!DateUtils.isSameDay(date, application.getEndTime())) {
date = DateUtils.addDays(date, 1);
dateList.add(date);
}
代码如上,表面上看来意思是从申请起始时间到申请结束时间的所有日期加入到 dateList 中,但是由于起始时间比结束时间大无限循环了。
本文主要介绍作者处理这样的问题的一个过程,涉及到java自带的jps,jstack工具,另外还使用到了JProfile工具分析内存。
问题还原
首先模拟一下当时的情况,编写一个controller如下:
@GetMapping(value = "/oom")
public String index() throws ParseException {
SimpleDateFormat sdf = new SimpleDateFormat("yyyy-mm-dd");
Date startTime = sdf.parse("2019-01-22");
Date endTime = sdf.parse("2019-01-21");
List<Date> dateList = new ArrayList<Date>();
dateList.add(startTime);
while(!isSameDay(startTime, endTime)){
startTime = addDays(startTime, 1);
dateList.add(startTime);
}
return "success";
}
详细源码见我的github: https://github.com/yzuwangfeng/dealWithProblem
首先我们将项目打包并运行:
java -Xmx2048m -Xms512m -XX:+HeapDumpOnOutOfMemoryError -jar dealWithProblem-0.0.1-SNAPSHOT.jar
之后访问 localhost:8080/oom
此时会发现浏览器迟迟无法访问成功,等待没多久,我们就可以看到OOM异常了:
由于启动的时候,我加上了打印堆栈信息的参数,因而我们可以使用 JProfile 分析 OOM 时的内存信息:
通过这两张图片我们可以明显的分析出来是dateList的内容过多了
到这一步,貌似这个问题已经解决完了,但是实际处理线上问题时,远不止这么简单,示例代码中我只写了一个list, 一个循环,实际情况比这复杂许多,因而,我们需要更详细的信息进行分析。
查找并分析线程
首先通过top命令分析一下当前系统进程,如图:
通过分析得到进程号为25968的进程占用cpu非常大。
ps:
查找这个进程号的另一种方式就是通过jps命令,jps会列出当前系统中所有的java进程,前面一步,运行项目通过的是 java -jar 命令,所以jps列出的进程中 jar对应的进程就是我们的项目进程了。
找到进程号之后,我们需要分析其中的线程,即通过 top -Hp 25968
,得到线程分析列表:、
在列表中看到,25970,25971,25972,25973 这四个线程占用cpu最高,且非常相近,将这些线程号转换为16进制后分别为6572,6573,6574,6575
通过jstack命令查看当前25968 进程中的所有线程: jstack 25968
,通过查找,可以发现这四个线程对应的是内存回收线程,如图:
显然这不是我们需要分析的线程,回过头再看分析表,可以看到25990相对占用cpu的时间也是比较多,转换为16进制为6586,这时可以在jstack中找到对应的线程信息:
打印堆栈信息,我们可以看到:
线程仍然执行在条件循环中,这一点已经显而易见了。
总结
到这里问题就分析完成了,虽然这是一个小问题,可能只需要修改或者删除一下线上的错误数据,但是实际上反映出一个问题,也是笔者最近在阅读《Effective Java》一书时看到的一条建议:
在编写方法时,需要对参数的有效性进行校验