6 Replies Latest reply on May 23, 2008 11:51 AM by kukeltje

    Problem with Timer execution. process classloader can't find

    rayun

      Hi,
      I have a problem with the execution of an action for my timers.
      I am using JBPM 3.2.2 with Tomcat and try to execute a process with a timer on 2 tasks in a fork.

      The part of the process which give me troubles is the following :

      <fork name="fork1">
       <transition name="To client" to="Client validation"></transition>
       <transition name="To broker" to="Broker validation"></transition>
       </fork>
       <task-node name="Client validation">
       <task name="client complete and validate informations" swimlane="client">
       <timer name="reminder1" duedate="30 seconds">
       <action name="Send a time-out notice for client" class="common.processhandlers.DueDateHandler"></action>
       </timer>
       </task>
       <transition name="Client informations completed" to="join1"></transition>
       </task-node>
       <task-node name="Broker validation">
       <task name="broker complete and validate informations" swimlane="broker">
       <timer name="reminder2" duedate="30 seconds">
       <action name="Send a time-out notice for broker" class="common.processhandlers.DueDateHandler"></action>
       </timer>
       </task>
       <transition name="Broker informations completed" to="join1"></transition>
       </task-node>
       <join name="join1">
       <transition name="All informations available" to="end"></transition>
       </join>
      


      The class DueDateHandler i try to execute in both timer is in the sources of the web application executing the process and do nothing but displaying a message.

      When i try to execute this process and the duedate for the timers expire, i get the following Error :


      ERROR - def.AbstractFlushingEventListener - 301 - 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#21383]
       at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
       at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2407)
       at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2307)
       at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2607)
       at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:92)
       at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
       at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
       at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:142)
       at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
       at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
       at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
       at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
       at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
       at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:256)
       at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:214)
       at org.jbpm.svc.Services.close(Services.java:225)
       at org.jbpm.JbpmContext.close(JbpmContext.java:139)
       at org.jbpm.job.executor.JobExecutorThread.acquireJobs(JobExecutorThread.java:144)
       at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:58)
      INFO - db.DbPersistenceService - 258 - optimistic locking failed
      INFO - svc.Services - 229 - problem closing service 'persistence': optimistic locking failed
      WARN - StatefulPersistenceContext.ProxyWarnLog - 615 - Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks ==
      WARN - StatefulPersistenceContext.ProxyWarnLog - 615 - Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks ==
      ERROR - instantiation.Delegation - 142 - couldn't load delegation class 'common.processhandlers.DueDateHandler'
      java.lang.ClassNotFoundException: class 'common.processhandlers.DueDateHandler' could not be found by the process classloader
       at org.jbpm.instantiation.ProcessClassLoader.findClass(ProcessClassLoader.java:118)
       at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
       at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
       at org.jbpm.instantiation.Delegation.instantiate(Delegation.java:140)
       at org.jbpm.instantiation.Delegation.getInstance(Delegation.java:125)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.instantiation.Delegation$$EnhancerByCGLIB$$87bad03b.getInstance(<generated>)
       at org.jbpm.graph.def.Action.execute(Action.java:121)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.graph.def.Action$$EnhancerByCGLIB$$322143d.execute(<generated>)
       at org.jbpm.graph.def.GraphElement.executeAction(GraphElement.java:264)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.taskmgmt.def.Task$$EnhancerByCGLIB$$b38133b8.executeAction(<generated>)
       at org.jbpm.job.Timer.execute(Timer.java:56)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.job.Job$$EnhancerByCGLIB$$7970239a.execute(<generated>)
       at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:164)
       at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64)
      ERROR - instantiation.Delegation - 165 - couldn't instantiate delegation class 'common.processhandlers.DueDateHandler'
      java.lang.NullPointerException
       at org.jbpm.instantiation.FieldInstantiator.newInstance(FieldInstantiator.java:105)
       at org.jbpm.instantiation.FieldInstantiator.instantiate(FieldInstantiator.java:48)
       at org.jbpm.instantiation.Delegation.instantiate(Delegation.java:163)
       at org.jbpm.instantiation.Delegation.getInstance(Delegation.java:125)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.instantiation.Delegation$$EnhancerByCGLIB$$87bad03b.getInstance(<generated>)
       at org.jbpm.graph.def.Action.execute(Action.java:121)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.graph.def.Action$$EnhancerByCGLIB$$322143d.execute(<generated>)
       at org.jbpm.graph.def.GraphElement.executeAction(GraphElement.java:264)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.taskmgmt.def.Task$$EnhancerByCGLIB$$b38133b8.executeAction(<generated>)
       at org.jbpm.job.Timer.execute(Timer.java:56)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.job.Job$$EnhancerByCGLIB$$7970239a.execute(<generated>)
       at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:164)
       at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64)
      ERROR - def.GraphElement - 275 - action threw exception: null
      java.lang.NullPointerException
       at org.jbpm.graph.def.Action.execute(Action.java:122)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.graph.def.Action$$EnhancerByCGLIB$$322143d.execute(<generated>)
       at org.jbpm.graph.def.GraphElement.executeAction(GraphElement.java:264)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.taskmgmt.def.Task$$EnhancerByCGLIB$$b38133b8.executeAction(<generated>)
       at org.jbpm.job.Timer.execute(Timer.java:56)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.job.Job$$EnhancerByCGLIB$$7970239a.execute(<generated>)
       at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:164)
       at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64)
      WARN - job.Timer - 62 - timer action threw exception
      org.jbpm.graph.def.DelegationException
       at org.jbpm.graph.def.GraphElement.raiseException(GraphElement.java:387)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.graph.def.ProcessDefinition$$EnhancerByCGLIB$$c4ed9d31.raiseException(<generated>)
       at org.jbpm.graph.def.GraphElement.raiseException(GraphElement.java:378)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.graph.node.TaskNode$$EnhancerByCGLIB$$45bbca9f.raiseException(<generated>)
       at org.jbpm.graph.def.GraphElement.raiseException(GraphElement.java:378)
       at org.jbpm.graph.def.GraphElement.executeAction(GraphElement.java:281)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.taskmgmt.def.Task$$EnhancerByCGLIB$$b38133b8.executeAction(<generated>)
       at org.jbpm.job.Timer.execute(Timer.java:56)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.job.Job$$EnhancerByCGLIB$$7970239a.execute(<generated>)
       at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:164)
       at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64)
      Caused by: java.lang.NullPointerException
       at org.jbpm.graph.def.Action.execute(Action.java:122)
       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 org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
       at org.jbpm.graph.def.Action$$EnhancerByCGLIB$$322143d.execute(<generated>)
       at org.jbpm.graph.def.GraphElement.executeAction(GraphElement.java:264)
       ... 15 more
      



      The class loader won't find the action to execute for the timers while the class is present in the application.

      I tried many things but couldn't find a solution to this problem.


        • 1. Re: Problem with Timer execution. process classloader can't
          a.wintersteiger

          Hi rayun,

          I have exactly the same problem and - thanks for posting - am working on it since last friday. I have built a simple test process and the problem comes in with *even only one timer* - but only when you fork! I have tried the same thing without any forked executions, works fine.

          But I only get the StaleObjectStateException, like this:


          17:42:59,231 INFO [DbPersistenceService] optimistic locking failed
          17:42:59,247 INFO [Services] problem closing service 'persistence': optimistic locking failed
          17:42:59,309 WARN [ProxyWarnLog] Narrowing proxy to class org.jbpm.job.Timer - this operation breaks ==
          17:42:59,341 ERROR [AbstractFlushingEventListener] 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#271874]
          at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1765)
          at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2523)
          at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
          at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
          at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
          at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
          at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146)
          at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
          at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
          at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
          at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
          at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
          at org.jbpm.persistence.db.DbPersistenceService.commit(DbPersistenceService.java:256)
          at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:214)
          at org.jbpm.svc.Services.close(Services.java:225)
          at org.jbpm.JbpmContext.close(JbpmContext.java:139)
          at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:184)
          at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64)


          with this process definition:
          <process-definition xmlns="urn:jbpm.org:jpdl-3.2" name="simple">
           <start-state name="start">
           <transition to="fork1" name="to_state">
           </transition>
           </start-state>
          
           <state name="first">
           <timer duedate="2 Minutes" name="Wait2Minutes" transition="to_end">
           <action></action>
           </timer>
           <transition to="join1" name="to_end">
           </transition>
           </state>
          
           <fork name="fork1">
           <transition to="node1"></transition>
           <transition to="first" name="to first"></transition>
           </fork>
          
           <join name="join1">
           <transition to="end"></transition>
           </join>
          
           <node name="node1">
           <transition to="join1"></transition>
           </node>
          
          
           <end-state name="end"></end-state>
          </process-definition>
          

          Your ClassNotFoundException looks to me like you have forgotten to deploy your handler classes together with the process...?!? Maybe can tell more tomorrow.

          Andy

          • 2. Re: Problem with Timer execution. process classloader can't
            kukeltje

            known issue afaik with forks that do not contain waitstates in each 'leg' of the fork (shouldn't that be called 'tooth')

            • 3. Re: Problem with Timer execution. process classloader can't
              a.wintersteiger

              Hi Ronald,

              thank you for the answer. Interesting that this is a known issue (bug oder by desing?). Do you know any work around for this?

              IMHO it's quite a common scenario to have a "fork with two legs" one doing something rather quickly (like sending a message or so, without a wait state) and in the other one waiting for a result...

              Best regards
              Andy

              • 4. Re: Problem with Timer execution. process classloader can't
                kukeltje

                Andy,

                It's certainly nicht bei design, it is a 'bug'. All info there is is in the Jira.

                A workaround could be to not send the message in a node in a leg, but do it in the transition to the other node (so no fork is needed since it is not done in real parallel if it is not async)

                • 5. Re: Problem with Timer execution. process classloader can't
                  a.wintersteiger

                  Hi Ronald,

                  great, thank you very much - I have spent about two hours searching in jBPM Jira but did not find this issue (probably I overlooked it). As this is a process with much more "forking going on in it" (3 levels deep) and the process is somehow given by the customer there is no easy workaround. Anyway, I've contacted JBoss support to provide help. For the meantime I implemented a kind of BUSY_WAITING using Thread.wait() which works fine as long as there is little load (threads, I use MDBs signalling the process instance) ...

                  Andy

                  • 6. Re: Problem with Timer execution. process classloader can't
                    kukeltje

                    Andy,

                    It is kind of related to the configuration of the datasource . Especially how transaction isolation is configured (or, if not, what the default of your DB is). The docs say the minimal isolation should be readcommitted. In that case the trigger/timer should not be visible yet if not all legs of the fork are committed.

                    Also if you have a testcase where the task is signalled very quickly before the rest of the process is comitted (do commit/close by reloading the process at the correct moments in the unittest, see the jbpm unittests for examples), you can get these errors which in real work you do not get.

                    Can you also post your unittest?