[jboss-jira] [JBoss JIRA] (WFLY-6561) EJB Timers Intermittently Execute Repeatedly on Server Restart with Error Code WFLYEJB0043

[Kevin Chen (JIRA)]

    [ https://issues.jboss.org/browse/WFLY-6561?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13202267#comment-13202267 ] 

Kevin Chen commented on WFLY-6561:
----------------------------------

Hi,

We notice this problem rear its head again on an individual's workstation.  Again, it is still intermittent. 

Below is the code revised from past comments that would execute on Wildfly startup.


{code:java}
protected ScheduleExpression createScheduleExpression() {
        ScheduleExpression expression = new ScheduleExpression();
        long millisecondsFromNow = System.currentTimeMillis() + 180000;
        expression.second("2").minute("*").hour("*").start(new Date(millisecondsFromNow));
        return expression;
    }
{code}

Below is a sample log.  The user started their Wildfly instance at 13:17.  The time is 13:20 of the log after the 3 minute intentional delay at startup but the next expiration time is set in the past at 13:17.  We would expect the nextExpiration to be around 13:20, not 13:17

2016-05-05-13:20:15,048 WARN  [org.jboss.as.ejb3] (EJB default - 69) [  ] WFLYEJB0043: A previous execution of timer [id=3e129abd-88d7-4b24-8e2c-93686633d314 timedObjectId=synergy.synergy-app-head.QuartzWatcherService auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at 8c06c93 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Thu May 05 13:17:02 PDT 2016 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Thu May 05 13:20:15 PDT 2016.

> EJB Timers Intermittently Execute Repeatedly on Server Restart with Error Code WFLYEJB0043
> ------------------------------------------------------------------------------------------
>
>                 Key: WFLY-6561
>                 URL: https://issues.jboss.org/browse/WFLY-6561
>             Project: WildFly
>          Issue Type: Bug
>          Components: EJB
>    Affects Versions: 10.0.0.Final
>            Reporter: Kevin Chen
>            Assignee: Stuart Douglas
>
> On Wildfly10, we are experiencing intermittent problems where on server startup, an @Timeout annotated method can be executed hundreds of times in a second (log below).  Going through the references to the @Timeout methods and the @Scheduled methods, all scheduled methods are set to be non-persistent (ex: timerConfig.setPersistent(false), persistent=false) so we don't know how this could occur.  It is not consistent and our only solution has been to kill the Wildfly10 server process and restart.
> 13:47:27,824 WARN  [org.jboss.as.ejb3] (EJB default - 6) [  ] WFLYEJB0043: A previous execution of timer [id=d31eb95a-3f8b-4b7d-882e-f1ff53bc7de8 timedObjectId=synergy.synergy-app-head.QuartzWatcherService auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at dec94c6 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 06 12:10:00 PDT 2016 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Wed Apr 06 13:47:27 PDT 2016.
> 13:47:27,825 WARN  [org.jboss.as.ejb3] (EJB default - 96) [  ] WFLYEJB0043: A previous execution of timer [id=d31eb95a-3f8b-4b7d-882e-f1ff53bc7de8 timedObjectId=synergy.synergy-app-head.QuartzWatcherService auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at dec94c6 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 06 12:10:00 PDT 2016 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Wed Apr 06 13:47:27 PDT 2016.
> 13:47:27,825 WARN  [org.jboss.as.ejb3] (EJB default - 97) [  ] WFLYEJB0043: A previous execution of timer [id=d31eb95a-3f8b-4b7d-882e-f1ff53bc7de8 timedObjectId=synergy.synergy-app-head.QuartzWatcherService auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at dec94c6 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 06 12:10:00 PDT 2016 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Wed Apr 06 13:47:27 PDT 2016.
> 13:47:27,825 WARN  [org.jboss.as.ejb3] (EJB default - 37) [  ] WFLYEJB0043: A previous execution of timer [id=d31eb95a-3f8b-4b7d-882e-f1ff53bc7de8 timedObjectId=synergy.synergy-app-head.QuartzWatcherService auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl at dec94c6 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 06 12:10:00 PDT 2016 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Wed Apr 06 13:47:27 PDT 2016.



--
This message was sent by Atlassian JIRA
(v6.4.11#64026)