[jboss-user] [jBPM Users] - Re: StaleObjectException in JBPM 4.0
mmusaji
do-not-reply at jboss.com
Tue Aug 25 08:17:32 EDT 2009
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 at 1265109'
| 13:05:22,405 FIN | [ScopeInstanceImpl] create variable 'expObj' in 'execution[process.39]' with value 'org.application.SDM.ExpObject at e2892b'
| 13:05:22,405 FIN | [ScopeInstanceImpl] create variable 'sysObj' in 'execution[process.39]' with value 'org.application.SDM.SysObject at 14b6b02'
| 13:05:22,405 FIN | [ScopeInstanceImpl] create variable 'mainObj' in 'execution[process.39]' with value 'org.application.SDM.MainObject at 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 at 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 at 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 at 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 at 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?
View the original post : http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4251451#4251451
Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=4251451
More information about the jboss-user
mailing list