WFLYEJB0043: A previous execution of timer [timer]

2019-04-11 22:13发布

问题:

I have defined some persistent timers in a singleton EJB as follows (using WildFly 9.0.2 final).

@Startup
@Singleton
@Lock(LockType.READ)
public class BackgroundJobManager implements BackgroundJobService {

    @Schedule(dayOfMonth = "1", month = "Jan", year = "*", hour = "0", minute = "0", second = "0", persistent = true)
    private void doYearlyJob() {
        //...
    }

    @Schedule(hour = "*", minute = "*/5", second = "0", persistent = true)
    private void updateTopSellers() {
        //...
    }

    @Schedule(hour = "*", minute = "*/1", second = "0", persistent = true)
    private void updateFeedback() {
        //...
    }

    //...
}

Several warnings are issued on server startup and when the application is redeployed like the following (these are merely a few of them).

19:46:51,687 WARN  [org.jboss.as.ejb3] (EJB default - 3) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:25:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:51 IST 2015.
19:46:51,796 WARN  [org.jboss.as.ejb3] (EJB default - 4) WFLYEJB0043: A previous execution of timer [id=fc285ef2-c7a1-4a2e-af57-d320c769b445 timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 22:50:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:51 IST 2015.
19:46:51,890 WARN  [org.jboss.as.ejb3] (EJB default - 5) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:26:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:51 IST 2015.
19:46:51,953 WARN  [org.jboss.as.ejb3] (EJB default - 6) WFLYEJB0043: A previous execution of timer [id=fc285ef2-c7a1-4a2e-af57-d320c769b445 timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 22:55:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:51 IST 2015.
19:46:51,984 WARN  [org.jboss.as.ejb3] (EJB default - 7) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:27:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:51 IST 2015.
19:46:52,062 WARN  [org.jboss.as.ejb3] (EJB default - 8) WFLYEJB0043: A previous execution of timer [id=fc285ef2-c7a1-4a2e-af57-d320c769b445 timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 23:00:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,218 WARN  [org.jboss.as.ejb3] (EJB default - 9) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:28:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,328 WARN  [org.jboss.as.ejb3] (EJB default - 10) WFLYEJB0043: A previous execution of timer [id=fc285ef2-c7a1-4a2e-af57-d320c769b445 timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 23:05:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,390 WARN  [org.jboss.as.ejb3] (EJB default - 3) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:29:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,453 WARN  [org.jboss.as.ejb3] (EJB default - 4) WFLYEJB0043: A previous execution of timer [id=fc285ef2-c7a1-4a2e-af57-d320c769b445 timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 23:10:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,484 WARN  [org.jboss.as.ejb3] (EJB default - 5) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:30:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,531 WARN  [org.jboss.as.ejb3] (EJB default - 6) WFLYEJB0043: A previous execution of timer [id=fc285ef2-c7a1-4a2e-af57-d320c769b445 timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 23:15:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,593 WARN  [org.jboss.as.ejb3] (EJB default - 7) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:31:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,687 WARN  [org.jboss.as.ejb3] (EJB default - 8) WFLYEJB0043: A previous execution of timer [id=fc285ef2-c7a1-4a2e-af57-d320c769b445 timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 23:20:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.
19:46:52,781 WARN  [org.jboss.as.ejb3] (EJB default - 9) WFLYEJB0043: A previous execution of timer [id=15baaed1-d804-48fc-acdb-80ea3e04735f timedObjectId=WildFly.WildFly-ejb.BackgroundJobManager auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@9e86f initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Fri Dec 11 16:32:00 IST 2015 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sat Dec 12 19:46:52 IST 2015.

Timer service is defined in standalone-full-ha.xml as follows.

<timer-service thread-pool-name="default" default-data-store="clustered-store">
    <data-stores>
        <database-data-store name="clustered-store" datasource-jndi-name="java:jboss/datasources/projectXADatasource" database="mysql" partition="timer"/>
    </data-stores>
</timer-service>

These warnings also appear, when these timers are persisted to the file system in place of a database, no matter whether the application is deployed in a cluster (standalone-full-ha.xml) or non-cluster (standalone-full.xml) environment.

I regularly flush out all contents of standalone/data (except the deployed JDBC driver and custom contents), standalone/deployments and standalone/tmp whenever necessary. Symptoms of timers are no longer available in standalone/data as they were before, when timers were initially being persisted to the file system.

Is there a fix?


There is a question but I am not satisfied with the answer given (sorry). Besides, that question uses JBoss EAP 6.4 and why the tag spring presents there while using EJBs in an application server is a mystery to me.


Update :

The issue remains stationary in WildFly 10.0.0 final.

回答1:

This is an acknowledged bug. See https://issues.jboss.org/browse/WFLY-6561.

The bug has also been applied to JBoss 7 as well: https://issues.jboss.org/browse/JBEAP-4442



回答2:

We were getting this "warning" on startup which seems to execute the scheduledTimeout method successfully anyway. There's not really an error here especially since the persistent attribute on the @Schedule annotation defaults to true. This message appears for us (in development) during startup after the server has been down for a sustained period of time (therefore missing the timeout events that would have occurred had the server been online). Other answers to this question are also probably valid, but noting this here if the proper function of this feature is being overlooked.

Basically, if you're thinking this is a problem, re-evaluate whether you want your @Schedule timed event to replay all events missed while the server was offline. If not, then set the persistent attribute to false in the annotation.