3 Replies Latest reply on Jun 14, 2012 12:06 PM by milhaim

    Timer triggered more than it should after an exception (infinite loop some times).

    milhaim

      Hi All,

       

      I'm having an infinite loop in my business process in my project, so I reduced my process to a sample one and reproduced the bug. I'm using jbpm5.2 seam and jboss 5.1.

       

      the process:

      Screen Shot 2012-05-21 at 12.10.14.png

       

       

      In an ad-hoc model, I start the process and a timer is triggered each 60s to check some rules. I have a variable "iteration" which is incremented in the a script action (each time the triggered), after the third  iteration a throw an exception with I catch in my processManager.

       

      The rule where the exception is thrown

       

      Screen Shot 2012-05-21 at 12.10.50.png

      To reproduce the bug I start tow process instance, let the exception occurred and start a new process instance than the timer is triggered 3, 4 5 times in a second and it should happen just ones each 60s. Some times this exception produces an infinite loop (triggering the timer).

       

       

      I joined the process definition, the rule file and processmanager.ava (inspired from the jbpm console code).

       

      My question :

      Is it a problem in my code or a bug in jbpm, and if there is a way to workaround.

       

       

      If you need any further information, please let me know.

       

      thanks.

        • 1. Re: Timer triggered more than it should after an exception (infinite loop some times).
          milhaim

          feel free if you need any more information

          • 2. Re: Timer triggered more than it should after an exception (infinite loop some times).
            swiderski.maciej

            What I think is happening is:

            - timer works according to expectations - you can observe that by looking at number of step 1 node executions

            - every trigger of business rule task register listeners to be notified on rule execution

            - in case rule throws an exception it is not successfully executed meaning that listener is not signaled

            - as soon as the other process instance is started and goes into business rule task that is successfully executed with trigger all event listeners as they are matched based on ruleflow group name

             

            So depending on number of business rule task instances that were created with failing rule, you should see that number + 1 triggers of step 2 node.

             

            IMHO you should never thrown exception from the rule as that causes not predictable results.

             

            HTH

            • 3. Re: Timer triggered more than it should after an exception (infinite loop some times).
              milhaim

              Hi Maciej,

               

              Many thanks for your help , I was trying to upgrade  to jbpm  5.3 but I got some issues (hibernate with postgres).

               

              For this issue :

               

              - I'm throwing an exception from the rule just for test (this issue could happen in real life) and I understand  I should not throw exceptions from rules.

               

              - In step 1 in the process definition a have this script action: System.out.println("PROCESS  step 1 "+kcontext.getProcessInstance()... I have this log trace many times in 60 second (timer period) and some times it does not stop(I should have only one).

               

              Here some logs  :

               

              2012-06-14 16:28:49,812 INFO  [STDOUT] (pool-16-thread-1) PROCESS  step 1 WorkflowProcessInstance6 [processId=LoopBug,state=1] : after timer triggered  : 3

              2012-06-14 16:28:49,814 INFO  [STDOUT] (pool-16-thread-1)  Fire all rules  for process instance: 6

              2012-06-14 16:28:49,819 INFO  [STDOUT] (pool-16-thread-1) PROCESS   Step 2: after rules  validated  :

              2012-06-14 16:28:49,834 INFO  [STDOUT] (pool-16-thread-1) PROCESS  step 1 WorkflowProcessInstance11 [processId=LoopBug,state=1] : after timer triggered  : 4

              2012-06-14 16:28:49,836 INFO  [STDOUT] (pool-16-thread-1)  Fire all rules  for process instance: 11

              2012-06-14 16:28:49,840 INFO  [STDOUT] (pool-16-thread-1) PROCESS   Step 2: after rules  validated  :

              2012-06-14 16:28:49,855 INFO  [STDOUT] (pool-16-thread-1) PROCESS  step 1 WorkflowProcessInstance16 [processId=LoopBug,state=1] : after timer triggered  : 4

              2012-06-14 16:28:49,857 INFO  [STDOUT] (pool-16-thread-1)  Fire all rules  for process instance: 16

              2012-06-14 16:28:49,861 INFO  [STDOUT] (pool-16-thread-1) PROCESS   Step 2: after rules  validated  :

              2012-06-14 16:28:49,875 INFO  [STDOUT] (pool-16-thread-1) PROCESS  step 1 WorkflowProcessInstance1 [processId=LoopBug,state=1] : after timer triggered  : 6

              2012-06-14 16:28:49,878 INFO  [STDOUT] (pool-16-thread-1)  Fire all rules  for process instance: 1

              2012-06-14 16:28:49,883 INFO  [STDOUT] (pool-16-thread-1) PROCESS   Step 2: after rules  validated  :

              2012-06-14 16:28:49,896 INFO  [STDOUT] (pool-16-thread-1) PROCESS  step 1 WorkflowProcessInstance6 [processId=LoopBug,state=1] : after timer triggered  : 4

              2012-06-14 16:28:49,899 INFO  [STDOUT] (pool-16-thread-1)  Fire all rules  for process instance: 6

              2012-06-14 16:28:49,903 INFO  [STDOUT] (pool-16-thread-1) PROCESS   Step 2: after rules  validated  :

              2012-06-14 16:28:49,915 INFO  [STDOUT] (pool-16-thread-1) PROCESS  step 1 WorkflowProcessInstance11 [processId=LoopBug,state=1] : after timer triggered  : 5

              2012-06-14 16:28:49,918 INFO  [STDOUT] (pool-16-thread-1)  Fire all rules  for process instance: 11

              2012-06-14 16:28:49,922 INFO  [STDOUT] (pool-16-thread-1) PROCESS   Step 2: after rules  validated  :

              2012-06-14 16:28:49,936 INFO  [STDOUT] (pool-16-thread-1) PROCESS  step 1 WorkflowProcessInstance16 [processId=LoopBug,state=1] : after timer triggered  : 5

              2012-06-14 16:28:49,940 INFO  [STDOUT] (pool-16-thre

               

              step 1 is executed 30 time for each process instance  in less than 2 seconds.

               

              The complite log file (end of the file)