2 Replies Latest reply on Sep 23, 2009 10:04 AM by mmusaji

    Only Sync Fork Join working after Multiplicity fix

    mmusaji

      There was an issue fixed in JBPM 4.1 that resolved an issue where Join wouldnt continue after fork nodes.

      https://jira.jboss.org/jira/browse/JBPM-2407

      When I deploy my app in Jboss with ASync nodes in the fork of the process definition, it seems to freeze at the join. However if I deploy removing the Async it carries on to completion. This is using custom nodes and not states. Could this be related?

      This is different to

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

      in the sense that even if I put a Thread.sleep(), it doesn't solve the problem of the workflow not completing.




        • 1. Re: Only Sync Fork Join working after Multiplicity fix
          mmusaji

          I think I've managed to create a Junit test to replicate this. Please advice based on this.

          <process name="aSyncProcessCustom">
           <start>
           <transition to="theFork" />
           </start>
           <fork name="theFork">
           <transition to="customOne" />
           <transition to="customTwo" />
           <transition to="customThree" />
           </fork>
           <custom continue="async" name="customOne" class="org.workflow.test.forum.JoinTestApp$CustomOneClass">
           <transition to="join"/>
           </custom>
           <custom continue="async" name="customTwo" class="org.workflow.test.forum.JoinTestApp$CustomTwoClass">
           <transition to="join"/>
           </custom>
           <custom continue="async" name="customThree" class="org.workflow.test.forum.JoinTestApp$CustomThreeClass">
           <transition to="join"/>
           </custom>
           <join name="join">
           <transition to="customFour" />
           </join>
           <custom name="customFour" class="org.workflow.test.forum.JoinTestApp$CustomFourClass">
           <transition to="end"/>
           </custom>
           <end name="end" />
          </process>
          


          package org.workflow.test.forum;
          
          import org.jbpm.api.Execution;
          import org.jbpm.api.activity.ActivityBehaviour;
          import org.jbpm.api.activity.ActivityExecution;
          import org.jbpm.test.JbpmTestCase;
          
          public class JoinTestApp extends JbpmTestCase{
           String deploymentDbid;
          
           protected void setUp() throws Exception {
           super.setUp();
           }
          
           protected void tearDown() throws Exception {
           repositoryService.deleteDeploymentCascade(deploymentDbid);
           super.tearDown();
           }
          
           public void testJoinASync() throws Exception {
           deploymentDbid = repositoryService.createDeployment()
           .addResourceFromClasspath("org/workflow/test/forum/aSyncProcessCustom.jpdl.xml")
           .deploy();
          
           String processInstanceId = executionService.startProcessInstanceByKey("aSyncProcessCustom").getId();
           assertNotNull(processInstanceId);
          
           //all forks will complete while we sleep
           Thread.sleep(4000);
          
           Execution executionInStateFour = executionService.findExecutionById(processInstanceId)
           .findActiveExecutionIn("stateFour");
           assertNotNull("No Execution Found in State Four",executionInStateFour);
           executionService.signalExecutionById(executionInStateFour.getId());
          
           assertProcessInstanceEnded(processInstanceId);
           }
           public static class CustomOneClass implements ActivityBehaviour {
           private static final long serialVersionUID = 1L;
          
           public void execute(ActivityExecution execution) throws Exception {
           System.out.println("Executing");
          
           System.out.println(execution.getActivityName());
          
           execution.takeDefaultTransition();
           }
           }
          
           public static class CustomTwoClass implements ActivityBehaviour {
           private static final long serialVersionUID = 1L;
          
           public void execute(ActivityExecution execution) throws Exception {
           System.out.println("Executing");
          
           System.out.println(execution.getActivityName());
          
           execution.takeDefaultTransition();
           }
           }
          
           public static class CustomThreeClass implements ActivityBehaviour {
           private static final long serialVersionUID = 1L;
          
           public void execute(ActivityExecution execution) throws Exception {
           System.out.println("Executing");
          
           System.out.println(execution.getActivityName());
          
           execution.takeDefaultTransition();
           }
           }
          
           public static class CustomFourClass implements ActivityBehaviour {
           private static final long serialVersionUID = 1L;
          
           public void execute(ActivityExecution execution) throws Exception {
           System.out.println("Executing");
          
           System.out.println(execution.getActivityName());
          
           execution.takeDefaultTransition();
           }
          
           }
          
          }
          


          Output
          14:48:39,252 FIN | [BaseJbpmTestCase] === starting testJoinASync =============================
          14:48:39,392 FIN | [WireContext] eagerly initializing org.jbpm.pvm.internal.jobexecutor.JobExecutor
          14:48:39,424 INF | [DispatcherThread] starting DispatcherThread
          log4j:WARN No appenders could be found for logger (org.hibernate.cfg.Environment).
          log4j:WARN Please initialize the log4j system properly.
          14:48:40,408 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:40,439 FIN | [AcquireJobsCmd] locking jobs []
          14:48:40,439 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:40,439 FIN | [GetNextDueDateCmd] next due date is null
          14:48:40,439 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          14:48:40,596 FIN | [ProcessDefinitionImpl] creating new execution for process 'aSyncProcessCustom'
          14:48:40,596 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.1
          14:48:40,611 FIN | [ExecuteActivity] executing activity(13007496)
          14:48:40,611 FIN | [ExecuteActivity] executing activity(theFork)
          14:48:40,611 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.1.2
          14:48:40,611 FIN | [ExecutionImpl] created execution[aSyncProcessCustom.1.2]
          14:48:40,611 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
          14:48:40,611 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.1.3
          14:48:40,611 FIN | [ExecutionImpl] created execution[aSyncProcessCustom.1.3]
          14:48:40,611 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
          14:48:40,611 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.1.4
          14:48:40,611 FIN | [ExecutionImpl] created execution[aSyncProcessCustom.1.4]
          14:48:40,611 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
          14:48:40,627 FIN | [DispatcherThread] DispatcherThread woke up
          14:48:40,627 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:40,627 FIN | [AcquireJobsCmd] locking jobs [1]
          14:48:40,627 FIN | [DispatcherThread] submitting jobs [1]
          14:48:40,627 FIN | [DispatcherThread] added jobs [1] to the queue
          14:48:40,627 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:40,627 FIN | [AcquireJobsCmd] locking jobs [2]
          14:48:40,627 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[1]...
          14:48:40,627 FIN | [DispatcherThread] submitting jobs [2]
          14:48:40,627 FIN | [DispatcherThread] added jobs [2] to the queue
          14:48:40,627 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:40,642 FIN | [AcquireJobsCmd] locking jobs [3]
          14:48:40,642 FIN | [DispatcherThread] submitting jobs [3]
          14:48:40,642 FIN | [DispatcherThread] added jobs [3] to the queue
          14:48:40,642 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:40,642 FIN | [AcquireJobsCmd] locking jobs []
          14:48:40,642 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:40,642 FIN | [GetNextDueDateCmd] next due date is null
          14:48:40,658 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          Executing
          customOne
          Executing
          customTwo
          14:48:40,658 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[2]...
          14:48:40,658 FIN | [ExecuteActivity] executing activity(customOne)
          14:48:40,658 FIN | [ExecuteActivity] executing activity(join)
          14:48:40,658 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[3]...
          14:48:40,674 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[1]
          14:48:40,674 FIN | [ExecuteActivity] executing activity(customTwo)
          14:48:40,674 FIN | [ExecuteActivity] executing activity(join)
          14:48:40,674 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[2]
          14:48:40,674 FIN | [ExecuteActivity] executing activity(customThree)
          Executing
          customThree
          14:48:40,674 FIN | [ExecuteActivity] executing activity(join)
          14:48:40,674 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[3]
          14:48:41,252 FIN | [DispatcherThread] DispatcherThread woke up
          14:48:41,252 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:41,252 FIN | [AcquireJobsCmd] locking jobs []
          14:48:41,252 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:41,252 FIN | [GetNextDueDateCmd] next due date is null
          14:48:41,252 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          14:48:41,861 FIN | [DispatcherThread] DispatcherThread woke up
          14:48:41,861 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:41,892 FIN | [AcquireJobsCmd] locking jobs []
          14:48:41,892 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:41,892 FIN | [GetNextDueDateCmd] next due date is null
          14:48:41,908 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          14:48:42,502 FIN | [DispatcherThread] DispatcherThread woke up
          14:48:42,502 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:42,502 FIN | [AcquireJobsCmd] locking jobs []
          14:48:42,502 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:42,502 FIN | [GetNextDueDateCmd] next due date is null
          14:48:42,502 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          14:48:43,111 FIN | [DispatcherThread] DispatcherThread woke up
          14:48:43,111 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:43,111 FIN | [AcquireJobsCmd] locking jobs []
          14:48:43,111 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:43,111 FIN | [GetNextDueDateCmd] next due date is null
          14:48:43,111 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          14:48:43,705 FIN | [DispatcherThread] DispatcherThread woke up
          14:48:43,705 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:43,705 FIN | [AcquireJobsCmd] locking jobs []
          14:48:43,705 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:43,705 FIN | [GetNextDueDateCmd] next due date is null
          14:48:43,705 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          14:48:44,314 FIN | [DispatcherThread] DispatcherThread woke up
          14:48:44,314 FIN | [AcquireJobsCmd] start querying first acquirable job...
          14:48:44,314 FIN | [AcquireJobsCmd] locking jobs []
          14:48:44,314 FIN | [GetNextDueDateCmd] getting next due date...
          14:48:44,314 FIN | [GetNextDueDateCmd] next due date is null
          14:48:44,314 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@587c94
          14:48:44,627 SEV | [BaseJbpmTestCase]
          ### EXCEPTION ###########################################
          14:48:44,627 SEV | [BaseJbpmTestCase] ASSERTION FAILURE: No Execution Found in State Four
          junit.framework.AssertionFailedError: No Execution Found in State Four
           at junit.framework.Assert.fail(Assert.java:47)
           at junit.framework.Assert.assertTrue(Assert.java:20)
           at junit.framework.Assert.assertNotNull(Assert.java:217)
           at org.workflow.test.forum.JoinTestApp.testJoinASync(JoinTestApp.java:53)
           at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
           at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
           at java.lang.reflect.Method.invoke(Method.java:597)
           at junit.framework.TestCase.runTest(TestCase.java:164)
           at org.jbpm.test.BaseJbpmTestCase.runTest(BaseJbpmTestCase.java:80)
           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:120)
           at junit.framework.TestSuite.runTest(TestSuite.java:230)
           at junit.framework.TestSuite.run(TestSuite.java:225)
           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 ###########################################
          14:48:44,627 SEV | [BaseJbpmTestCase]
          14:48:44,642 FIN | [DbSessionImpl] deleting history process instance aSyncProcessCustom.1
          14:48:44,674 FIN | [DbSessionImpl] deleting process instance aSyncProcessCustom.1
          14:48:44,689 FIN | [DeleteDeploymentCmd] deleting deployment 104
          14:48:44,721 FIN | [BaseJbpmTestCase] === ending testJoinASync =============================
          


          • 2. Re: Only Sync Fork Join working after Multiplicity fix
            mmusaji

            I forgot to add the test without the syn that works ok.

            package org.workflow.test.forum;
            
            import org.jbpm.api.Execution;
            import org.jbpm.api.activity.ActivityBehaviour;
            import org.jbpm.api.activity.ActivityExecution;
            import org.jbpm.test.JbpmTestCase;
            
            public class JoinTestApp extends JbpmTestCase{
             String deploymentDbid;
            
             protected void setUp() throws Exception {
             super.setUp();
             }
            
             protected void tearDown() throws Exception {
             repositoryService.deleteDeploymentCascade(deploymentDbid);
             super.tearDown();
             }
            
             public void testJoinASync() throws Exception {
             deploymentDbid = repositoryService.createDeployment()
             .addResourceFromClasspath("org/workflow/test/forum/aSyncProcessCustom.jpdl.xml")
             .deploy();
            
             String processInstanceId = executionService.startProcessInstanceByKey("aSyncProcessCustom").getId();
             assertNotNull(processInstanceId);
            
             Thread.sleep(4000);
            
             assertProcessInstanceEnded(processInstanceId);
             }
             public static class CustomOneClass implements ActivityBehaviour {
             private static final long serialVersionUID = 1L;
            
             public void execute(ActivityExecution execution) throws Exception {
             System.out.println("Executing");
            
             System.out.println(execution.getActivityName());
            
             execution.takeDefaultTransition();
             }
             }
            
             public static class CustomTwoClass implements ActivityBehaviour {
             private static final long serialVersionUID = 1L;
            
             public void execute(ActivityExecution execution) throws Exception {
             System.out.println("Executing");
            
             System.out.println(execution.getActivityName());
            
             execution.takeDefaultTransition();
             }
             }
            
             public static class CustomThreeClass implements ActivityBehaviour {
             private static final long serialVersionUID = 1L;
            
             public void execute(ActivityExecution execution) throws Exception {
             System.out.println("Executing");
            
             System.out.println(execution.getActivityName());
            
             execution.takeDefaultTransition();
             }
             }
            
             public static class CustomFourClass implements ActivityBehaviour {
             private static final long serialVersionUID = 1L;
            
             public void execute(ActivityExecution execution) throws Exception {
             System.out.println("Executing");
            
             System.out.println(execution.getActivityName());
            
             execution.takeDefaultTransition();
             }
            
             }
            
            }
            


            Process Definition (NB. with no async nodes)

            <process name="aSyncProcessCustom">
             <start>
             <transition to="theFork" />
             </start>
             <fork name="theFork">
             <transition to="customOne" />
             <transition to="customTwo" />
             <transition to="customThree" />
             </fork>
             <custom name="customOne" class="org.workflow.test.forum.JoinTestApp$CustomOneClass">
             <transition to="join"/>
             </custom>
             <custom name="customTwo" class="org.workflow.test.forum.JoinTestApp$CustomTwoClass">
             <transition to="join"/>
             </custom>
             <custom name="customThree" class="org.workflow.test.forum.JoinTestApp$CustomThreeClass">
             <transition to="join"/>
             </custom>
             <join name="join">
             <transition to="customFour" />
             </join>
             <custom name="customFour" class="org.workflow.test.forum.JoinTestApp$CustomFourClass">
             <transition to="end"/>
             </custom>
             <end name="end" />
            </process>
            


            Output... please note that customFour is executed.

            15:02:53,799 FIN | [BaseJbpmTestCase] === starting testJoinASync =============================
            15:02:53,940 FIN | [WireContext] eagerly initializing org.jbpm.pvm.internal.jobexecutor.JobExecutor
            15:02:53,956 INF | [DispatcherThread] starting DispatcherThread
            log4j:WARN No appenders could be found for logger (org.hibernate.cfg.Environment).
            log4j:WARN Please initialize the log4j system properly.
            15:02:55,018 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:55,034 FIN | [AcquireJobsCmd] locking jobs []
            15:02:55,034 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:55,049 FIN | [GetNextDueDateCmd] next due date is null
            15:02:55,049 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:55,221 FIN | [ProcessDefinitionImpl] creating new execution for process 'aSyncProcessCustom'
            15:02:55,237 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.25
            15:02:55,237 FIN | [ExecuteActivity] executing activity(7819553)
            15:02:55,237 FIN | [ExecuteActivity] executing activity(theFork)
            Executing
            customOne
            Executing
            customTwo
            Executing
            customThree
            15:02:55,237 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.25.26
            15:02:55,237 FIN | [ExecutionImpl] created execution[aSyncProcessCustom.25.26]
            15:02:55,237 FIN | [ExecuteActivity] executing activity(customOne)
            15:02:55,237 FIN | [ExecuteActivity] executing activity(join)
            15:02:55,253 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.25.27
            15:02:55,253 FIN | [ExecutionImpl] created execution[aSyncProcessCustom.25.27]
            15:02:55,253 FIN | [ExecuteActivity] executing activity(customTwo)
            15:02:55,253 FIN | [ExecuteActivity] executing activity(join)
            15:02:55,253 FIN | [DefaultIdGenerator] generated execution id aSyncProcessCustom.25.28
            Executing
            customFour
            15:02:55,253 FIN | [ExecutionImpl] created execution[aSyncProcessCustom.25.28]
            15:02:55,253 FIN | [ExecuteActivity] executing activity(customThree)
            15:02:55,253 FIN | [ExecuteActivity] executing activity(join)
            15:02:55,253 FIN | [ExecutionImpl] execution[aSyncProcessCustom.25.26] ends
            15:02:55,253 FIN | [ExecutionImpl] execution[aSyncProcessCustom.25.27] ends
            15:02:55,253 FIN | [ExecutionImpl] execution[aSyncProcessCustom.25.28] ends
            15:02:55,253 FIN | [ExecuteActivity] executing activity(customFour)
            15:02:55,253 FIN | [ExecuteActivity] executing activity(end)
            15:02:55,253 FIN | [ExecutionImpl] execution[aSyncProcessCustom.25] ends
            15:02:55,268 FIN | [DbSessionImpl] deleting process instance aSyncProcessCustom.25
            15:02:55,659 FIN | [DispatcherThread] DispatcherThread woke up
            15:02:55,659 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:55,659 FIN | [AcquireJobsCmd] locking jobs []
            15:02:55,659 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:55,659 FIN | [GetNextDueDateCmd] next due date is null
            15:02:55,659 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:56,253 FIN | [DispatcherThread] DispatcherThread woke up
            15:02:56,253 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:56,253 FIN | [AcquireJobsCmd] locking jobs []
            15:02:56,253 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:56,253 FIN | [GetNextDueDateCmd] next due date is null
            15:02:56,253 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:56,862 FIN | [DispatcherThread] DispatcherThread woke up
            15:02:56,862 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:56,862 FIN | [AcquireJobsCmd] locking jobs []
            15:02:56,862 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:56,862 FIN | [GetNextDueDateCmd] next due date is null
            15:02:56,862 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:57,456 FIN | [DispatcherThread] DispatcherThread woke up
            15:02:57,456 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:57,471 FIN | [AcquireJobsCmd] locking jobs []
            15:02:57,471 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:57,471 FIN | [GetNextDueDateCmd] next due date is null
            15:02:57,471 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:58,065 FIN | [DispatcherThread] DispatcherThread woke up
            15:02:58,065 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:58,065 FIN | [AcquireJobsCmd] locking jobs []
            15:02:58,065 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:58,065 FIN | [GetNextDueDateCmd] next due date is null
            15:02:58,065 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:58,674 FIN | [DispatcherThread] DispatcherThread woke up
            15:02:58,674 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:58,674 FIN | [AcquireJobsCmd] locking jobs []
            15:02:58,674 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:58,674 FIN | [GetNextDueDateCmd] next due date is null
            15:02:58,674 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:59,268 FIN | [DispatcherThread] DispatcherThread woke up
            15:02:59,268 FIN | [AcquireJobsCmd] start querying first acquirable job...
            15:02:59,268 FIN | [AcquireJobsCmd] locking jobs []
            15:02:59,268 FIN | [GetNextDueDateCmd] getting next due date...
            15:02:59,268 FIN | [GetNextDueDateCmd] next due date is null
            15:02:59,268 FIN | [DispatcherThread] DispatcherThread will wait for max 600ms on org.jbpm.pvm.internal.jobexecutor.JobExecutor@6025e7
            15:02:59,300 FIN | [DeleteDeploymentCmd] deleting deployment 110
            15:02:59,331 FIN | [BaseJbpmTestCase] === ending testJoinASync =============================
            


            I'm using the jobExecutor in all these examples on purpose as this is the only way I can show what is happening. Executing job one by one isn't async obviously and thus signalling the jobs doesn't reproduce this issue.