3 Replies Latest reply on Sep 21, 2011 11:30 AM by rrpeterson

    Problem in a process with a event-based timer and JPAWorkingMemoryDbLogger

    mpiraccini
    mpiraccini Aug 16, 2011 10:34 AM

      Hi Guys,

       

      I have a very simple process with a timer event:

       

      process-with-timer-event.jpeg

      The timer has a timeCylce of 500ms. The scripts simply set a variable (message1 and message2) that i look to see of the scripts has been executed.

      My test see that -after the prcess start- the first task is executed, waits for 1000ms and then check the that the second task has been executed (inspecting the message2 variable). Also the test check that the process is completed.

      The Task2 script task containt that code:

       

      <bpmn2:script>
System.out.println(&quot;Executing Script Task 1&quot;);
kcontext.setVariable(&quot;message&quot;,&quot;Executed Script Task 1&quot;);
</bpmn2:script>

       

       

      That works perfectly...at least until I add:

       

       JPAWorkingMemoryDbLogger logger = new JPAWorkingMemoryDbLogger(session);

       

      When I do that, it seems that:

      - The timer does not trigger the "Script Task 2" task.

      - The error below appears in the console:

       

      Hibernate: insert into NodeInstanceLog (id, log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type) values (null, ?, ?, ?, ?, ?, ?, ?)

      INFO  BitronixTransactionManager - shutting down Bitronix Transaction Manager

      org.drools.RuntimeDroolsException: Unexpected exception executing action org.jbpm.process.instance.event.DefaultSignalManager$SignalProcessInstanceAction@22862041

          at org.drools.common.AbstractWorkingMemory.executeQueuedActions(AbstractWorkingMemory.java:996)

          at org.drools.impl.StatefulKnowledgeSessionImpl.executeQueuedActions(StatefulKnowledgeSessionImpl.java:845)

          at org.jbpm.process.instance.event.DefaultSignalManager.signalEvent(DefaultSignalManager.java:89)

          at org.jbpm.process.instance.timer.TimerManager$ProcessJob.execute(TimerManager.java:164)

          at org.drools.time.impl.JDKTimerService$JDKCallableJob.call(JDKTimerService.java:151)

          at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.internalCall(JpaJDKTimerService.java:80)

          at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.access$100(JpaJDKTimerService.java:63)

          at org.drools.persistence.jpa.JpaJDKTimerService$JDKCallableJobCommand.execute(JpaJDKTimerService.java:96)

          at org.drools.persistence.jpa.JpaJDKTimerService$JDKCallableJobCommand.execute(JpaJDKTimerService.java:84)

          at org.drools.persistence.SingleSessionCommandService.execute(SingleSessionCommandService.java:292)

          at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.call(JpaJDKTimerService.java:75)

          at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.call(JpaJDKTimerService.java:63)

          at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

          at java.util.concurrent.FutureTask.run(FutureTask.java:138)

          at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)

          at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)

          at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

          at java.lang.Thread.run(Thread.java:662)

      Caused by: java.lang.NullPointerException

          at org.jbpm.process.instance.impl.ProcessInstanceImpl.getProcess(ProcessInstanceImpl.java:67)

          at org.jbpm.workflow.instance.impl.WorkflowProcessInstanceImpl.getWorkflowProcess(WorkflowProcessInstanceImpl.java:180)

          at org.jbpm.workflow.instance.impl.WorkflowProcessInstanceImpl.getNodeContainer(WorkflowProcessInstanceImpl.java:68)

          at org.jbpm.workflow.instance.impl.NodeInstanceImpl.getNode(NodeInstanceImpl.java:100)

          at org.jbpm.workflow.instance.node.ActionNodeInstance.getActionNode(ActionNodeInstance.java:35)

          at org.jbpm.workflow.instance.node.ActionNodeInstance.internalTrigger(ActionNodeInstance.java:43)

          at org.jbpm.workflow.instance.impl.NodeInstanceImpl.trigger(NodeInstanceImpl.java:122)

          at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerConnection(NodeInstanceImpl.java:185)

          at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerCompleted(NodeInstanceImpl.java:150)

          at org.jbpm.workflow.instance.impl.ExtendedNodeInstanceImpl.triggerCompleted(ExtendedNodeInstanceImpl.java:47)

          at org.jbpm.workflow.instance.node.StateBasedNodeInstance.triggerCompleted(StateBasedNodeInstance.java:162)

          at org.jbpm.workflow.instance.node.TimerNodeInstance.triggerCompleted(TimerNodeInstance.java:135)

          at org.jbpm.workflow.instance.node.TimerNodeInstance.signalEvent(TimerNodeInstance.java:125)

          at org.jbpm.workflow.instance.impl.WorkflowProcessInstanceImpl.signalEvent(WorkflowProcessInstanceImpl.java:333)

          at org.jbpm.process.instance.event.DefaultSignalManager$SignalProcessInstanceAction.execute(DefaultSignalManager.java:117)

          at org.drools.common.AbstractWorkingMemory.executeQueuedActions(AbstractWorkingMemory.java:994)

          ... 18 more

       

       

      ...any idea? It seems a bug to me...

      • 2476 Views
      • Categories: jBPM 5.1
      • Tags:
        • 1. Re: Problem in a process with a event-based timer and JPAWorkingMemoryDbLogger
          mpiraccini
          mpiraccini Aug 26, 2011 12:57 PM (in response to mpiraccini)

          So...it's a bug or I'm missing something?

            • Actions
          • 2. Re: Problem in a process with a event-based timer and JPAWorkingMemoryDbLogger
            rrpeterson
            rrpeterson Sep 19, 2011 12:28 PM (in response to mpiraccini)

            I'm getting this same exception.  I create 5 instances of a process.  Mid-point in the process I have a timer, and things are run/persisted properly until the timer is reached.  At this point control is returned to the caller, which waits for some time until re-aquiring the session instances (via JPAKnowledgeService.loadStatefulKnowledgeSession(w, x, y, z)) and fireUntilHalt() is called on the ksession.  At this point, an intermittent # of my remaining process instances will execute properly (maybe 2 out of 5), and the remaining fail with the following exception:

             

            Hibernate: select processins0_.InstanceId as InstanceId121_0_, processins0_.lastModificationDate as lastModi2_121_0_, processins0_.lastReadDate as lastRead3_121_0_, processins0_.processId as processId121_0_, processins0_.processInstanceByteArray as processI5_121_0_, processins0_.startDate as startDate121_0_, processins0_.state as state121_0_, processins0_.OPTLOCK as OPTLOCK121_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=?

            org.drools.RuntimeDroolsException: Unexpected exception executing action org.jbpm.process.instance.event.DefaultSignalManager$SignalProcessInstanceAction@3f1dae99

            at org.drools.common.AbstractWorkingMemory.executeQueuedActions(AbstractWorkingMemory.java:996)

            at org.drools.impl.StatefulKnowledgeSessionImpl.executeQueuedActions(StatefulKnowledgeSessionImpl.java:845)

            at org.jbpm.process.instance.event.DefaultSignalManager.signalEvent(DefaultSignalManager.java:89)

            at org.jbpm.process.instance.timer.TimerManager$ProcessJob.execute(TimerManager.java:164)

            at org.drools.time.impl.JDKTimerService$JDKCallableJob.call(JDKTimerService.java:151)

            at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.internalCall(JpaJDKTimerService.java:80)

            at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.access$100(JpaJDKTimerService.java:63)

            at org.drools.persistence.jpa.JpaJDKTimerService$JDKCallableJobCommand.execute(JpaJDKTimerService.java:96)

            at org.drools.persistence.jpa.JpaJDKTimerService$JDKCallableJobCommand.execute(JpaJDKTimerService.java:84)

            at org.drools.persistence.SingleSessionCommandService.execute(SingleSessionCommandService.java:292)

            at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.call(JpaJDKTimerService.java:75)

            at org.drools.persistence.jpa.JpaJDKTimerService$JpaJDKCallableJob.call(JpaJDKTimerService.java:63)

            at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

            at java.util.concurrent.FutureTask.run(FutureTask.java:138)

            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)

            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)

            at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

            at java.lang.Thread.run(Thread.java:662)

            Caused by: java.lang.NullPointerException

            at org.jbpm.process.audit.JPAWorkingMemoryDbLogger.getEntityManager(JPAWorkingMemoryDbLogger.java:131)

            at org.jbpm.process.audit.JPAWorkingMemoryDbLogger.addNodeExitLog(JPAWorkingMemoryDbLogger.java:118)

            at org.jbpm.process.audit.JPAWorkingMemoryDbLogger.logEventCreated(JPAWorkingMemoryDbLogger.java:80)

            at org.drools.audit.WorkingMemoryLogger.filterLogEvent(WorkingMemoryLogger.java:196)

            at org.drools.audit.WorkingMemoryLogger.beforeNodeLeft(WorkingMemoryLogger.java:506)

            at org.drools.event.ProcessEventSupport.fireBeforeNodeLeft(ProcessEventSupport.java:112)

            at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerConnection(NodeInstanceImpl.java:162)

            at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerCompleted(NodeInstanceImpl.java:150)

            at org.jbpm.workflow.instance.impl.ExtendedNodeInstanceImpl.triggerCompleted(ExtendedNodeInstanceImpl.java:47)

            at org.jbpm.workflow.instance.node.StateBasedNodeInstance.triggerCompleted(StateBasedNodeInstance.java:162)

            at org.jbpm.workflow.instance.node.TimerNodeInstance.triggerCompleted(TimerNodeInstance.java:135)

            at org.jbpm.workflow.instance.node.TimerNodeInstance.signalEvent(TimerNodeInstance.java:125)

            at org.jbpm.workflow.instance.impl.WorkflowProcessInstanceImpl.signalEvent(WorkflowProcessInstanceImpl.java:333)

            at org.jbpm.process.instance.event.DefaultSignalManager$SignalProcessInstanceAction.execute(DefaultSignalManager.java:117)

            at org.drools.common.AbstractWorkingMemory.executeQueuedActions(AbstractWorkingMemory.java:994)

            ... 18 more

              • Actions
            • 3. Re: Problem in a process with a event-based timer and JPAWorkingMemoryDbLogger
              rrpeterson
              rrpeterson Sep 21, 2011 11:30 AM (in response to rrpeterson)

              The solution for my problem came by not calling fireUntilHalt() on my session. 

               

              In this thread: http://community.jboss.org/thread/172227

              Mauricio mentions fireUntilHalt causing persistence problems, as threads get into a type of race condition with the sessions/transactions.

               

              Hope this helps!

                • Actions