[jbpm-users] [JBoss jBPM] - Problem using multiple timers

nikosd23 do-not-reply at jboss.com
Fri Jun 19 06:18:36 EDT 2009


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:
anonymous wrote : 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

View the original post : http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4238723#4238723

Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=4238723



More information about the jbpm-users mailing list