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

Kevin Chen (JIRA) issues at jboss.org
Fri May 6 13:47:00 EDT 2016


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

Kevin Chen edited comment on WFLY-6561 at 5/6/16 1:46 PM:
----------------------------------------------------------

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.  The "second" argument is set to "2" instead of "0".


{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.


was (Author: kcpublic):
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)


More information about the jboss-jira mailing list