1 Reply Latest reply on Jun 19, 2006 3:44 AM by tsar_bomba

    Possible EJB persistent timer bug?

    Scott McNab Newbie

      Hello.

      I am using JBossAs 4.0.4.GA with EJB3.0 RC8 and Postgres, and have implemented a jBPM timer service as a SLSB in a similar way to this post:

      http://www.jboss.com/index.html?module=bb&op=viewtopic&t=74691

      However, after running for some time I get this exception:

      2006-06-14 19:52:18,328 ERROR [org.jboss.ejb.txtimer.TimerServiceImpl] Cannot create txtimer
      java.lang.IllegalStateException: Unable to persist timer
      at org.jboss.ejb.txtimer.DatabasePersistencePolicy.insertTimer(DatabasePersistencePolicy.java:126)
      at jrockit.reflect.VirtualNativeMethodInvoker.invoke(Ljava.lang.Object;[Ljava.lang.Object;)Ljava.lang.Object;(Unknown Source)
      at java.lang.reflect.Method.invoke(Ljava.lang.Object;[Ljava.lang.Object;I)Ljava.lang.Object;(Unknown Source)
      at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
      at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
      at $Proxy26.insertTimer(Ljava.lang.String;Lorg.jboss.ejb.txtimer.TimedObjectId;Ljava.util.Date;JLjava.io.Serializable;)V(Unknown Source)
      at org.jboss.ejb.txtimer.TimerServiceImpl.createTimer(TimerServiceImpl.java:256)
      at org.jboss.ejb.txtimer.TimerServiceImpl.createTimer(TimerServiceImpl.java:202)
      at com.vieo.ccs.server.bean.JbpmSchedulerBean.timeoutHandler(JbpmSchedulerBean.java:107)
      at jrockit.reflect.VirtualNativeMethodInvoker.invoke(Ljava.lang.Object;[Ljava.lang.Object;)Ljava.lang.Object;(Unknown Source)
      at java.lang.reflect.Method.invoke(Ljava.lang.Object;[Ljava.lang.Object;I)Ljava.lang.Object;(Unknown Source)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
      at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
      Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key violates unique constraint "timers_pk"
      at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1512)
      at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1297)
      at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:188)
      at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:430)
      at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:346)
      at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:300)
      at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:251)
      at org.jboss.ejb.txtimer.GeneralPurposeDatabasePersistencePlugin.insertTimer(GeneralPurposeDatabasePersistencePlugin.java:186)
      at org.jboss.ejb.txtimer.DatabasePersistencePolicy.insertTimer(DatabasePersistencePolicy.java:122)
      at jrockit.reflect.VirtualNativeMethodInvoker.invoke(Ljava.lang.Object;[Ljava.lang.Object;)Ljava.lang.Object;(Unknown Source)
      at java.lang.reflect.Method.invoke(Ljava.lang.Object;[Ljava.lang.Object;I)Ljava.lang.Object;(Unknown Source)
      at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
      at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
      at $Proxy26.insertTimer(Ljava.lang.String;Lorg.jboss.ejb.txtimer.TimedObjectId;Ljava.util.Date;JLjava.io.Serializable;)V(Unknown Source)
      at org.jboss.ejb.txtimer.TimerServiceImpl.createTimer(TimerServiceImpl.java:256)
      at org.jboss.ejb.txtimer.TimerServiceImpl.createTimer(TimerServiceImpl.java:202)
      at com.vieo.ccs.server.bean.JbpmSchedulerBean.timeoutHandler(JbpmSchedulerBean.java:107)


      Other people seem to be having a similar problem too:

      http://www.jboss.com/index.html?module=bb&op=viewtopic&t=84439
      http://www.jboss.com/index.html?module=bb&op=viewtopic&t=76127
      http://www.jboss.com/index.html?module=bb&op=viewtopic&t=60741

      I have spent some time investigating this and there definitely seems to be a conflict with old timers not being cleared from the database:

      My test server is up and down all the time during development (not always shutdown cleanly) and as a result there are 3 'stale' entries in the Timer database table (some a few days old even). The above exception occurs as a result of a new timer being created with the same ID as one of these stale database entries.

      I see two related causes for this:

      1. The TimerIdGenerator implementation (BigIntegerTimerIdGenerator.java) always initialises its count to 0 at system start.

      2. For some reason, the old/obsolete timers are not being cleaned from the database at startup.

      The combination of these two factors ensures that if there are stale timer entries it is only a matter of time until the new timer ID increments until it reaches the ID of an existing timer!

      It seems to me that the code causing factor 1 is inherently unsafe in a persistent environment - I would have expected the TimerIdGenerator implementation to make some kind of 'get next value' or sequence call on the database? Isn't having a transient counter like this asking for trouble in a persisted environment?

      Also, after debugging the server startup and application deployment, for some reason it appears that EJBTimerServiceImpl.restoreTimers() is never being called. The only place I can see that might invoke this are when the EntityContainer and SessionContainer classes are started, yet this does not appear to happen (possibly because I am looking at JBossAS source code only?) I don't have the EJB3 source but maybe the EJB3 container does not make this call?

      This seems to me to be a critical problem with EJB timers and I hope what I have said makes sense and can be fixed.

      Thanks
      Scott

        • 1. Re: Possible EJB persistent timer bug?
          tsar_bomba Newbie

          Hi Scott,

          I'm in one of those posts you mentioned...and it appears that this is just one of those things that is falling on deaf ears. It would seem that it's a pretty obvious problem and is perhaps in the process of being fixed.

          I'm having other problems w/ timers and my @Timeout methods are occasionally throwing an IllegalStateException and I can't seem to figure out why...either way Timers are completely unreliable for me in the current implementation of JBoss AS.

          Once this hurdle is covered I can sleep better (my app is relying on two timers that need to be running!)