12 Replies Latest reply on Aug 25, 2009 11:59 AM by Ronald van Kuijk

    StaleObjectException in JBPM 4.0

    Mustafa Musaji Novice

      After doing much reading and checking up on this I've still not found a solution that works. I'm using a MYSQL database and I've updated the ISOLATION LEVEL to read committed but still getting a StaleObjectException when my workflow goes through the fork.

      Is there any other updates to this or a workaround. It does always occur but sometimes more than other times and not necessarily at the same time in the flow.

        • 2. Re: StaleObjectException in JBPM 4.0
          Ronald van Kuijk Master

          Configuration? Versions of other things etc...etc...etc...

          • 3. Re: StaleObjectException in JBPM 4.0
            Mustafa Musaji Novice

            Apologies Ronald, I was hoping for more of a discussion as opposed to a solution to my specific problem.

            Here's the fork and join from my workflow.

            <java class="org.workflow.FindProviders" g="276,7,80,40" method="execute" name="find providers">
             <transition name="" to="fork"/>
             </java>
            
             <fork g="298,85,80,40" name="fork">
             <transition g="-62,-18" name="validate red" to="validate red request"/>
             <transition g="-64,-18" name="validate exp" to="validate exp request"/>
             <transition g="-63,-17" name="validate sys" to="validate sys request"/>
             </fork>
            
             <custom continue="async" name="validate red request" class="org.workflow.Validate1" exp="#{myFirstObj}">
             <transition g="-27,-18" name="" to="join"/>
             </custom>
            
             <custom continue="async" name="validate exp request" class="org.workflow.Validate2" exp="#{mySecondObj}">
             <transition g="-27,-18" name="" to="join"/>
             </custom>
            
             <custom continue="async" name="validate sys request" class="org.workflow.Validate3" exp="#{myThirdObj}">
             <transition g="-27,-18" name="" to="join"/>
             </custom>
            
             <join g="267,368,80,40" name="join">
             <transition name="check results" to="evaluate validation results" g="-47,-16"/>
             </join>
            ...
            


            Starting the process using JobExecutor config
            <jbpm-configuration>
            
             <process-engine-context>
            
             <job-executor threads="5" idle="10" idle-max="0" lock-millis="0" />
            
             </process-engine-context>
            
            </jbpm-configuration>


            Using MySQL and everytime I run the forks run concurrently as expected. But then sometimes in between the forks or sometimes after I get this exception

            org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.pvm.internal.model.ExecutionImpl#53]
             at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1792)
             at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2435)
             at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
             at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
             at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:115)
             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:321)
             at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:64)
             at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:996)
             at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1141)
             at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
             at org.jbpm.pvm.internal.hibernate.DbSessionImpl.deleteProcessDefinitionHistory(DbSessionImpl.java:165)
             at org.jbpm.pvm.internal.cmd.DeleteDeploymentCmd.execute(DeleteDeploymentCmd.java:77)
             at org.jbpm.pvm.internal.svc.DefaultCommandService.execute(DefaultCommandService.java:42)
             at org.jbpm.pvm.internal.tx.StandardTransactionInterceptor.execute(StandardTransactionInterceptor.java:54)
             at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.execute(EnvironmentInterceptor.java:54)
             at org.jbpm.pvm.internal.svc.RetryInterceptor.execute(RetryInterceptor.java:55)
             at org.jbpm.pvm.internal.repository.RepositoryServiceImpl.deleteDeploymentCascade(RepositoryServiceImpl.java:70)
             at biz.thelogicgroup.fraudswitch.workflow.FraudWorkflowTest.tearDown(FraudWorkflowTest.java:76)
             at junit.framework.TestCase.runBare(TestCase.java:130)
             at junit.framework.TestResult$1.protect(TestResult.java:106)
             at junit.framework.TestResult.runProtected(TestResult.java:124)
             at junit.framework.TestResult.run(TestResult.java:109)
             at junit.framework.TestCase.run(TestCase.java:118)
             at junit.framework.TestSuite.runTest(TestSuite.java:208)
             at junit.framework.TestSuite.run(TestSuite.java:203)
             at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
             at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
             at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
             at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
             at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
             at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
            ### EXCEPTION ###########################################
            ### EXCEPTION ###########################################
            


            I read somewhere this is expected behaviour but this surely can't be right... can it?

            • 4. Re: StaleObjectException in JBPM 4.0
              Mustafa Musaji Novice

              Forgot to add, as you can see each fork is working on a different object. I thought I would try this as I was getting StaleObjectExceptions when they were working on the same object (understandable I thought!).

              My previous thread before I got job executor working shows the old config.

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

              But now they are all working on different objects I don't get why each fork cares what the other objects are doing?

              • 5. Re: StaleObjectException in JBPM 4.0
                Mustafa Musaji Novice

                Looking at a recent post:

                http://www.jboss.org/index.html?module=bb&op=viewtopic&t=160091&postdays=0&postorder=asc&start=0

                I am assuming now that this Exception is just "expected" behaviour, which is a little annoying but not much I can do about it from the sounds of it.

                However, my workflow seems to not be working despite this. Sometimes it will run to the end of the workflow and other times it will halt at the join?

                Any help would be greatly appreciated.

                My workflow:

                <?xml version="1.0" encoding="UTF-8"?>
                
                <process name="process" xmlns="http://jbpm.org/4.0/jpdl">
                 <start>
                 <transition to="parse request"/>
                 </start>
                
                 <custom exp="#{mainObj}" class="org.application.workflow.ProcessRequest" name="process request">
                 <transition to="evaluate process request result"/>
                 </custom>
                
                 <decision name="evaluate process request result" expr="#{content}" >
                 <transition name="valid" to="find providers" />
                 <transition name="invalid" to="error"/>
                 </decision>
                
                 <java class="org.application.workflow.FindProviders" method="execute" name="find providers">
                 <transition to="fork"/>
                 </java>
                
                 <fork name="fork">
                 <transition name="validate red" to="validate red request"/>
                 <transition name="validate exp" to="validate exp request"/>
                 <transition name="validate sys" to="validate sys request"/>
                 </fork>
                
                 <custom continue="async" name="validate red request" class="org.application.workflow.ValidateReDFraudRequest" exp="#{redObj}">
                 <transition to="join"/>
                 </custom>
                
                 <custom continue="async" name="validate exp request" class="org.application.workflow.ValidateExpFraudRequest" exp="#{expObj}">
                 <transition to="join"/>
                 </custom>
                
                 <custom continue="async" name="validate sys request" class="org.application.workflow.ValidateSysFraudRequest" exp="#{sysObj}">
                 <transition to="join"/>
                 </custom>
                
                 <join name="join">
                 <transition continue="exclusive" name="check results" to="evaluate validation results"/>
                 </join>
                
                 <decision name="evaluate validation results" expr="#{content}" >
                 <transition name="valid" to="construct message" />
                 <transition name="invalid" to="error"/>
                 </decision>
                
                 <java class="org.application.workflow.ConstructRequest" method="execute" name="construct message">
                 <transition to="send"/>
                 </java>
                
                 <java class="org.application.workflow.SendRequest" method="execute" name="send">
                 <transition to="get responses"/>
                 </java>
                
                 <java class="org.application.workflow.GetResponse" method="execute" name="get responses">
                 <transition to="process responses"/>
                 </java>
                
                 <java class="org.application.workflow.ProcessResponse" method="execute" name="process responses">
                 <transition name="complete" to="getmainObject"/>
                 <transition name="process" to="find providers"/>
                 <transition name="error" to="error"/>
                 </java>
                
                 <custom name="getmainObject" class="org.application.workflow.GetmainObject" exp="#{mainObj}">
                 <transition to="end"/>
                 </custom>
                
                 <task name="end">
                 <transition name="to complete" to="end process"/>
                 </task>
                
                 <end name="end process" state="complete"/>
                 <end-error name="error"/>
                
                 </process>
                


                My Unit test:
                 protected void setUp() throws Exception {
                 super.setUp();
                
                 variables.put("content", "valid");
                
                 //create main object
                 mainObj = new MainObject("001");
                
                 //create other object information
                 expObj = new ExpObject();
                 expObj.setName("exp Name");
                 expObj.setDetails("some exp details");
                
                
                 sysObj = new SysObj();
                 sysObj.setName("sys Name");
                 sysObj.setDetails("Sys Details");
                
                 redObj = new RedObj();
                 redObj.setName("red Name");
                 redObj.setDetails("red details");
                
                 variables.put("mainObj", mainObj);
                 variables.put("redObj", redObj);
                 variables.put("expObj", expObj);
                 variables.put("sysObj", sysObj);
                
                 deploymentDbid = repositoryService.createDeployment()
                 .addResourceFromClasspath("org/application/workflow/process.jpdl.xml")
                 .deploy();
                 }
                
                 public void testSimple() {
                
                 ProcessInstance processInstance = executionService.startProcessInstanceByKey("process", variables);
                 String processInstanceId = processInstance.getId();
                
                 }
                



                My output:
                13:05:21,077 FIN | [BaseJbpmTestCase] === starting testSimple =============================
                13:05:21,217 FIN | [BaseJbpmTestCase] using ProcessEngine 6301159
                13:05:21,280 INF | [Environment] Hibernate 3.3.1.GA
                13:05:21,280 INF | [Environment] hibernate.properties not found
                13:05:21,280 INF | [Environment] Bytecode provider name : javassist
                13:05:21,280 INF | [Environment] using JDK 1.4 java.sql.Timestamp handling
                13:05:21,311 INF | [Configuration] configuring from resource: jbpm.hibernate.cfg.xml
                13:05:21,311 INF | [Configuration] Configuration resource: jbpm.hibernate.cfg.xml
                13:05:21,342 INF | [Configuration] Reading mappings from resource : jbpm.repository.hbm.xml
                13:05:21,420 INF | [Configuration] Reading mappings from resource : jbpm.execution.hbm.xml
                13:05:21,483 INF | [Configuration] Reading mappings from resource : jbpm.history.hbm.xml
                13:05:21,514 INF | [Configuration] Reading mappings from resource : jbpm.task.hbm.xml
                13:05:21,530 INF | [Configuration] Reading mappings from resource : jbpm.identity.hbm.xml
                13:05:21,530 INF | [Configuration] Configured SessionFactory: null
                13:05:21,545 INF | [DriverManagerConnectionProvider] Using Hibernate built-in connection pool (not for production use!)
                13:05:21,545 INF | [DriverManagerConnectionProvider] Hibernate connection pool size: 20
                13:05:21,545 INF | [DriverManagerConnectionProvider] autocommit mode: false
                13:05:21,545 INF | [DriverManagerConnectionProvider] using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/jbpm4
                13:05:21,545 INF | [DriverManagerConnectionProvider] connection properties: {user=jboss, password=****}
                13:05:21,686 INF | [Dialect] Using dialect: org.hibernate.dialect.MySQLInnoDBDialect
                13:05:21,702 INF | [TransactionFactoryFactory] Using default transaction strategy (direct JDBC transactions)
                13:05:21,702 INF | [TransactionManagerLookupFactory] No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
                13:05:21,702 INF | [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
                13:05:21,717 INF | [SessionFactoryImpl] building session factory
                13:05:22,077 INF | [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
                13:05:22,389 FIN | [ProcessDefinitionImpl] creating new execution for process 'process'
                13:05:22,389 FIN | [DefaultIdGenerator] generated execution id process.39
                13:05:22,389 FIN | [ScopeInstanceImpl] create variable 'content' in 'execution[process.39]' with value 'valid'
                13:05:22,389 FIN | [ScopeInstanceImpl] create variable 'redObj' in 'execution[process.39]' with value 'org.application.SDM.RedObject@1265109'
                13:05:22,405 FIN | [ScopeInstanceImpl] create variable 'expObj' in 'execution[process.39]' with value 'org.application.SDM.ExpObject@e2892b'
                13:05:22,405 FIN | [ScopeInstanceImpl] create variable 'sysObj' in 'execution[process.39]' with value 'org.application.SDM.SysObject@14b6b02'
                13:05:22,405 FIN | [ScopeInstanceImpl] create variable 'mainObj' in 'execution[process.39]' with value 'org.application.SDM.MainObject@1a41cc7'
                13:05:22,405 FIN | [ExecuteActivity] executing activity(16009656)
                13:05:22,405 FIN | [ExecuteActivity] executing activity(process request)
                13:05:22,405 FIN | [ExecuteActivity] executing activity(evaluate process request result)
                DEBUG: process request
                13:05:22,436 FIN | [ExecuteActivity] executing activity(find providers)
                13:05:22,436 FIN | [ExecuteActivity] executing activity(fork)
                13:05:22,436 FIN | [DefaultIdGenerator] generated execution id process.39.validate red
                13:05:22,452 FIN | [ExecutionImpl] created execution[process.39.validate red]
                13:05:22,452 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
                DEBUG: process ID: processID 001
                DEBUG: Finding Providers
                13:05:22,452 INF | [JobExecutorThread] starting...
                13:05:22,452 INF | [DispatcherThread] starting...
                13:05:22,452 FIN | [DefaultIdGenerator] generated execution id process.39.validate exp
                13:05:22,452 FIN | [ExecutionImpl] created execution[process.39.validate exp]
                13:05:22,452 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
                13:05:22,467 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,467 FIN | [DefaultIdGenerator] generated execution id process.39.validate sys
                13:05:22,467 FIN | [ExecutionImpl] created execution[process.39.validate sys]
                13:05:22,467 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
                13:05:22,467 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,483 FIN | [DbSessionImpl] deleting history process instance process.39
                13:05:22,483 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,483 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,483 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,483 FIN | [AcquireJobsCmd] locking jobs [43]
                13:05:22,483 FIN | [DispatcherThread] pushing jobs on the queue [43]
                13:05:22,483 FIN | [DispatcherThread] added jobs [43] to the queue
                13:05:22,483 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,499 FIN | [DbSessionImpl] deleting process instance process.39
                13:05:22,499 FIN | [AcquireJobsCmd] locking jobs [44]
                13:05:22,499 FIN | [JobExecutorThread] took job(s) [43] from queue
                13:05:22,499 FIN | [DispatcherThread] pushing jobs on the queue [44]
                13:05:22,499 FIN | [DispatcherThread] added jobs [44] to the queue
                13:05:22,499 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,514 FIN | [AcquireJobsCmd] locking jobs [45]
                13:05:22,514 FIN | [DispatcherThread] pushing jobs on the queue [45]
                ### EXCEPTION ###########################################
                13:05:22,514 SEV | [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.pvm.internal.model.op.ExecuteActivityMessage#43]
                 at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1792)
                 at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2551)
                 at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2725)
                 at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:97)
                 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:172)
                 at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
                 at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:64)
                 at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:996)
                 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1141)
                 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
                 at org.jbpm.pvm.internal.hibernate.DbSessionImpl.deleteProcessDefinitionHistory(DbSessionImpl.java:165)
                 at org.jbpm.pvm.internal.cmd.DeleteDeploymentCmd.execute(DeleteDeploymentCmd.java:77)
                 at org.jbpm.pvm.internal.svc.DefaultCommandService.execute(DefaultCommandService.java:42)
                 at org.jbpm.pvm.internal.tx.StandardTransactionInterceptor.execute(StandardTransactionInterceptor.java:54)
                 at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.execute(EnvironmentInterceptor.java:54)
                 at org.jbpm.pvm.internal.svc.RetryInterceptor.execute(RetryInterceptor.java:55)
                 at org.jbpm.pvm.internal.repository.RepositoryServiceImpl.deleteDeploymentCascade(RepositoryServiceImpl.java:70)
                 at biz.thelogicgroup.processswitch.workflow.processWorkflowTest.tearDown(processWorkflowTest.java:77)
                 at junit.framework.TestCase.runBare(TestCase.java:130)
                 at junit.framework.TestResult$1.protect(TestResult.java:106)
                 at junit.framework.TestResult.runProtected(TestResult.java:124)
                 at junit.framework.TestResult.run(TestResult.java:109)
                 at junit.framework.TestCase.run(TestCase.java:118)
                 at junit.framework.TestSuite.runTest(TestSuite.java:208)
                 at junit.framework.TestSuite.run(TestSuite.java:203)
                 at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
                 at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
                ### EXCEPTION ###########################################
                13:05:22,514 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[43]...
                ### EXCEPTION ###########################################
                13:05:22,514 INF | [DefaultCommandService] exception while executing command org.jbpm.pvm.internal.cmd.DeleteDeploymentCmd@19ed7e
                org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.pvm.internal.model.op.ExecuteActivityMessage#43]
                 at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1792)
                 at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2551)
                 at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2725)
                 at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:97)
                 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:172)
                 at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
                 at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:64)
                 at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:996)
                 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1141)
                 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
                 at org.jbpm.pvm.internal.hibernate.DbSessionImpl.deleteProcessDefinitionHistory(DbSessionImpl.java:165)
                 at org.jbpm.pvm.internal.cmd.DeleteDeploymentCmd.execute(DeleteDeploymentCmd.java:77)
                 at org.jbpm.pvm.internal.svc.DefaultCommandService.execute(DefaultCommandService.java:42)
                 at org.jbpm.pvm.internal.tx.StandardTransactionInterceptor.execute(StandardTransactionInterceptor.java:54)
                 at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.execute(EnvironmentInterceptor.java:54)
                 at org.jbpm.pvm.internal.svc.RetryInterceptor.execute(RetryInterceptor.java:55)
                 at org.jbpm.pvm.internal.repository.RepositoryServiceImpl.deleteDeploymentCascade(RepositoryServiceImpl.java:70)
                 at biz.thelogicgroup.processswitch.workflow.processWorkflowTest.tearDown(processWorkflowTest.java:77)
                 at junit.framework.TestCase.runBare(TestCase.java:130)
                 at junit.framework.TestResult$1.protect(TestResult.java:106)
                 at junit.framework.TestResult.runProtected(TestResult.java:124)
                 at junit.framework.TestResult.run(TestResult.java:109)
                 at junit.framework.TestCase.run(TestCase.java:118)
                 at junit.framework.TestSuite.runTest(TestSuite.java:208)
                 at junit.framework.TestSuite.run(TestSuite.java:203)
                 at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
                 at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
                 at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
                ### EXCEPTION ###########################################
                13:05:22,530 FIN | [ExecuteActivity] execution[process.39.validate red] executes activity(validate red request)
                DEBUG: Validating redObj Request
                DEBUG: Provider Details: red details
                DEBUG: Provider Details changed to: redObj Details have been changed
                13:05:22,530 FIN | [ScopeInstanceImpl] updating variable 'redObj' in 'execution[process.39]' to value 'org.application.SDM.RedObject@67c1a6'
                13:05:22,530 FIN | [ExecuteActivity] execution[process.39.validate red] executes activity(join)
                13:05:22,530 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[43]
                DEBUG: Validating expObj Request
                DEBUG: Provider Details: some exp details
                DEBUG: Provider Details changed to: expObj Details have been changed
                13:05:22,545 FIN | [JobExecutorThread] took job(s) [44] from queue
                13:05:22,545 FIN | [DispatcherThread] added jobs [45] to the queue
                13:05:22,545 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,545 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,545 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,545 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,545 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,545 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[44]...
                13:05:22,545 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,545 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,545 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,545 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,545 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,545 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,545 FIN | [ExecuteActivity] execution[process.39.validate exp] executes activity(validate exp request)
                13:05:22,545 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,545 FIN | [ScopeInstanceImpl] updating variable 'expObj' in 'execution[process.39]' to value 'org.application.SDM.ExpObject@1b2b131'
                13:05:22,545 FIN | [ExecuteActivity] execution[process.39.validate exp] executes activity(join)
                13:05:22,545 FIN | [AcquireJobsCmd] start querying first acquirable job...
                DEBUG: Validating sysObj Request
                DEBUG: Provider Details: Sys Details
                DEBUG: Provider Details changed to: sysObj Details have been changed
                13:05:22,545 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,545 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,545 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,545 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,545 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[44]
                13:05:22,545 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,545 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,561 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,561 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,561 FIN | [JobExecutorThread] took job(s) [45] from queue
                13:05:22,561 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[45]...
                13:05:22,561 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,561 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,561 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,561 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,561 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,561 FIN | [ExecuteActivity] execution[process.39.validate sys] executes activity(validate sys request)
                13:05:22,561 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,561 FIN | [ScopeInstanceImpl] updating variable 'sysObj' in 'execution[process.39]' to value 'org.application.SDM.SysObject@13acc52'
                13:05:22,561 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,561 FIN | [ExecuteActivity] execution[process.39.validate sys] executes activity(join)
                13:05:22,561 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,561 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,561 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,561 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,561 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,561 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,561 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,561 FIN | [ExecutionImpl] execution[process.39.validate red] ends
                13:05:22,561 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,561 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,561 FIN | [ExecutionImpl] execution[process.39.validate exp] ends
                13:05:22,561 FIN | [ExecutionImpl] execution[process.39.validate sys] ends
                13:05:22,561 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,561 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,577 FIN | [JobExecutorMessageSession] sending message ExecuteEventListenerMessage
                13:05:22,577 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,577 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,577 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[45]
                13:05:22,577 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,577 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,577 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,577 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,577 FIN | [AcquireJobsCmd] locking jobs [46]
                13:05:22,577 FIN | [DispatcherThread] pushing jobs on the queue [46]
                13:05:22,577 FIN | [DispatcherThread] added jobs [46] to the queue
                13:05:22,577 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,577 FIN | [JobExecutorThread] took job(s) [46] from queue
                13:05:22,577 FIN | [ExecuteJobCmd] executing job message[46]...
                13:05:22,577 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,577 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,577 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,577 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,577 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,577 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,592 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,592 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,592 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,592 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,592 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,592 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,592 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,592 FIN | [DbSessionImpl] deleting history process instance process.39
                13:05:22,592 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,592 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,592 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,592 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,592 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,592 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,592 FIN | [DbSessionImpl] deleting process instance process.39
                13:05:22,608 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,608 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,608 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,608 FIN | [DeleteDeploymentCmd] deleting deployment 220
                13:05:22,608 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,624 FIN | [BaseJbpmTestCase] === ending testSimple =============================
                
                13:05:22,624 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,624 FIN | [AcquireJobsCmd] locking jobs []
                13:05:22,624 FIN | [GetNextDueDateCmd] getting next due date...
                13:05:22,624 FIN | [GetNextDueDateCmd] next due date is null
                13:05:22,639 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:05:22,639 FIN | [AcquireJobsCmd] locking jobs []
                
                


                What I would expect to see is after the join a few more debug lines as follows:

                DEBUG: Constructing Message
                DEBUG: Sending Message
                13:14:15,688 FIN | [AcquireJobsCmd] locking jobs []
                13:14:15,688 FIN | [GetNextDueDateCmd] getting next due date...
                13:14:15,688 FIN | [GetNextDueDateCmd] next due date is null
                13:14:15,688 FIN | [AcquireJobsCmd] start querying first acquirable job...
                13:14:15,688 FIN | [AcquireJobsCmd] locking jobs []
                13:14:15,688 FIN | [GetNextDueDateCmd] getting next due date...
                13:14:15,688 FIN | [ExecuteActivity] executing activity(construct message)
                13:14:15,688 FIN | [ExecuteActivity] executing activity(send)
                DEBUG: Getting Response
                DEBUG: Processing Response
                DEBUG: Getting Main Object and Provider Information After Change
                DEBUG: redObj Details have been changed
                DEBUG: expObj Details have been changed
                DEBUG: sysObj Details have been changed
                


                I only see this sometimes.... why is it so unpredictable?

                • 6. Re: StaleObjectException in JBPM 4.0
                  Joram Barrez Master

                  I quickly went trough your unit test:

                  * You have at least 2 threads: the JUnit thread and x jobexecutor threads

                  * The JUnit thread does executes all your codes until the end. At that point, the teardown() message is called causing your processdefinition to be deleted.

                  * However, the JobExecutor thread is still around. Now he comes into play and tries to execute some activity of a process definition that doesn't exist anymore.

                  Hence, your error message ("deleted by another transaction")

                  Try to add Thread.sleep(10000) at the end of your unit test. It should work now. The reason why it works sometimes is because sometimes the jobexecutor is scheduled before the JUnit thread (damn parallel programming ;-)

                  Hope this helps

                  • 7. Re: StaleObjectException in JBPM 4.0
                    Mustafa Musaji Novice

                    You are a star :)

                    I'm kicking myself for now realising this now as it's seems soo obvious, but I guess that I got so caught up with trying to figure out JBPM I was blinded so to speak!

                    But thank you for such a quick response and good explanation.

                    • 8. Re: StaleObjectException in JBPM 4.0
                      Ronald van Kuijk Master

                      @Joram

                      Second example why deleting the processinstance immediately is a *big* issue in unittests (isEnded() also does not work in situations where it is realy ended, strange
                      behaviour ;-)).

                      I think this should become part of the dev docs, don't you?

                      @mmusaji,

                      Great that it works and sorry you had to be the guineapig for 'this' I'll try to write a blog entry about these things and/or something for the docs

                      • 9. Re: StaleObjectException in JBPM 4.0
                        Joram Barrez Master

                        @Ronald:

                        The problem is not that the process instance is ended. In fact, it was probably still before the join activity.

                        However, the tearDown() method does a deleteDeploymentCasade() which deletes everything related to the deployment (including the active process instance). I agree that's kinda confusing ... but it sure helps us writing quick tests without having to clean up our database ourselves every test.

                        For unit tests, there is an assertion: assertProcessInstanceEnded(String pId).

                        So, I don't yet see the issue with processInstances. Perhaps you can enlighten me?

                        • 10. Re: StaleObjectException in JBPM 4.0
                          Ronald van Kuijk Master

                          Sorry, to little info from my side.

                          If you *do* end the process in the unit test because you want to *know* it has ended, the teardown throws an exception.

                          And I agree that it is much easier for us to use, but as you already mention, the 'confusion' kicks in very often. Also many people do not know the new assertions.

                          Maybe the teardown should check if it is still running and do the sleep itself until it checks that the process has ended or sleeps 10 seconds and then kill it anyway (but maybe also delete running jobs etc)


                          Off Topic: so maybe a very little amount of data could be left in the execution table e.g. the process instance id and the fact that it has ended or whatever. This one record does not really clutter the db does it? Or in some command check if there is a process id in the history table if the execution returns null, more explicit warnings can be thrown then. Tom changed the getVariable to log a message that there is no process instance but there is not process instance ACTIVE anymore. Could also be kind of confusing. And instead of documenting all this, it is probably easier to log it in a nicer way.

                          • 11. Re: StaleObjectException in JBPM 4.0
                            Mustafa Musaji Novice

                            I don't mind being a guinea pig. I hope this helps other people who have the same issue.

                            Most of what you guys are saying is going over my head, however I think if the teardown waited for the process to finish this would resolve this problem quite quickly.

                            If I wanted to do this and override the tear down method in my Junit can you please post an example of how I would go about this? Would be a large amount of code involving checking the db or is there "isAlive()" method somewhere?

                            • 12. Re: StaleObjectException in JBPM 4.0
                              Ronald van Kuijk Master

                               

                              "mmusaji" wrote:
                              I don't mind being a guinea pig. I hope this helps other people who have the same issue.

                              Not only others, also us (creating awareness)
                              "mmusaji" wrote:

                              Most of what you guys are saying is going over my head, however I think if the teardown waited for the process to finish this would resolve this problem quite quickly.

                              Then you at least got my main point ;-)

                              "mmusaji" wrote:

                              If I wanted to do this and override the tear down method in my Junit can you please post an example of how I would go about this? Would be a large amount of code involving checking the db or is there "isAlive()" method somewhere?


                              The source of the AbstractDBTestcase is the basis. But just before deleting it, retrieve the processinstance based on the id, if this succeeds,, sleep, then retrieve it again based on the processInstance id. If this returns null, it is ended and you can delete it