※ 项目背景:上线1个月的项目-设备点检模块
※"设备专项点检模块"需求:每月倒数第三日生成次月设备点检计划,6月计划在5月29日正常生成,7月计划应该在6月28日早05:00生成。
但是本日(6月28日)却未生成7月设备专检计划,产生了线上一级阻断性bug。
首先查看定时任务使用定时任务框架LTS,确认今早05:00执行过定时任务:
cron表达式: "0 0 5 1,26,27,28,29 * ?"
表示每个月的1,26,27,28,29早晨05:00执行一次,在定时任务类中通过代码控制具体每个月的执行日期,确保是在每个月的倒数第三天执行,通过日历Calendar来保证取到每个月倒数第三天。
public class CreateSpecialExaminationPlanJob implements JobRunner {
......
Calendar calendar=Calendar.getInstance();
int lastDay=calendar.getActualMaximum(Calendar.DAY_OF_MONTH);
int today=calendar.get(Calendar.DAY_OF_MONTH);
boolean isLastSecondDay=(lastDay-today==2);
boolean isFirstDay=(today==1);
SpeExaPlanService speExaPlanService = SpringUtil.getBean(SpeExaPlanService.class);
try {
FunctionResult result;
if(isFirstDay){
//每个月第一天凌晨将临时计划转换为正式计划
result=speExaPlanService.transferFormalPlan();
}else if(isLastSecondDay){
//每个月倒数第三天执行下个月的临时计划生成任务
result=speExaPlanService.generatePlan();
}else{
return new Result(Action.EXECUTE_SUCCESS,"no need to execute special examination plan");
}
......
}
目前来看这一段代码没有问题,配合cron表达式能够正常获取到每月倒数第三天的日期,并控制接口的调用。
同时查看生产环境错误日志:
生产环境错误日志.png
java.lang.StackOverflowError
这是我第一次遇到栈溢出错误,因为java有GC机制,所以一般不会出现栈溢出问题,查阅资料后一般认为栈溢出是因为递归形成了无限递归导致的。
根据错误日志可以看出是由DateInfoUtil.switchDate()这个方法抛出的Error:
//在具体代码中找到这个方法:
......
/**
* 计算下次的计划时间
* @param cycleInterval
* @param lastActDate
* @return
*/
Date getPlanDate(Integer cycleInterval,Date lastActDate){
Calendar calendar=Calendar.getInstance();
//获取某月最大天数
int lastDay = calendar.getActualMaximum(Calendar.DAY_OF_MONTH);
//设置本月的最大天数
calendar.set(Calendar.DAY_OF_MONTH, lastDay);
Date lastDayOfMonth=calendar.getTime();
lastDayOfMonth=DateInfoUtil.switchDate(lastDayOfMonth,DateInfoUtil.MAX_DATE_TYPE);
if(cycleInterval > maxWeekNumInMonth) {
if (lastActDate.after(lastDayOfMonth)) {
//如果日期为下个月及以后的日期 (当周期大于四周且未实行点检的情况下时存在日期为以后日期的情况)
return lastActDate;
}
}
calendar.setTime(lastActDate);
calendar.add(Calendar.WEEK_OF_YEAR,cycleInterval);
//若计划日期大于这个月的时间,则返回该日期,否则继续加
if (calendar.getTime().after(lastDayOfMonth)) {
return calendar.getTime();
}
return getPlanDate(cycleInterval,calendar.getTime());
}
DateInfoUtil.switchDate()方法如下,是一个将当前日期转换为当天最大日期(23:59:59)或者最小日期(00:00:00)的方法。
public static Date switchDate(Date date, Integer switchType) {
Calendar calendar = DateUtils.toCalendar(date);
//MAX_DATE_TYPE为定义的传参,约定MAX_DATE_TYPE = 2,switchType = 2时表示取当天最大时间,反之则表示取当天最小时间。
if (MAX_DATE_TYPE.equals(switchType)) {
calendar.set(Calendar.HOUR_OF_DAY, calendar.getActualMaximum(Calendar.HOUR_OF_DAY));
calendar.set(Calendar.MINUTE, calendar.getActualMaximum(Calendar.MINUTE));
calendar.set(Calendar.SECOND, calendar.getActualMaximum(Calendar.SECOND));
calendar.set(Calendar.MILLISECOND, calendar.getActualMaximum(Calendar.MILLISECOND));
} else {
calendar.set(Calendar.HOUR_OF_DAY, calendar.getActualMinimum(Calendar.HOUR_OF_DAY));
calendar.set(Calendar.MINUTE, calendar.getActualMinimum(Calendar.MINUTE));
calendar.set(Calendar.SECOND, calendar.getActualMinimum(Calendar.SECOND));
calendar.set(Calendar.MILLISECOND, calendar.getActualMinimum(Calendar.MILLISECOND));
}
return calendar.getTime();
}
一开始分析时,认为是计算计划日期时频繁调用了DateInfoUtil.switchDate()方法导致栈溢出,所以取消调用该方法,直接在代码中写死时分秒(23:59:59)。
Calendar calendar=Calendar.getInstance();
//获取某月最大天数
int lastDay = calendar.getActualMaximum(Calendar.DAY_OF_MONTH);
//设置本月的最大天数
calendar.set(Calendar.DAY_OF_MONTH, lastDay);
calendar.set(Calendar.HOUR_OF_DAY, 23);
calendar.set(Calendar.MINUTE, 59);
calendar.set(Calendar.SECOND, 59);
Date lastDayOfMonth=calendar.getTime();
如此修改后,在开发环境测试能够正常生成7月数据。
发布预生产环境时,从生产环境直接拉数据到预生产环境,能够正常生成7月点检计划。遂认为已经修复该bug。
后来发现测试环境在28日早05:00成功生成7月点检计划,当时个人主观强行解释是由于测试库数据量过少,而生产库数据量较大,调用该方法时内存占用过多引起的,实际上测试库数据为10条,生产库数据为217条,并无巨大数量差异。
后来的事实证明这个bug是源于更深层次的原因,与是否调用该方法并无关系。
晚间发布生产环境,直接调用swagger的接口触发该任务,仍然报java.lang.StackOverflowError(栈溢出)错误:
晚间发布生产环境仍然报栈溢出错误.png
所以很可能是连续两次出现该问题的函数有问题:
//连续两次出现该问题的函数
//获取计划日期
getPlanDate()
通过调用getPlanDate()方法来计算下次计划时间,这是一个递归方法,入参为周期数 cycleInterval 和上次实施日期 lastActDate 。
函数的递归思路是:
cycleInterval是一个固定的int值,表示周期数,单位为周,如果传入周期为4周,初始值为月初,加上4周后,很有可能还在这个月以内,比如当lastActDate是4月1日时,加上4周,还在4月以内,是4月29日 这样就需要再加一个周期(4周),判断如果它早于这个月最后一天,就继续调用这个方法加一个周期(4周)。
当cycleInterval数为5以上时,无论如何一个月至多只出现一次计划,所以当cycleInterval > 4 时,直接可以跳出递归,若cycleInterval <= 4,则可能需要再加上一次周期。
递归方法如下:
/**
* 计算下次的计划时间
* @param cycleInterval
* @param lastActDate
* @return
*/
Date getPlanDate(Integer cycleInterval,Date lastActDate){
Calendar calendar=Calendar.getInstance();
//获取某月最大天数
int lastDay = calendar.getActualMaximum(Calendar.DAY_OF_MONTH);
//设置本月的最大天数
calendar.set(Calendar.DAY_OF_MONTH, lastDay);
calendar.set(Calendar.HOUR_OF_DAY, 23);
calendar.set(Calendar.MINUTE, 59);
calendar.set(Calendar.SECOND, 59);
Date lastDayOfMonth=calendar.getTime();
if(cycleInterval > maxWeekNumInMonth) {
if (lastActDate.after(lastDayOfMonth)) {
//如果日期为下个月及以后的日期 (当周期大于四周且未实行点检的情况下时存在日期为以后日期的情况)
return lastActDate;
}
}
calendar.setTime(lastActDate);
calendar.add(Calendar.WEEK_OF_YEAR,cycleInterval);
//若计划日期大于这个月的时间,则返回该日期,否则继续加
if (calendar.getTime().after(lastDayOfMonth)) {
return calendar.getTime();
}
return getPlanDate(cycleInterval,calendar.getTime());
}
领导指出我这一段递归函数是有问题的,在实际的java开发中,应尽量避免递归函数。
这里每次递归,都会产生冗余的calendar对象,短期少量的递归或许能满足业务需求,但是如果有大量递归,就可能造成严重的性能问题。
于是只能从头开始核查代码
从头开始核查代码时,发现的问题.png
在这一句sql查询出的记录中,发现了问题,INIT_CHECK_DATE的值为 0219-02-10,在业务逻辑中,这个初始点检时间是作为计划点检时间的基数存在的,仅在第一次生成计划时间时生效,使用(INIT_CHECK_DATE + cycleInterval * 7 )得到在实际日期 (2019年6月28) 的次月中的计划日期。
所以当初始点检日期为219-02-10时,计算到2019-06-28以后,需要计算1800年中的递归,此时的递归,每一次都会产生一个calendar对象,所有的引用都是有效的,GC也不能起作用,会瞬间将栈内存挤爆,所以会不断抛出java.lang.StackOverflowError错误,之前弃用的获取当日时间最大值函数并不是问题的真正原因,真正的原因在这里。
问题答案已经很接近了,经过核查,大概有接近10台设备的共数十条标准,导入的年份都为219年,这个应该是使用人员导入点检标准数据时产生的错误。
在修改了数据库数据(将219改为2019)后,调用swagger接口生成7月计划,此时,数据库中最早的为2018年3月,使用递归方法计算下次计划日期,足足花了有5分钟之久。可见递归方法是在性能上是有明显缺陷的,在编程时,没有考虑到性能的问题,以为实现业务就可以了,产生了这次线上阻塞性问题。
后期会修改递归方法,使用循环方法进行业务实现。
那么为什么导入数据的时候没有合适的校验取拦截这些错误的日期呢?
其实在导入时是做了日期校验的,
private static final SimpleDateFormat dateFormat=new SimpleDateFormat("yyyy-MM-dd");
//校验初始更换日期格式,必须能转化成yyyy-mm-dd格式
try {
dateFormat.setLenient(false);
dateFormat.parse(importVO.getInitCheckDate());
}catch (Exception e) {
return ErrorCode.SpeExaStandardImportInitCheckDateInvalid;
}
但是这个校验仅仅只考虑到输入非法日期值时的校验,比如"2019年03月10日"这种数据,对于"219-02-10"这种数据,严格来说是合法的日期。在编码时没有考虑到这种情况,缺乏健壮性。
那么为什么上线首月的数据生成正常呢?
经过查询:
问题数据详情.png
可以发现问题数据都是在6月18日导入的,此时,6月份的计划已生成,在6月底生成7月计划时,这些错误数据就像埋好的地雷,终于在6月底引爆了这次栈溢出故障。
以上的两个问题的回答,也从侧面佐证了本次的阻断性bug确实是由于生产库数据错误和使用了递归算法导致的。
大量的递归运算,接近于无限递归,也符合java栈溢出的主要原因。
修改了数据库数据后,7月份的点检计划正常生成,该BUG到此解决,后期需要弃用递归算法,对流程进行完善。
问题总结:
造成本次线上阻塞性bug的原因:
1.导入校验做的不够充分,未能识别导入的错误数据;
2.使用了递归方法来实现业务逻辑,而递归往往要消耗大量的的系统资源,很容易造成栈溢出问题;
3.操作人员的偶发性错误导致错误的数据被录入了系统;
4.分析问题时,没有深入问题内部去考虑,仅仅使用似是而非的解释搪塞,这种错误在线上生产环境是不能够被容忍的。
后期整改内容:
1.在导入部分添加校验,只允许导入初始点检时间为一年以内的数据;
2.弃用递归方法,使用资源占用更小的循环方法;
3.排查其他功能模块是否存在类似问题;
非常感谢帮助我排查问题的业务人员,测试人员和领导。
相关阅读:
《如果要用Java实现算法,一定慎用递归》
https://cloud.tencent.com/info/ad6e62448c5d25d620915de47a19e657.html
网友评论