3 Replies Latest reply on Jun 19, 2009 10:52 AM by kukeltje

Problem using multiple timers

nikosd23 Jun 19, 2009 6:18 AM

Hi,

We have identified a case in which when using 2 timers in a flow we get exception. To be more specific, we use the following process-definition.xml

<?xml version="1.0" encoding="UTF-8"?>

<process-definition
 xmlns="" name="TestWait">
 <start-state name="start">
 <transition name="" to="SysOut "></transition>
 </start-state>
 <node name="SysOut ">
 <event type="node-enter">
 <action name="action1" class="com.handlers.FlowActionHandler" config-type="constructor">System.out.println('WAITING FOR '+firstTimer);</action></event>
 <transition name="" to="Wait for firstTimer"></transition></node>
 <state name="Wait for firstTimer">
 <timer duedate="4 seconds" transition="resp"><action class="com.handlers.TimeoutActionHandler"></action></timer>
 <transition name="resp" to="SysOut after 1"></transition>
 </state>
 <node name="SysOut after 1">
 <event type="node-enter">
 <action name="action1" class="com.handlers.FlowActionHandler" config-type="constructor">
 System.out.println('After first timer. Going to second timer');
 </action>
 </event>
 <transition name="" to="Wait secondTimer"></transition>
 </node>
 <state name="Wait secondTimer">
 <timer duedate="10 seconds" transition="resp"><action class="com.handlers.TimeoutActionHandler"></action></timer>
 <transition name="resp" to="SysOut after 2"></transition>
 </state>
 <node name="SysOut after 2">
 <event type="node-enter">
 <action name="action1" class="com.handlers.FlowActionHandler" config-type="constructor">System.out.println('After second wait time');
 </action>
 </event>
 <transition name="" to="end1"></transition>
 </node>
 <end-state name="end1"></end-state>
</process-definition>

The source code of TimeoutActionHandler follows:

public class TimeoutActionHandler implements ActionHandler {
 private static final long serialVersionUID = 1L;
 private Logger log = Logger.getLogger(TimeoutActionHandler.class);

 public void execute(ExecutionContext executionContext) throws Exception {

 ProcessInstance processInstance = executionContext.getProcessInstance();
 if (processInstance.getRootToken().isLocked()) {
 log.debug("A timer of Flow " + processInstance.getId() + " was skipped. The flow had been resumed.");
 return;
 }

 executionContext.setVariable(MESSAGE_CODE, "timeout");
 executionContext.leaveNode();
 }

}

The flow starts and we get in the first wait state, the token waits there for 4 seconds, then we have a System.out.println, then instead of getting in the second wait state, we get the second printout and we get errors. The errors we receive follow:

