[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Thomas Diesler updated JBPM-2036: --------------------------------- Summary: StaleObjectStateException when timer ends process (was: StaleObjectStateException when timer firing leads to process end and timer has 'repeat' attribute set) -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Martin Putz updated JBPM-2036: ------------------------------ Summary: StaleObjectStateException when repeating timer signals the token (was: StaleObjectStateException when timer ends process) Description: With the following timer definition on a state node <state name='state1'> <timer name='timer-to-end-with-repeat' duedate='1 second' repeat='5 seconds'> <action class='org.jbpm.scheduler.exe.TimerDbTest$Signal' /> </timer> <transition name='to_state2' to='state2'/> </state> and the action class execute() method being public void execute(ExecutionContext executionContext) throws Exception { executionContext.leaveNode(); } leads to: 2009-02-10 21:38:45,404 16508 ERROR [org.hibernate.event.def.AbstractFlushingEventListener] (JbpmJobExecutor:127.0.0.1:1:) 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#86] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1769) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) 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:226) at org.jbpm.persistence.db.DbPersistenceService.endTransaction(DbPersistenceService.java:131) at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:197) at org.jbpm.svc.Services.close(Services.java:243) at org.jbpm.JbpmContext.close(JbpmContext.java:133) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:194) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:61) If 'repeat' is not set, the token is leaving the state as expected. was: With the following timer definition on a state node <state name='state1'> <timer name='timer-to-end-with-repeat' duedate='1 second' repeat='5 seconds'> <action class='org.jbpm.scheduler.exe.TimerDbTest$Signal' /> </timer> <transition name='to_end' to='end'/> </state> and the action class execute() method being public void execute(ExecutionContext executionContext) throws Exception { executionContext.leaveNode(); } leads to: 2009-02-10 21:38:45,404 16508 ERROR [org.hibernate.event.def.AbstractFlushingEventListener] (JbpmJobExecutor:127.0.0.1:1:) 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#86] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1769) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) 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:226) at org.jbpm.persistence.db.DbPersistenceService.endTransaction(DbPersistenceService.java:131) at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:197) at org.jbpm.svc.Services.close(Services.java:243) at org.jbpm.JbpmContext.close(JbpmContext.java:133) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:194) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:61) If 'repeat' is not set, the process finishes just fine. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Thomas Diesler updated JBPM-2036: --------------------------------- Component/s: Core Engine I added the test case which currently fails with [tdiesler@tddell trunk]$ mvn -Dtest=JBPM2036Test test Caused by: org.hibernate.ObjectDeletedException: deleted object would be re-saved by cascade (remove deleted object from associations): [org.jbpm.instantiation.Delegation#1] at org.hibernate.impl.SessionImpl.forceFlush(SessionImpl.java:1014) at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:165) at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.performSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:94) at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70) at org.hibernate.impl.SessionImpl.fireSaveOrUpdate(SessionImpl.java:507) at org.hibernate.impl.SessionImpl.saveOrUpdate(SessionImpl.java:499) at org.hibernate.engine.CascadingAction$5.cascade(CascadingAction.java:218) at org.hibernate.engine.Cascade.cascadeToOne(Cascade.java:268) at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:216) at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169) at org.hibernate.engine.Cascade.cascade(Cascade.java:130) at org.hibernate.event.def.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:131) at org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:122) at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:65) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26) 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:226) at org.jbpm.persistence.db.DbPersistenceService.endTransaction(DbPersistenceService.java:131) -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Work on JBPM-2036 started by Thomas Diesler. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Work on JBPM-2036 stopped by Thomas Diesler. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Alejandro Guizar commented on JBPM-2036: ---------------------------------------- I have been able to reproduce the original SOSE. The conflicting queries are: 2009-02-11 13:37:40,842 DEBUG [org.jbpm.db.JobSession] deleting timers by name 'state1' for Token[name=/,node=State(state1)] 2009-02-11 13:37:40,845 DEBUG [org.hibernate.SQL] delete from JBPM_JOB where CLASS_='T' and TOKEN_=? and NAME_=? and ( LOCKOWNER_ is null or REPEAT_ is not null ) and 2009-02-11 13:37:40,868 DEBUG [org.jbpm.persistence.db.DbPersistenceService] committing org.hibernate.transaction.JDBCTransaction@ee20fe 2009-02-11 13:37:40,872 DEBUG [org.hibernate.SQL] /* update org.jbpm.job.Timer */ update JBPM_JOB set VERSION_=?, DUEDATE_=?, PROCESSINSTANCE_=?, TOKEN_=?, TASKINSTANCE_=?, ISSUSPENDED_=?, ISEXCLUSIVE_=?, LOCKOWNER_=?, LOCKTIME_=?, EXCEPTION_=?, RETRIES_=?, NAME_=?, REPEAT_=?, TRANSITIONNAME_=?, ACTION_=?, GRAPHELEMENTTYPE_=?, GRAPHELEMENT_=? where ID_=? and VERSION_=? Thinking about a solution right now... -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Alejandro Guizar resolved JBPM-2036. ------------------------------------ Resolution: Done PostgreSQL indicated precisely what the violation was. It even did so in Spanish :-) 2009-02-12 13:55:09,048 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: 23503 2009-02-12 13:55:09,048 ERROR [org.hibernate.util.JDBCExceptionReporter] ERROR: update o delete en «jbpm_delegation» viola la llave foránea «fk_action_actndel» en la tabla «jbpm_action» Detail: La llave (id_)=(10) todavía es referida desde la tabla «jbpm_action». Anyhow, these little informative logs allowed me to find out that a duplicate of the Timer.action entity was being saved in JobSession unnecessarily. The duplicate Action entity referenced the original Delegation entity and prevented the Delegation from being deleted. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Alejandro Guizar commented on JBPM-2036: ---------------------------------------- David, the 3.2.4 and 3.2.5 releases are in fact the same as 3.3.0 and 3.3.1 sans the GWT console. Going forward we will continue maintaining the 3.2.x branch. The GWT console will focus on jBPM 4. Hence 3.2.6 can be considered the successor to 3.3.1 as well. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] David Roberts commented on JBPM-2036: ------------------------------------- Thanks Alejandro. I have posted a thread regarding a timer issue which I have noticed in the latest Jbpm 3.2.6 SNAPSHOT. I am guessing it may be related to this Jira issue fix, as above you commented "Resolved the SOSE by not deleting repeating timers, simply preventing further repetitions". Basically, when a task instance ends, the timer attached to it is not deleted until its due date is up again, and it runs one more time. This could be undesirable as perhaps we don't want to timer to run if the task has ended? Please see the post at: http://www.jboss.org/index.html?module=bb&op=viewtopic&t=150919 Kind regards -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Alejandro Guizar updated JBPM-2036: ----------------------------------- Comment: was deleted -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Alejandro Guizar commented on JBPM-2036: ---------------------------------------- Merged fix into 3.2.5.SP2 in 3994. Not resolving yet in order to address the remark made by David. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Alejandro Guizar commented on JBPM-2036: ---------------------------------------- I just committed an update (to branch 3.2.5.SP) that unlocks the timer right after calculating the next due date so that: (a) any job executor thread can acquire it next time (b) other parts of the engine know it is not executing, and can be deleted Robert, I changed JBPM2036Test so that it covered the situation you mentioned in your forum post. I will merge into trunk later today. Could you please verify that the update fixes the anomalous behavior at your site? -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] David Roberts commented on JBPM-2036: ------------------------------------- I checked out the latest trunk, and seems to work now, thanks. However, I am now receiving an exception which I didn't before, and im not sure if its related to this issue? If I have a Timer attached to a Task, and I create the process instance which in turn creates the first task with that attached timer, when calling taskInstance.start(actorId), I get the following exception: ERROR JbpmJobExecutor@192.168.8.114:1 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.graph.exe.Token#25] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2407) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2307) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2607) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:92) 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:142) 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:226) at org.jbpm.persistence.db.DbPersistenceService.endTransaction(DbPersistenceService.java:131) at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:197) at org.jbpm.svc.Services.close(Services.java:243) at org.jbpm.JbpmContext.close(JbpmContext.java:133) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:200) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:63) INFO JbpmJobExecutor@192.168.8.114:1 org.jbpm.persistence.db.DbPersistenceService - problem committing transaction: optimistic locking failed INFO JbpmJobExecutor@192.168.8.114:1 org.jbpm.svc.Services - optimistic locking failed, could not close service: persistence -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Alejandro Guizar reopened JBPM-2036: ------------------------------------ Container matrix failed in MySQL for no apparent reason. http://jbpm.dyndns.org:8280/hudson/job/jBPM325-Container-Matrix/5/ -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ https://jira.jboss.org/jira/browse/JBPM-2036?page=com.atlassian.jira.plug... ] Sunil S commented on JBPM-2036: ------------------------------- Hi, I am using JBPM 3.2.6.GA within Seam 2.0.2.SP1 and I am still seeing this issue. Here is the extract from the logs, SOSE is at the end. 0:34:30,375 DEBUG [GraphElement] event 'node-enter' on Node(timer-node) for Token(/) 00:34:30,406 DEBUG [GraphElement] executing CreateTimerAction@1be4a09 00:34:30,406 DEBUG [Token] token[1] is locked by token[1] 00:34:30,406 DEBUG [GraphElement] event 'timer-create' on Node(timer-node) for Token(/) 00:34:30,437 DEBUG [JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]' 00:34:30,437 DEBUG [JbpmContext] creating org.jbpm.JbpmContext@111430 00:34:30,437 DEBUG [JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]' 00:34:30,437 DEBUG [JbpmContext] creating org.jbpm.JbpmContext@14494ca 00:34:30,437 DEBUG [JbpmContext] closing jbpmContext org.jbpm.JbpmContext@14494ca 00:34:30,437 DEBUG [DbPersistenceServiceFactory] creating persistence service 00:34:30,437 DEBUG [DbPersistenceService] creating hibernate session 00:34:30,484 DEBUG [JbpmContext] closing jbpmContext org.jbpm.JbpmContext@111430 00:34:30,484 DEBUG [Services] executing default save operations 00:34:30,500 DEBUG [HibernateSaveOperation] saving process instance 00:34:30,500 DEBUG [SaveLogsOperation] posting logs to logging service. 00:34:30,500 DEBUG [CascadeSaveOperation] cascading save of 'ProcessInstance(1)' 00:34:30,500 DEBUG [Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@10c6402 00:34:30,500 DEBUG [DbPersistenceService] flushing SessionImpl(PersistenceContext[entityKeys=[EntityKey[org.jbpm.module.exe.ModuleInstance#2], EntityKey[org.jbpm.module.exe.ModuleInstance#1], EntityKey[org.jbpm.graph.exe.ProcessInstance#1]],collectionKeys=[CollectionKey[org.jbpm.context.exe.ContextInstance.tokenVariableMaps#1], CollectionKey[org.jbpm.graph.exe.ProcessInstance.runtimeActions#1], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances#2], CollectionKey[org.jbpm.graph.exe.ProcessInstance.instances#1], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#2]]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]]) 00:34:30,500 DEBUG [DbPersistenceService] closing hibernate session 00:34:30,500 DEBUG [Services] closing service 'tx': org.jbpm.tx.TxService@1741027 00:34:30,500 DEBUG [Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@d08bdb 00:34:30,500 DEBUG [Token] token[1] is unlocked by token[1] 00:34:30,515 DEBUG [GraphElement] executing Action(#{planTest.setCount(0)}) 00:34:30,515 DEBUG [JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]' 00:34:30,515 DEBUG [JbpmContext] creating org.jbpm.JbpmContext@e6065d 00:34:30,515 DEBUG [JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]' 00:34:30,515 DEBUG [JbpmContext] creating org.jbpm.JbpmContext@1abec22 00:34:30,515 DEBUG [JbpmContext] closing jbpmContext org.jbpm.JbpmContext@1abec22 00:34:30,531 DEBUG [DbPersistenceServiceFactory] creating persistence service 00:34:30,531 DEBUG [DbPersistenceService] creating hibernate session 00:34:30,640 INFO [PlanTestAction] ->setCount(0) 00:34:30,640 DEBUG [VariableContainer] update variable 'count' in 'TokenVariableMap[/]' to value '0' 00:34:30,687 DEBUG [JbpmContext] closing jbpmContext org.jbpm.JbpmContext@e6065d 00:34:30,703 DEBUG [Services] executing default save operations 00:34:30,703 DEBUG [HibernateSaveOperation] saving process instance 00:34:30,703 DEBUG [SaveLogsOperation] posting logs to logging service. 00:34:30,718 DEBUG [CascadeSaveOperation] cascading save of 'ProcessInstance(1)' 00:34:30,718 DEBUG [Services] executing default save operations 00:34:30,718 DEBUG [HibernateSaveOperation] saving process instance 00:34:30,718 DEBUG [SaveLogsOperation] posting logs to logging service. 00:34:30,718 DEBUG [CascadeSaveOperation] cascading save of 'ProcessInstance(1)' 00:34:30,718 DEBUG [Services] executing default save operations 00:34:30,718 DEBUG [HibernateSaveOperation] saving process instance 00:34:30,718 DEBUG [SaveLogsOperation] posting logs to logging service. 00:34:30,718 DEBUG [CascadeSaveOperation] cascading save of 'ProcessInstance(1)' 00:34:30,718 DEBUG [Services] executing default save operations 00:34:30,718 DEBUG [HibernateSaveOperation] saving process instance 00:34:30,718 DEBUG [SaveLogsOperation] posting logs to logging service. 00:34:30,718 DEBUG [CascadeSaveOperation] cascading save of 'ProcessInstance(1)' 00:34:30,718 DEBUG [Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@164e7e6 00:34:30,718 DEBUG [DbPersistenceService] flushing SessionImpl(PersistenceContext[entityKeys=[EntityKey[org.jbpm.graph.exe.Token#1], EntityKey[org.jbpm.context.exe.VariableInstance#1], EntityKey[org.jbpm.context.exe.TokenVariableMap#1], EntityKey[org.jbpm.module.exe.ModuleInstance#2], EntityKey[org.jbpm.module.exe.ModuleInstance#1], EntityKey[org.jbpm.graph.exe.ProcessInstance#1], EntityKey[org.jbpm.context.log.variableinstance.LongUpdateLog#179]],collectionKeys=[CollectionKey[org.jbpm.context.exe.TokenVariableMap.variableInstances#1], CollectionKey[org.jbpm.graph.exe.Token.children#1], CollectionKey[org.jbpm.graph.exe.ProcessInstance.runtimeActions#1], CollectionKey[org.jbpm.context.exe.ContextInstance.tokenVariableMaps#1], CollectionKey[org.jbpm.graph.exe.Token.comments#1], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances#2], CollectionKey[org.jbpm.graph.exe.ProcessInstance.instances#1], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#2]]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]]) 00:34:30,718 DEBUG [DbPersistenceService] closing hibernate session 00:34:30,718 DEBUG [Services] closing service 'tx': org.jbpm.tx.TxService@2e5a01 00:34:30,718 DEBUG [Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@1171477 00:34:30,718 DEBUG [JobSession] deleted Job(1) 00:34:30,718 DEBUG [JbpmContext] closing jbpmContext org.jbpm.JbpmContext@178b9e6 00:34:30,718 DEBUG [Services] executing default save operations 00:34:30,718 DEBUG [HibernateSaveOperation] saving process instance 00:34:30,718 DEBUG [SaveLogsOperation] posting logs to logging service. 00:34:30,828 DEBUG [CascadeSaveOperation] cascading save of 'ProcessInstance(1)' 00:34:30,828 DEBUG [Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@af8d28 00:34:30,828 DEBUG [DbPersistenceService] flushing SessionImpl(PersistenceContext[entityKeys=[EntityKey[org.jbpm.graph.def.ProcessDefinition#1], EntityKey[org.jbpm.graph.exe.Token#1], EntityKey[org.jbpm.graph.log.ActionLog#180], EntityKey[org.jbpm.graph.def.Node#3], EntityKey[org.jbpm.graph.def.Event#3], EntityKey[org.jbpm.graph.log.NodeLog#181], EntityKey[org.jbpm.graph.def.Node#4], EntityKey[org.jbpm.graph.exe.ProcessInstance#1], EntityKey[org.jbpm.graph.def.Event#1], EntityKey[org.jbpm.job.Timer#26], EntityKey[org.jbpm.job.Job#1], EntityKey[org.jbpm.graph.def.Event#2], EntityKey[org.jbpm.graph.log.ActionLog#184], EntityKey[org.jbpm.graph.log.ActionLog#183], EntityKey[org.jbpm.graph.log.TransitionLog#182], EntityKey[org.jbpm.graph.def.Transition#3], EntityKey[org.jbpm.module.exe.ModuleInstance#2], EntityKey[org.jbpm.module.exe.ModuleInstance#1], EntityKey[org.jbpm.graph.def.Action#2], EntityKey[org.jbpm.graph.def.Action#1], EntityKey[org.jbpm.graph.def.Action#4]],collectionKeys=[CollectionKey[org.jbpm.graph.def.ProcessDefinition.definitions#1], CollectionKey[org.jbpm.graph.def.ProcessDefinition.nodes#1], CollectionKey[org.jbpm.graph.exe.Token.comments#1], CollectionKey[org.jbpm.graph.def.Node.arrivingTransitions#4], CollectionKey[org.jbpm.graph.def.Node.arrivingTransitions#3], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#2], CollectionKey[org.jbpm.graph.def.Node.exceptionHandlers#3], CollectionKey[org.jbpm.graph.def.Node.exceptionHandlers#4], CollectionKey[org.jbpm.graph.exe.Token.children#1], CollectionKey[org.jbpm.context.exe.ContextInstance.tokenVariableMaps#1], CollectionKey[org.jbpm.graph.def.Transition.exceptionHandlers#3], CollectionKey[org.jbpm.graph.def.Node.events#4], CollectionKey[org.jbpm.graph.def.Node.events#3], CollectionKey[org.jbpm.graph.def.Event.actions#1], CollectionKey[org.jbpm.graph.def.Node.leavingTransitions#3], CollectionKey[org.jbpm.graph.def.Node.leavingTransitions#4], CollectionKey[org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#1], CollectionKey[org.jbpm.graph.def.Event.actions#3], CollectionKey[org.jbpm.graph.def.Event.actions#2], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances#2], CollectionKey[org.jbpm.graph.exe.ProcessInstance.instances#1], CollectionKey[org.jbpm.graph.def.ProcessDefinition.events#1], CollectionKey[org.jbpm.graph.def.ProcessDefinition.actions#1], CollectionKey[org.jbpm.graph.exe.ProcessInstance.runtimeActions#1], CollectionKey[org.jbpm.graph.def.Transition.events#3]]];ActionQueue[insertions=[] updates=[] deletions=[EntityDeleteAction[org.jbpm.job.ExecuteNodeJob#1]] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]]) 00:34:30,843 ERROR [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.graph.exe.Token#1] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2407) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2307) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2607) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:92) 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:142) 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.jbpm.persistence.db.DbPersistenceService.flushSession(DbPersistenceService.java:261) at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:200) at org.jbpm.svc.Services.close(Services.java:243) at org.jbpm.JbpmContext.close(JbpmContext.java:133) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:195) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:62) 00:34:30,843 INFO [DbPersistenceService] problem flushing session: optimistic locking failed 00:34:30,843 DEBUG [DbPersistenceService] closing hibernate session 00:34:30,843 INFO [Services] optimistic locking failed, could not close service: persistence 00:34:30,843 DEBUG [Services] closing service 'tx': org.jbpm.tx.TxService@15c00fd 00:34:30,843 DEBUG [Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService@145028a 00:34:30,843 DEBUG [DbSchedulerService] timers were produced, job executor will be signalled 00:34:30,843 DEBUG [Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@1a9cb4b 00:34:30,843 DEBUG [JobExecutorThread] optimistic locking failed, could not complete job Job(1) -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira