线上出现了定时器执行问题,日志如下:
2018-08-23 23:50:00,001 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-5:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-23 23:50:00,023 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1:AdminInfoCountSchedule:14 | ----------定时任务-统计信息发布数入>库-------
2018-08-23 23:50:00,703 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1:AdminInfoCountSchedule:16 | ----------定时任务-统计信息发布数入>库--
2018-08-23 23:50:00,850 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-5:InvalidDataSchedule:27 | ----------定时任务-更新条数--13----30----2
018-08-24 01:00:00,000 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,001 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-4:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,001 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-4:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,001 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,001 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-4:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,002 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-2:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,005 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-7:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,005 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-10:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:00,009 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-2:InvalidDataSchedule:18 | ----------定时任务-更新失效数据-------
2018-08-24 01:00:24,035 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-4:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 01:00:24,134 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-4:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 01:00:24,282 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-2:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 01:00:24,385 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-4:InvalidDataSchedule:27 | ----------定时任务-更新条数--57----154----0
2018-08-24 01:00:24,386 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-2:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 01:00:24,440 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-7:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 01:00:24,481 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-10:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 01:00:24,487 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 01:00:24,492 | INFO | org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6:InvalidDataSchedule:27 | ----------定时任务-更新条数--0----0----0
2018-08-24 08:48:56,509 | INFO | http-nio-2020-exec-813:SysLog:66 | sessionId[2823e04f-7f9e-4712-aa3f-1a3498a94690] user[null=null] uri[/zhaoniuw_web_admin/login] params[]
2018-08-24 08:48:56,510 | INFO | http-nio-2020-exec-813:SysLog:72 | sessionId[2823e04f-7f9e-4712-aa3f-1a3498a94690] user[null=null] uri[/zhaoniuw_web_admin/login] params[] time[1ms]
两个问题:
- 前一天23:50出发了一个应该是第二天凌晨1:00的定时任务
- 凌晨触发的任务有多次执行
配置文件如下:
<bean id="bizObject" class="com.schedule.InvalidDataSchedule"/>
<bean id="jobDetail" class="org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean">
<property name="targetObject" ref="bizObject"/>
<property name="targetMethod" value="updateInvalidDataStatus"/>
<property name="concurrent" value="false"/>
</bean>
<bean id="invalidCronTrigger" class="org.springframework.scheduling.quartz.CronTriggerFactoryBean">
<property name="jobDetail" ref="jobDetail"/>
<property name="cronExpression" value="0 0 01 * * ?"/>
</bean>
<!-- ********************************************************************************************** -->
<!-- 统计 -->
<bean id="countSchedule" class="com.schedule.AdminInfoCountSchedule"/>
<bean id="countJobDetail"
class="org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean">
<property name="targetObject" ref="countSchedule"/>
<property name="targetMethod" value="countAdminInfos"/>
<property name="concurrent" value="false"/>
</bean>
<bean id="countCronTrigger" class="org.springframework.scheduling.quartz.CronTriggerFactoryBean">
<property name="jobDetail" ref="countJobDetail"/>
<property name="cronExpression" value="0 50 23 * * ?"/>
</bean>
<bean class="org.springframework.scheduling.quartz.SchedulerFactoryBean">
<property name="triggers">
<list>
<ref bean="invalidCronTrigger"/>
<ref bean="countCronTrigger"/>
</list>
</property>
</bean>
web.xml
<context-param>
<param-name>contextConfigLocation</param-name>
<param-value>classpath:spring/app-*.xml,classpath:schedule-beans.xml</param-value>
</context-param>
查找之前正常的日志,异常前后并未添加和定时器相关的代码。查看日志在tomcat关闭时有很多报错:
23-Aug-2018 20:30:28.171 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [XXXX] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-8] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
,而且由于项目上线使用的是jenkins的自动shutdowm-替换war包-startup的流程,所以可能进程一直没有关掉。
不修改代码手动kill tomcat一次测试。测试结果回归正常,触发也正常。
原因就是因为tomcat未正常结束导致的quartz进程依然在运行,错误时间触发的问题是附带问题。
解决:
- 保证tomcat的正常结束,不要使用shutdown.sh
killTomcat()
{
pid=`ps -ef|grep tomcat|grep java|awk '{print $2}'`
echo "tomcat Id list :$pid"
if [ "$pid" = "" ]
then
echo "no tomcat pid alive"
else
kill -9 $pid
fi
}