Timers get cancelled in TimerServiceBean.ejbTimeout even Run

[supterlobster]

Hi,

In a processdef, one fork leads to several states, each state has a timer attached. The idea is to do concurrent async executions through the TimerServiceBean. However, get exceptions, when those states changing to join node.

Caused by: org.jbpm.graph.def.DelegationException: Row was updated or deleted by another transaction (or u
nsaved-value mapping was incorrect): [org.jbpm.graph.exe.Token#177]
at org.jbpm.graph.def.GraphElement.raiseException(GraphElement.java:367)
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.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.jav
a:173)
at org.jbpm.graph.def.ProcessDefinition_$$_javassist_98.raiseException(ProcessDefinition_$$_javass
ist_98.java)
at org.jbpm.graph.def.GraphElement.raiseException(GraphElement.java:358)
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.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.jav
a:173)
at org.jbpm.graph.node.State_$$_javassist_89.raiseException(State_$$_javassist_89.java)
at org.jbpm.job.Timer.execute(Timer.java:66)
at org.jbpm.scheduler.ejbtimer.ExecuteTimerCommand.execute(ExecuteTimerCommand.java:23)
at org.jbpm.ejb.impl.CommandServiceBean.execute(CommandServiceBean.java:90)
... 42 more

This is acceptable if things can rollback. However when this happens, timers still been cancelled, so the actions will never been retried and the process sitting dead:

2007-06-23 02:05:15,627 996227 DEBUG [org.jbpm.svc.Services] (EJB-Timer-7[target=jboss.j2ee:jndiName=local
/TimerServiceBean@11364891,service=EJB]:) closing service 'persistence': org.jbpm.persistence.jta.JtaDbPer
sistenceService@698193
2007-06-23 02:05:15,627 996227 DEBUG [org.jbpm.persistence.db.DbPersistenceService] (EJB-Timer-7[target=jb
oss.j2ee:jndiName=local/TimerServiceBean@11364891,service=EJB]:) committing hibernate transaction
2007-06-23 02:05:15,628 996228 DEBUG [org.hibernate.transaction.CMTTransaction] (EJB-Timer-7[target=jboss.
j2ee:jndiName=local/TimerServiceBean@11364891,service=EJB]:) commit
2007-06-23 02:05:15,628 996228 DEBUG [org.jbpm.svc.Services] (EJB-Timer-7[target=jboss.j2ee:jndiName=local
/TimerServiceBean@11364891,service=EJB]:) closing service 'scheduler': org.jbpm.scheduler.ejbtimer.EjbSche
dulerService@b9ec0e
2007-06-23 02:05:15,628 996228 DEBUG [org.jbpm.scheduler.ejbtimer.EjbSchedulerService] (EJB-Timer-7[target
=jboss.j2ee:jndiName=local/TimerServiceBean@11364891,service=EJB]:) removing the timer service session bea
n
2007-06-23 02:05:15,631 996231 DEBUG [org.jbpm.svc.Services] (EJB-Timer-8[target=jboss.j2ee:jndiName=local
/TimerServiceBean@11364891,service=EJB]:) closing service 'tx': org.jbpm.tx.TxService@38be48
2007-06-23 02:05:15,632 996232 ERROR [org.jboss.ejb.plugins.LogInterceptor] (EJB-Timer-8[target=jboss.j2ee
:jndiName=local/TimerServiceBean@11364891,service=EJB]:) TransactionRolledbackLocalException in method: pu
blic abstract java.lang.Object org.jbpm.command.CommandService.execute(org.jbpm.command.Command), causedBy
:
org.jbpm.JbpmException: couldn't execute org.jbpm.scheduler.ejbtimer.ExecuteTimerCommand@2d0914
at org.jbpm.ejb.impl.CommandServiceBean.execute(CommandServiceBean.java:92)
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.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.j
ava:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterce
ptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterc
eptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)

Should Timer.cancel() rollback facing a RuntimeException in JTA transactions? I tried both JTA and CMP for hibernate, no luck. Did I miss something?

Justin

[supterlobster]

jbpm.cfg.xml

<jbpm-context>
<service name="persistence" factory="org.jbpm.persistence.jta.JtaDbPersistenceServiceFactory" >
 <field name="sessionFactoryJndiName">
 <string value="java:/WorkflowSessionFactory" />
 </field>
 <field name="isCurrentSessionEnabled"><true /></field>
 <field name="isTransactionEnabled"><false /></field>
 </service>
 <service name="message" factory="org.jbpm.msg.jms.JmsMessageServiceFactoryImpl" />
 <service name="scheduler" factory="org.jbpm.scheduler.ejbtimer.EjbSchedulerServiceFactory" />
 <service name="tx" factory="org.jbpm.tx.TxServiceFactory" />
 <service name="logging" factory="org.jbpm.logging.db.DbLoggingServiceFactory" />
 <service name="authentication" factory="org.jbpm.security.authentication.DefaultAuthenticationServiceFactory" />
 </jbpm-context>

hibernate.cfg.xml

<session-factory name="java:/WorkflowSessionFactory">

 <!-- hibernate dialect -->
 <property name="hibernate.dialect">org.hibernate.dialect.Oracle9Dialect</property>

 <!-- JDBC connection properties (begin) ===
 <property name="hibernate.connection.driver_class">org.hsqldb.jdbcDriver</property>
 <property name="hibernate.connection.url">jdbc:hsqldb:mem:jbpm</property>
 <property name="hibernate.connection.username">sa</property>
 <property name="hibernate.connection.password"></property>
 ==== JDBC connection properties (end) -->

 <property name="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</property>

 <!-- DataSource properties (begin) -->
 <property name="hibernate.connection.datasource">java:/XAJbpmDS</property>
 <!-- DataSource properties (end) -->

 <!-- JTA transaction properties (begin)
 <property name="hibernate.transaction.factory_class">org.hibernate.transaction.JTATransactionFactory</property>
 <property name="hibernate.transaction.manager_lookup_class">org.hibernate.transaction.JBossTransactionManagerLookup</property>
 <property name="jta.UserTransaction">UserTransaction</property>
 === JTA transaction properties (end) -->

 <!-- CMT transaction properties (begin) -->
 <property name="hibernate.transaction.factory_class">org.hibernate.transaction.CMTTransactionFactory</property>
 <property name="hibernate.transaction.manager_lookup_class">org.hibernate.transaction.JBossTransactionManagerLookup</property>
 <!-- CMT transaction properties (end) -->

[supterlobster]

Ok, found the problem.

TimerService.add() does not have interval, so only one execution suppose to run. Made a small patch, works fine now.
Still, the concurrent execption is really ugly. Will try tree cache to see if any difference.

[kukeltje]

or try using ejb3 timers...

[kukeltje]

ignore previous comment (wrong thread...)