6 Replies Latest reply on Sep 26, 2012 11:42 AM by tmag

    Persisted timer task not firing on session restore

    tmag

      We are planning to start using JBPM 5.3 in our organization, and started with the following simple process which has the deadline for this month end. Please help !!

       

      Its a simple timer task with 500ms delay & 30 sec period - which sends a reminder email every 30 sec . We need this process to be persistent to be able to restore anytime.

      For testing am using Postgres.

       

      1) First am starting a process and after a couple of reminder emails sent out (say after 1 minute) stopping that process to simulate a failure scenerio. Then am reloading the session.

      2) When I reload the session quickly within the period  (30 sec) - there are no exceptions & able to see timer event kicking off reminders as per schedule. Here is my code :

       

             setupDataSource();    // postgres datasource

              Environment env = getEnvironment();

              KnowledgeBase kbase = createKnowledgeBase("IncidentProcess.bpmn");

       

             StatefulKnowledgeSession ksession = JPAKnowledgeService.loadStatefulKnowledgeSession( <sessionId>, kbase, null, env );

            ksession.getWorkItemManager().registerWorkItemHandler("Email", new SystemOutWorkItemHandler());

       

      3)  But when I wait more than 30 sec., say upto 5 minutes (in relatime - maintenance may take hours) & reload the session - getting the following exception about WorkItemHanlder which am registering as above. But seems its failing while loading session itself. Also its deleting entry from 'ProcessInstanceInfo' table.

       

       

      Hibernate: select nextval ('WORKITEMINFO_ID_SEQ')

      Hibernate: select workitemin0_.workItemId as workItemId4_0_, workitemin0_.creationDate as creation2_4_0_, workitemin0_.name as name4_0_, workitemin0_.processInstanceId as processI4_4_0_, workitemin0_.state as state4_0_, workitemin0_.OPTLOCK as OPTLOCK4_0_, workitemin0_.workItemByteArray as workItem7_4_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=?

      Hibernate: select processins0_.InstanceId as col_0_0_ from ProcessInstanceInfo processins0_ inner join EventTypes eventtypes1_ on processins0_.InstanceId=eventtypes1_.InstanceId where eventtypes1_.element=?

      Unable to execute timer job!

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

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

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

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

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

          at org.drools.time.SelfRemovalJob.execute(SelfRemovalJob.java:15)

          at org.drools.time.impl.DefaultTimerJobInstance.call(DefaultTimerJobInstance.java:47)

          at org.drools.persistence.jpa.JpaTimerJobInstance.internalCall(JpaTimerJobInstance.java:43)

          at org.drools.persistence.jpa.JDKCallableJobCommand.execute(JDKCallableJobCommand.java:20)

          at org.drools.persistence.jpa.JDKCallableJobCommand.execute(JDKCallableJobCommand.java:6)

          at org.drools.command.impl.DefaultCommandService.execute(DefaultCommandService.java:36)

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

          at org.drools.persistence.jpa.JpaTimerJobInstance.call(JpaTimerJobInstance.java:34)

          at org.drools.persistence.jpa.JpaTimerJobInstance.call(JpaTimerJobInstance.java:14)

          at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)

          at java.util.concurrent.FutureTask.run(Unknown Source)

          at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)

          at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)

          at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)

          at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

          at java.lang.Thread.run(Unknown Source)

      Caused by: org.jbpm.workflow.instance.WorkflowRuntimeException: [com.ecom.incident.process:8 - Reminder:5] -- Could not find work item handler for Email

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

          at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerNodeInstance(NodeInstanceImpl.java:205)

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

          at org.jbpm.workflow.instance.node.SplitInstance.internalTrigger(SplitInstance.java:100)

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

          at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerNodeInstance(NodeInstanceImpl.java:205)

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

          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:326)

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

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

          ... 19 more

      Hibernate: insert into WorkItemInfo (creationDate, name, processInstanceId, state, OPTLOCK, workItemByteArray, workItemId) values (?, ?, ?, ?, ?, ?, ?)

      Hibernate: update WorkItemInfo set creationDate=?, name=?, processInstanceId=?, state=?, OPTLOCK=?, workItemByteArray=? where workItemId=? and OPTLOCK=?

      Hibernate: delete from EventTypes where InstanceId=?

      Hibernate: delete from ProcessInstanceInfo where InstanceId=? and OPTLOCK=?

      IncidentProcess2-image.png

       

      Message was edited by: tmag

        • 1. Re: Persisted timer event couldn't find work item handler after reload
          tmag

          Anyone faced similar issue before? 

           

          In this link : https://issues.jboss.org/browse/JBPM-3170, I see :

           

          Note that timers are persistent.  They are saved as part of the session state.  Restoring a session from database also restores the timers, so they can fire if necessary.  Timers also fire only once, on the session where the timer is registered.

          The JIRA refers to the fact that the session needs to be active for the timer to fire. If the user disposes the session, the timer will not fire any more. In situations where a long-lived session is used to execute processes, the session will always be alive (and can be restored in case of server restart) and timers will fire as requested.

          In more complex set-ups, where multiple sessions are used and sessions could be disposed in between, a centralised session could be used to manage the timers when the other sessions are disposed.

          A solution where sessions can automatically be restored when a timer might need to fire, for example by using quartz to trigger this, is under development in the community but not yet available.

           

          a) What does it mean by "timers fire only once & they will not fire anymore if the user disposes the session"?

          b) Session always need to be active? but its also mentioned restoring a session from database also restores timers.

          c) In my case when I reload the session before the timer period( i.e., 30 secs) the timer running fine. But if I wait for more time before reloading the session - getting above exception and entry removed from ProcessInstanceInfo.

           

          Would really appreciate anyone's help on this please.

          • 2. Re: Persisted timer event couldn't find work item handler after reload
            tmag

            Tried the same scenerio with a simple script instead of workitem handler, but the same Unexpected exception executing action org.jbpm.process.instance.event.DefaultSignalManager$SignalProcessInstanceAction.

            IncidentProcess3-image.png

            Unable to execute timer job!

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

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

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

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

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

                at org.drools.time.SelfRemovalJob.execute(SelfRemovalJob.java:15)

                at org.drools.time.impl.DefaultTimerJobInstance.call(DefaultTimerJobInstance.java:47)

                at org.drools.persistence.jpa.JpaTimerJobInstance.internalCall(JpaTimerJobInstance.java:43)

                at org.drools.persistence.jpa.JDKCallableJobCommand.execute(JDKCallableJobCommand.java:20)

                at org.drools.persistence.jpa.JDKCallableJobCommand.execute(JDKCallableJobCommand.java:6)

                at org.drools.command.impl.DefaultCommandService.execute(DefaultCommandService.java:36)

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

                at org.drools.persistence.jpa.JpaTimerJobInstance.call(JpaTimerJobInstance.java:34)

                at org.drools.persistence.jpa.JpaTimerJobInstance.call(JpaTimerJobInstance.java:14)

                at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)

                at java.util.concurrent.FutureTask.run(Unknown Source)

                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)

                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)

                at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)

                at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

                at java.lang.Thread.run(Unknown Source)

            Caused by: java.lang.NullPointerException

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

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

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

                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.triggerNodeInstance(NodeInstanceImpl.java:201)

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

                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:326)

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

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

                ... 19 more

            • 3. Re: Persisted timer task not firing on session restore
              krisverlaenen

              The first issue seems to be that, when restoring the session, it is detecting that a timer should have been fired and it is immediately firing this.  Unfortunately, it's doing this before you have registered the necessary handlers, so it will fail finding those.  The reason that it also tries to delete the process instance info is that due to this exception during the execution of the process instance, the process instance is aborted (as we cannot execute it correctly), leading to the deletion of the process instance info from the database.

               

              One way to avoid this is to use a configuration file to register the handlers.  An example can be found here: https://github.com/droolsjbpm/jbpm/tree/master/jbpm-installer/conf/META-INF

              If you put these two files in a META-INF folder in your classpath, you can specify your handlers in that configuration file (rather then registering them using the API).

               

              For the second issue (Unknown node instance type: org.jbpm.workflow.instance.node.ActionNodeInstance@c5c781), the engine is trying to persist the state of the process instance in the database while the process instance is still executing.  This is usually caused by multiple threads running on the same process instance. Could you open a JIRA issue for this and attach the process and the java code you use to execute this, so we can try to reproduce?

               

              Thx,

              Kris

              • 4. Re: Persisted timer task not firing on session restore
                tmag

                Thanks Kris. Let me try this CustomWorkHandlers and get back to you.

                 

                For the second issue(Unknown node instance type: org.jbpm.workflow.instance.node.ActionNodeInstance@c5c781) created JIRA https://issues.jboss.org/browse/JBPM-3798#comment-12720327 and attached process & code.

                • 5. Re: Persisted timer task not firing on session restore
                  tmag

                  It worked with registering handlers through configuration. Thanks Kris.

                  • 6. Re: Persisted timer task not firing on session restore
                    tmag

                    Hi Kris,

                     

                    How can I pass arguments to these handlers through configuration? Say I need StatefulKnowledgeSession in my handler to make it async.