]
Roger Lee commented on WFLY-5195:
---------------------------------
Stuart,
I'm having a similar problem. Did you do this fix programatically?
Thanks.
Persistent timers sometimes remain IN_TIMEOUT in database and
don't ever activate again
---------------------------------------------------------------------------------------
Key: WFLY-5195
URL:
https://issues.jboss.org/browse/WFLY-5195
Project: WildFly
Issue Type: Bug
Components: EJB
Affects Versions: 10.0.0.Beta2
Reporter: Jan Martiska
Assignee: Stuart Douglas
Fix For: 10.0.0.CR1
Attachments: in-timeout-reproducer.zip
The scenario:
A persistent timer goes off right before its application gets undeployed
{noformat}
[0m[32m08:43:38,086 DEBUG [org.jboss.as.ejb3] (EJB default - 1)
Timer task invoked at: Tue Aug 25 08:43:38 CEST 2015 for timer
[id=d563c5b3-c98c-44c9-87f6-04a492280a67
timedObjectId=testTimerServiceSerialization.a.TimerServiceSerializationBean
auto-timer?:false persistent?:true
timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@43ca0624
initialExpiration=Tue Aug 25 08:43:35 CEST 2015 intervalDuration(in milli sec)=100
nextExpiration=Tue Aug 25 08:43:38 CEST 2015 timerState=ACTIVE
info=org.jboss.as.test.integration.ejb.timerservice.serialization.InfoA@1ce85ecb]
{noformat}
The timer changes its state to IN_TIMEOUT and persists this into the database.
It fails to invoke the bean method, because the application is no longer available
{noformat}
[0m[31m08:43:38,515 ERROR [org.jboss.as.ejb3] (EJB default - 1)
WFLYEJB0020: Error invoking timeout for timer: [id=d563c5b3-c98c-44c9-87f6-04a492280a67
timedObjectId=testTimerServiceSerialization.a.TimerServiceSerializationBean
auto-timer?:false persistent?:true
timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@43ca0624
initialExpiration=Tue Aug 25 08:43:35 CEST 2015 intervalDuration(in milli sec)=100
nextExpiration=Tue Aug 25 08:43:38 CEST 2015 timerState=IN_TIMEOUT
info=org.jboss.as.test.integration.ejb.timerservice.serialization.InfoA@1ce85ecb]:
java.lang.IllegalStateException
at org.jboss.msc.value.InjectedValue.getValue(InjectedValue.java:47)
at
org.jboss.as.ejb3.timerservice.TimerServiceImpl.getInvoker(TimerServiceImpl.java:564)
at org.jboss.as.ejb3.timerservice.TimerTask.invokeBeanMethod(TimerTask.java:188)
at org.jboss.as.ejb3.timerservice.TimerTask.callTimeout(TimerTask.java:184)
at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:157)
at
org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1224)
at
org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:497)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
{noformat}
It considers retrying, but then it doesn't retry, because the state is IN_TIMEOUT
{noformat}
08:43:38,515 INFO [org.jboss.as.ejb3] (EJB default - 1) WFLYEJB0021: Timer:
[id=d563c5b3-c98c-44c9-87f6-04a492280a67
timedObjectId=testTimerServiceSerialization.a.TimerServiceSerializationBean
auto-timer?:false persistent?:true
timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@43ca0624
initialExpiration=Tue Aug 25 08:43:35 CEST 2015 intervalDuration(in milli sec)=100
nextExpiration=Tue Aug 25 08:43:38 CEST 2015 timerState=IN_TIMEOUT
info=org.jboss.as.test.integration.ejb.timerservice.serialization.InfoA@1ce85ecb] will be
retried
08:43:38,515 INFO [org.jboss.as.ejb3] (EJB default - 1) WFLYEJB0024: Timer is not
active, skipping retry of timer: [id=d563c5b3-c98c-44c9-87f6-04a492280a67
timedObjectId=testTimerServiceSerialization.a.TimerServiceSerializationBean
auto-timer?:false persistent?:true
timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@43ca0624
initialExpiration=Tue Aug 25 08:43:35 CEST 2015 intervalDuration(in milli sec)=100
nextExpiration=Tue Aug 25 08:43:38 CEST 2015 timerState=IN_TIMEOUT
info=org.jboss.as.test.integration.ejb.timerservice.serialization.InfoA@1ce85ecb]
{noformat}
It gives up and tries to persist the state back to ACTIVE, but it fails, because the
DatabaseTimerPersistence service is no longer available
{noformat}
08:43:38,516 WARN [org.jboss.as.ejb3] (EJB default - 1) WFLYEJB0016: Timer persistence
is not enabled, persistent timers will not survive JVM restarts
{noformat}
So the state remains IN_TIMEOUT in the database. When the application is redeployed, it
is initialized with this state and it never goes off again.
This happens with a JDBC storage in a database that is slow enough so that the update of
state to IN_TIMEOUT proceeds correctly, but the actual bean method invocation fails
already.
Attaching a reproducer which simulates a slow database using Byteman, so it can be run
even with the ExampleDS.