[JBoss JIRA] (WFLY-5195) Persistent timers sometimes remain IN_TIMEOUT in database and don't ever activate again
12:34 a.m.
[
https://issues.jboss.org/browse/WFLY-5195?page=com.atlassian.jira.plugin....
]
Stuart Douglas commented on WFLY-5195:
--------------------------------------
I have fixed this by simply modifying the timer state back to active.
There are still some issues with clustered timers though, that basically relate to failed
task detection (e.g. if a node in the cluster goes away with a task in IN_TIMEOUT, then
other cluster nodes will not pick up the task). This requires quite a bit of feature
development that I think is outside the scope of EAP7.0. To workaround this we should
recommend that nodes are always shut down using graceful shutdown, as this will prevent
this occurring.
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
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.
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
3729
days inactive
3729
days old
0 comments
1 participants
participants (1)
-
Stuart Douglas (JIRA)