Timer not available

[komet_1978]

Hallo,

I am using JBoss 5.1.0.GA with default Datasource settings.

I want to start a timer, store its handle to an entity and access the timer by the stored handle.

Without a restart inbetween everything works fine. But when I restart the jboss after timer creation and access the timer by the stored handle I get the following Exception:

javax.ejb.NoSuchObjectLocalException: Timer not available:
at org.jboss.ejb.txtimer.TimerHandleImpl.getTimer(TimerHandleImpl.java:203)
...

It seems to me that the timer does not survive the restart. I thought that timers are persisted and available also after a restart, aren't they by default? Should I change the configuration for the timerservice to achieve that?

My hsqldb runs in a "InProcessMode". Thanks for helping.

[komet_1978]

I figured out that the ids of the timers stored in the public.timers table change with every restart of jboss. Then the handle stored in the entity does not match the timer's id.

How can I change this disadvantagoues behaviour?

[dimitris]

Just by looking at your description, why not retrieving the active timers directly after the restart from the EJB that created them in the first place, they should be there? I don't think you need to store the handle.

[komet_1978]

Just by looking at your description, why not retrieving the active timers directly after the restart from the EJB that created them in the first place, they should be there? I don't think you need to store the handle.

The timers are managed by the timer service. I don't hold them in my EJB which is a STSB and has the timer service injected. My STSB is only a facade for the service and provides methods to create a timer, change a timer or cancel a timer.

I don't see any possibility to identify and access a certain timer by timerservice api. Of course I can get the whole list of active timers by calling timerService.getTimers(). But then I would have to iterate over the collection to find the timer instance I want to change. This isn't nice ;-).

TimerHandles are defined to provide a direct acess to a timer and as mentioned in the ejb3 specification a handle must be able to achieve that (chapter 18):

"The container must implement a timer handle to be usable over the lifetime of the timer."

This default behaviour of the timer table conflicts with the specification.

[komet_1978]

I found an issue report that matches my issue:

https://jira.jboss.org/jira/browse/JBAS-4598

and felt free to create a sub task of it:

https://jira.jboss.org/jira/browse/JBAS-7328

[dimitris]

JBAS-4598 is an old report against 4.0.5 and many things changed in timers in 4.2.2+

Thinking more about this, maybe the moment you ask for the timers, those are not created yet? i.e. the target container where the timers belong has not fully started for it's timers to be there. Can you verify this is not the case, i.e. check for the timers after the deployment is complete, or see if you can configure a dependency.

[jaikiran]

In addition to what Dimitris asked for - is this EJB3 or EJB 2.x? And please post the entire exception stacktrace.

[komet_1978]

JBAS-4598 is an old report against 4.0.5 and many things changed in timers in 4.2.2+

Thinking more about this, maybe the moment you ask for the timers, those are not created yet? i.e. the target container where the timers belong has not fully started for it's timers to be there. Can you verify this is not the case, i.e. check for the timers after the deployment is complete, or see if you can configure a dependency.

My EJB doesn't access the timers during the start up phase but always after the deplyoment is complete. So therefore there is no need to configure a dependency.

A look into the defaultDB.log (in jboss.home\server\default\data) reveales the following disadvantageous behaviour on start up, 3 timers are deleted from table timers and recreated, but get different ids:

DELETE FROM TIMERS WHERE TIMERID='1255087193422' AND TARGETID='[target=...,name=EETimerService,service=EJB3]'
DELETE FROM TIMERS WHERE TIMERID='1255087193423' AND TARGETID='[target=...,name=EETimerService,service=EJB3]'
DELETE FROM TIMERS WHERE TIMERID='1255087193424' AND TARGETID='[target=...,name=EETimerService,service=EJB3]'
INSERT INTO TIMERS VALUES('1255092103922','[target=...,name=EETimerService,service=EJB3]','2009-10-12 01:18:23.437000000',0,NULL,'aced00057372002464652e6d6574616672616d652e6a6162632e65652e74696d65722e54696d6572496e666f50fe499a85be42e10200045a00096578656354696d65724c00066272616e63687400124c6a6176612f6c616e672f537472696e673b4c000970726f6365737349647400104c6a6176612f6c616e672f4c6f6e673b4c000573696249647400134c6a6176612f6c616e672f496e74656765723b78700074000774696d656f75747372000e6a6176612e6c616e672e4c6f6e673b8be490cc8f23df0200014a000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b02000078700000000000450002737200116a6176612e6c616e672e496e746567657212e2a0a4f781873802000149000576616c75657871007e000700000000')
INSERT INTO TIMERS VALUES('1255092103923','[target=...]','2009-10-12 01:18:27.296000000',0,NULL,'aced00057372002464652e6d6574616672616d652e6a6162632e65652e74696d65722e54696d6572496e666f50fe499a85be42e10200045a00096578656354696d65724c00066272616e63687400124c6a6176612f6c616e672f537472696e673b4c000970726f6365737349647400104c6a6176612f6c616e672f4c6f6e673b4c000573696249647400134c6a6176612f6c616e672f496e74656765723b78700074000774696d656f75747372000e6a6176612e6c616e672e4c6f6e673b8be490cc8f23df0200014a000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b02000078700000000000450004737200116a6176612e6c616e672e496e746567657212e2a0a4f781873802000149000576616c75657871007e000700000000')
INSERT INTO TIMERS VALUES('1255092103924','[target=...]','2009-10-12 01:18:32.656000000',0,NULL,'aced00057372002464652e6d6574616672616d652e6a6162632e65652e74696d65722e54696d6572496e666f50fe499a85be42e10200045a00096578656354696d65724c00066272616e63687400124c6a6176612f6c616e672f537472696e673b4c000970726f6365737349647400104c6a6176612f6c616e672f4c6f6e673b4c000573696249647400134c6a6176612f6c616e672f496e74656765723b78700074000774696d656f75747372000e6a6176612e6c616e672e4c6f6e673b8be490cc8f23df0200014a000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b02000078700000000000450006737200116a6176612e6c616e672e496e746567657212e2a0a4f781873802000149000576616c75657871007e000700000000')