2009-06-19 10:52:18,645 INFO [STDOUT] WAITING FOR 4 seconds
2009-06-19 10:52:18,660 WARN [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] Narrowing proxy to class org.jbpm.graph.node.State - this operation breaks ==
2009-06-19 10:52:22,225 WARN [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] Narrowing proxy to class org.jbpm.job.Timer - this operation breaks ==
2009-06-19 10:52:22,310 INFO [STDOUT] After first timer. Going to second timer
2009-06-19 10:52:22,327 WARN [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] Narrowing proxy to class org.jbpm.graph.node.State - this operation breaks ==
2009-06-19 10:52:22,398 INFO [STDOUT] After second wait time
2009-06-19 10:52:22,462 ERROR [org.hibernate.event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.job.Timer#9853]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2523)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:253)
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:211)
at org.jbpm.svc.Services.close(Services.java:222)
at org.jbpm.JbpmContext.close(JbpmContext.java:139)
at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:267)
at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:71)
2009-06-19 10:52:22,469 ERROR [org.jbpm.persistence.db.DbPersistenceService] hibernate commit failed
org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.job.Timer#9853]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2523)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:253)
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:211)
at org.jbpm.svc.Services.close(Services.java:222)
at org.jbpm.JbpmContext.close(JbpmContext.java:139)
at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:267)
at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:71)
2009-06-19 10:52:22,471 ERROR [STDERR] org.jbpm.persistence.JbpmPersistenceException: hibernate commit failed
2009-06-19 10:52:22,472 ERROR [STDERR] at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:216)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.jbpm.svc.Services.close(Services.java:222)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.jbpm.JbpmContext.close(JbpmContext.java:139)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:267)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:71)
2009-06-19 10:52:22,472 ERROR [STDERR] Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.job.Timer#9853]
2009-06-19 10:52:22,472 ERROR [STDERR] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2523)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
2009-06-19 10:52:22,472 ERROR [STDERR] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146)
2009-06-19 10:52:22,473 ERROR [STDERR] at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
2009-06-19 10:52:22,473 ERROR [STDERR] at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
2009-06-19 10:52:22,473 ERROR [STDERR] at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
2009-06-19 10:52:22,473 ERROR [STDERR] at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
2009-06-19 10:52:22,473 ERROR [STDERR] at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
2009-06-19 10:52:22,473 ERROR [STDERR] at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:253)
2009-06-19 10:52:22,473 ERROR [STDERR] at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:211)
2009-06-19 10:52:22,473 ERROR [STDERR] ... 4 more
2009-06-19 10:52:22,473 ERROR [org.jbpm.svc.Services] problem closing service 'persistence'
org.jbpm.persistence.JbpmPersistenceException: hibernate commit failed
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:216)
at org.jbpm.svc.Services.close(Services.java:222)
at org.jbpm.JbpmContext.close(JbpmContext.java:139)
at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:267)
at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:71)
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.job.Timer#9853]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2523)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:253)
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:211)
... 4 more
2009-06-19 10:52:22,474 ERROR [org.jbpm.job.executor.JobExecutorThread] problem committing job execution transaction for job 9853-timer(Wait for firstTimer,10:52:22,000) (flow with id 6380)
org.jbpm.JbpmException: problem closing services {persistence=org.jbpm.persistence.JbpmPersistenceException: hibernate commit failed}
at org.jbpm.svc.Services.close(Services.java:235)
at org.jbpm.JbpmContext.close(JbpmContext.java:139)
at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:267)
at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:71)
Caused by: org.jbpm.persistence.JbpmPersistenceException: hibernate commit failed
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:216)
at org.jbpm.svc.Services.close(Services.java:222)
... 3 more
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.job.Timer#9853]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2523)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:253)
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:211)
... 4 more
2009-06-19 10:52:22,475 ERROR [org.jbpm.job.executor.JobExecutorThread] exception in job executor thread. waiting 5000 milliseconds
org.jbpm.JbpmException: problem closing services {persistence=org.jbpm.persistence.JbpmPersistenceException: hibernate commit failed}
at org.jbpm.svc.Services.close(Services.java:235)
at org.jbpm.JbpmContext.close(JbpmContext.java:139)
at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:267)
at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:71)
Caused by: org.jbpm.persistence.JbpmPersistenceException: hibernate commit failed
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:216)
at org.jbpm.svc.Services.close(Services.java:222)
... 3 more
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.job.Timer#9853]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2523)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:253)
at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:211)
... 4 more

You can see both the system outs and the errors produced. We would like to know if someone has faced the same error (and how to resolve it)or if there is a bug of jbpm that is already resolved in the new edition. We are using JBOSS 4.2.2 and jBPM 3.1

1. Re: Problem using multiple timers

kukeltje Jun 19, 2009 6:43 AM (in response to nikosd23)

do not use 'node.Äºeave' in a timer where you also have a transition specified in the timer. The transition is automatically taken if the action in the timer has finished.
Actions
2. Re: Problem using multiple timers

nikosd23 Jun 19, 2009 9:04 AM (in response to nikosd23)

Thanks a lot kukeltje!!!
You have managed with one line to solve our problem.
Actions
3. Re: Problem using multiple timers

kukeltje Jun 19, 2009 10:52 AM (in response to nikosd23)

You are most welcome. For others who read this, it is not related to multiple timers... this error occurs with one timer as well (afaik)
Actions

Go to original post