1 2 Previous Next 20 Replies Latest reply on Sep 16, 2009 1:52 PM by Leo van den berg

    jBPM persistency problem

    Leo van den berg Master

      Hi guys,


      I am trying to solve a problem I have with jBPM in Seam. I want to have a reporting-task supervised every day, meaning if the actor doesn't fill in his/her report within an hour, he should receive a warning every 24 hours. After trying to  get the whole stuff working I found out that the timer has some problems when you use a repeat value. However if you use a repeat value of tru or yes everything seems to work. But now the tricky part. I am trying to save objects the taskinstance instance and that won't work without a nasty error which in fact doesn't seem to be a faulure.



      I stripped everything down to some simple beans to see what happen:


      My processdefinition:




      <process-definition xmlns="urn:jbpm.org:jpdl-3.2"
              xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
              xsi:schemaLocation="urn:jbpm.org:jpdl-3.2 http://jbpm.org/xsd/jpdl-3.2.xsd"  name="test">
              <event type="process-start">
                      <script>
                              System.out.println("@@@@@@ PROCESS START");
                      </script>
              </event>
              <event type="process-end">
                      <script>
                              System.out.println("@@@@@@ PROCESS END");
                      </script>
              </event>
              <start-state name="start-state">
                      <transition to="login-checker" />
              </start-state>
              <task-node name="login-checker">
                      <event type="node-enter">
                      <script>
                              System.out.println("STATE " + node + " entered.");
                      </script>
                      </event>
                      <event type="node-leave">
                      <script>
                              System.out.println("STATE " + node + " left.");
                      </script>
                      </event>
                      <task name="check-this" >
                      <assignment  actor-id="#{actor.id}"/>
                              <timer duedate="10 seconds" name="wait-for-timeout" repeat="yes">
                                      <action expression="#{bpmRequestTimeOut.check()}" />
                              </timer>
                      </task>
                      <transition to="end-state" />
              </task-node>
              <end-state name="end-state" />
      </process-definition>
      
       



      The timer action bean:




      @Name("bpmRequestTimeOut")
      public class BpmRequestTimeOutAction implements Serializable  {
      
              @In(required=false) TaskInstance taskInstance;
              @In Events events;
              
              @Logger Log log;
              
              @Transactional
              public void check(){
                      if (taskInstance != null){
                              log.info("Finally the timer works: Timed out processInstance " +
                                              taskInstance.getName());
                              events.raiseEvent("timedOutCheck", taskInstance.getId());
                      }
              }
      } 
      



      The observer bean:




      @Name("timeOutListener")
      public class TimeOutListener {
      
              
              @In(required=false) TaskInstance taskInstance;
              @Logger Log log;
      
              //@In(required=false, scope=ScopeType.BUSINESS_PROCESS)
              //@Out(required=false, scope=ScopeType.BUSINESS_PROCESS)
              Long counter = -1L;
      
              @In Actor actor;
              
              @Observer(create=true, value="timedOutCheck")
              @Transactional
              public void listen(Long tid){
                      
                      if (taskInstance != null){
                              Long counter = (Long) taskInstance.getContextInstance().getVariable("counter");
                              if (counter == null) counter = 0L;
                              log.info("TimeOut received. taskInstance " +    taskInstance.getName());
                              counter++;
                              taskInstance.getContextInstance().setVariable("counter", counter);
                              if (counter > 10) {
                                      log.info("Timer expired over 10 times, special log will be made and failure will be registered.");
                                      taskInstance .getContextInstance().createVariable("refusedInteractionActor", taskInstance.getActorId());
                                      taskInstance.end();
                              }
                      }
                      else log.info("TimeOut received. taskInstance == null.");
              }
      }
      



      I tried every configuratuion and this solutions gives the least problems, just one single (but nasty) error:




      2009-09-11 23:58:58,193 ERROR [org.hibernate.event.def.AbstractFlushingEventListener] (JbpmJobExecutor:192.168.1.101:1) 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.job.Timer#4]
              at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1792)
              at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2435)
              at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
              at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
              at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:115)
              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:168)
              at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
              at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
              at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027)
              at org.jbpm.persistence.db.DbPersistenceService.flushSession(DbPersistenceService.java:278)
              at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:236)
              at org.jbpm.svc.Services.close(Services.java:236)
              at org.jbpm.JbpmContext.close(JbpmContext.java:136)
              at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:190)
              at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:60)
      
      



      As you can see in the observer bean I also tried to use @In/Out with the counter attribute but it gives the same problem.


      The funny thing is that the value get's saved and retrieved without a problem. It has to do with saving the object, because at the moment I directly do a te
      taskInstance.end() there are no errors.


      It works but I really don't like these kind of errors, because you never know...


      I am using jboss 5.1 with 2.1.1 and the whole application is using a single (MySQL) database (domainmodel and jbpm-tables).


      Any hints/tips would be very much appreciated!


      Leo







        • 1. Re: jBPM persistency problem
          Leo van den berg Master

          Changed to Asynchronous processing (with the Seam tag), keeps working the same, but with same error. I am still puzzling...


          • 2. Re: jBPM persistency problem
            Ronald van Kuijk Apprentice

            Try upgrading to jBPM 3.2.6SP1 (should be a drop-in replacement) and see what happens then. Have been some fixes afaik in this area

            • 3. Re: jBPM persistency problem
              Leo van den berg Master

              Hi Ronals,


              Thanks for the suggestion!


              I just changed the lib to 3.2.6S-P1 but the error remains. I  also tried it with 3.3.1.GA, but no luck so far, the strange thing is that data is persisted. I read something about not having full support for Timers but I can't find the page.


              I think it is basically a Transaction sync problem, so I need more digging.


               

              • 4. Re: jBPM persistency problem
                Ronald van Kuijk Apprentice

                Leo,


                3.3.1 is (almost) identical to 3.2.5 and the 3.3 branche has been retracted (not supported) so 3.2.6sp1 is the latest 3 release.


                You should be able to provide a real repeat now, that was an xsd thing (iirc) with a repeat of 'true' the delay is so small it causes the error.


                Besides that, with jBPM 3.2.6 you can configure that logging so the 'error' is not shown anymore since as you mentioned, it seems to work (and it actually does)

                • 5. Re: jBPM persistency problem
                  Leo van den berg Master

                  I've switched on debug for JBPM and found the following in the log, this is just a small part. The same block of logs is repeated hundreds of times. So there is definitely something really wrong with persistency of the process instance. 





                  ....
                  2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
                  2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
                  2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
                  2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
                  2009-09-15 11:31:19,044 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
                  2009-09-15 11:31:19,059 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (http-127.0.0.1-80-1) saving process instance
                  2009-09-15 11:31:19,075 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (http-127.0.0.1-80-1) posting logs to logging service.
                  2009-09-15 11:31:19,075 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (http-127.0.0.1-80-1) cascading save of 'ProcessInstance(1)'
                  2009-09-15 11:31:19,075 DEBUG [org.jbpm.svc.Services] (http-127.0.0.1-80-1) executing default save operations
                  And a lot more lines follow....
                  



                  • 6. Re: jBPM persistency problem
                    Ronald van Kuijk Apprentice

                    Did you turn debug on for org.jbpm or org.jbpm.svc? If the former is the case, executing the default save operation comes from somewhere outside jBPM. Can you turn debug on for more or even better, run it in debug mode and set a breakpoint on org.jbpm.svc.save.HibernateSaveOperation and see where the call originates? Oh, and did you change the repeat='yes' to something like e.g. repeat='1 min' ?

                    • 7. Re: jBPM persistency problem
                      Leo van den berg Master

                      I just changed the logging category to org.jbpm.svc and changed the true on the repeat to 1 minute.





                      2009-09-15 12:54:59,119 DEBUG [org.jbpm.svc.Services] (JbpmJobExecutor@192.168.1.100:1) executing default save operations
                      2009-09-15 12:54:59,135 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] (JbpmJobExecutor@192.168.1.100:1) saving process instance
                      2009-09-15 12:54:59,135 DEBUG [org.jbpm.svc.save.SaveLogsOperation] (JbpmJobExecutor@192.168.1.100:1) posting logs to logging service.
                      2009-09-15 12:54:59,135 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] (JbpmJobExecutor@192.168.1.100:1) cascading save of 'ProcessInstance(1)'
                      




                      I still get the same message, so let's see if I can find out where the request comes from..


                      • 8. Re: jBPM persistency problem
                        Leo van den berg Master

                        I think I found the related JIRA:


                        My Link


                        As stated in the last jira-reply, 3.2.6.GA didn't solve the problem. I will use a workaround until fixed.


                        Thanks anyway,


                        Leo

                        • 10. Re: jBPM persistency problem
                          Ronald van Kuijk Apprentice

                          As you mentioned before the code besides the repeat worked in the original jBPM and with 3.2.6SP1 even that works. But as I mentioned you can get rid of this specific logging line So no workaround is needed I think... or am I wrong?


                          btw, curious why you have this additional layer of indirection (raising a seam event (and having a listener) on a jbpm timer event).

                          • 11. Re: jBPM persistency problem
                            Ronald van Kuijk Apprentice

                            Some additional info which is in the jBPM docs I referred to, but nevertheless:


                            The original error was thrown by jBPM. The latter, although identical in message, is thrown by Hibernate, so a fix was made in jBPM and it works (afaik). The only thing that needs to be done is to circumvent the Hibernate message. The jBPM config param mentioned in the docs does exactely that.


                            • 12. Re: jBPM persistency problem
                              Leo van den berg Master

                              Hi Ronald,


                              thanks for your help. The extra observer is for test purposes. The application forms part of a (Traffic) Incident management application and timers are needed to remind operators or inspectors of pending tasks. Most users are not on-line all the time so I want to inform them also off-line (email, sms , fax or whatever). I normally hate cramping everything in the same component and basically with an observers you can do what you want. I used this combination also for async use, and to my big surprise Seam also provides the whole envronment to Asynchronous working components triggered by an asyncronous event. To be honeest, when I saw that wotking I was speechlees for a minute. So deep respect for the Seam-developers...


                              Leo

                              • 13. Re: jBPM persistency problem
                                Leo van den berg Master

                                Ronald,


                                Just a small additional question...


                                To see what happens I also switched on sql-logging and I see that JbpmJobExecutor is executed every 5 seconds, what I don't understand is why basically the same query is fired twice in each timeslot.


                                Leo

                                • 14. Re: jBPM persistency problem
                                  Ronald van Kuijk Apprentice

                                  Do you have the logging? Might be that because of the way locking is used, a rollback takes place and another attempt is done. Or is this always the case, even without jobs?


                                  btw, does my post about the logging help? Does it work now? What are the issues that are still left?

                                  1 2 Previous Next