This explaines why new timers can be accessed by handles when jboss keeps running, and can not after a restart.

[komet_1978]

"jaikiran" wrote:
In addition to what Dimitris asked for - is this EJB3 or EJB 2.x? And please post the entire exception stacktrace.

This is EJB 3. As you can see, the cancel method gets a TimerHandle which has been created before the restart. The id of the corresponding timer is 1255092103925.

I checked the timers table after the restart and there was no timer with this id. Although no timer had a timeout event and no timer has been canceled. And as already mentioned this exception never comes up without a restart.

Here is the main part of the exception stacktrace:

ENTER cancelTimer([id=1255092103925,target=[target=....jar,name=EETimerService,service=EJB3],first=12-Okt-2009 02:45:49.031,periode=0])
15:01:44,687 ERROR [EETimerService,19] javax.ejb.NoSuchObjectLocalException: Timer not available: [target=jboss.j2ee:ear=jabcee-server-SNAPSHOT.ear,jar=jabcee-server-ejb-SNAPSHOT.jar,name=EETimerService,service=EJB3]
 at ...EETimerService.cancelTimer(EETimerService.java:147)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)
 at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:69)
 at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor$InvocationContext.proceed(InvocationContextInterceptor.java:138)
 at ....EJBMethodDebugLogger.logMethod(EJBMethodDebugLogger.java:16)
 at sun.reflect.GeneratedMethodAccessor330.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.ejb3.interceptors.aop.EJB3InterceptorInterceptor.invoke(EJB3InterceptorInterceptor.java:83)
 at org.jboss.ejb3.interceptors.aop.EJB3InterceptorInterceptor.invoke(EJB3InterceptorInterceptor.java:70)
 at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:59)
 at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:73)
 at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:59)
 at sun.reflect.GeneratedMethodAccessor319.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.aop.advice.PerJoinpointAdvice.invoke(PerJoinpointAdvice.java:174)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.fillMethod(InvocationContextInterceptor.java:72)
 at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_fillMethod_18733404.invoke(InvocationContextInterceptor_z_fillMethod_18733404.java)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.setup(InvocationContextInterceptor.java:88)
 at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_setup_18733404.invoke(InvocationContextInterceptor_z_setup_18733404.java)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:62)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:56)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:68)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)
 at org.jboss.aspects.tx.TxInterceptor$RequiresNew.invoke(TxInterceptor.java:261)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.security.Ejb3AuthenticationInterceptorv2.invoke(Ejb3AuthenticationInterceptorv2.java:186)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:41)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
 at org.jboss.ejb3.session.SessionSpecContainer.invoke(SessionSpecContainer.java:176)
 at org.jboss.ejb3.session.SessionSpecContainer.invoke(SessionSpecContainer.java:216)
 at org.jboss.ejb3.proxy.impl.handler.session.SessionProxyInvocationHandlerBase.invoke(SessionProxyInvocationHandlerBase.java:207)
 at org.jboss.ejb3.proxy.impl.handler.session.SessionProxyInvocationHandlerBase.invoke(SessionProxyInvocationHandlerBase.java:164)
 at $Proxy457.cancelTimer(Unknown Source)
...
Caused by: javax.ejb.NoSuchObjectLocalException: Timer not available: [target=...,name=EETimerService,service=EJB3]
 at org.jboss.ejb.txtimer.TimerHandleImpl.getTimer(TimerHandleImpl.java:203)
 at
...EETimerService.cancelTimer(EETimerService.java:143)
 ... 322 more

[komet_1978]

My workaround is:

On start up I iterate over all Timers and synchronize their handles with my entities. Then the handles stored in the entities can be used to access the recreated timers.

There is no other solution at the moment without such kind of overhead, I'm afraid.