5 Replies Latest reply on Jan 18, 2007 11:03 AM by johan.parent

    TaskInstance.end() hogs CPU time

    johan.parent

      Hi all,

      I'm evaluating jBPM(3.1.x) and therefore making simple test programs. To my surprise the profiler showed that the TaskInstance.end() method consumes 90+% of the time. In turn the time this spent in this method breaks down in:

      - Hibernate.IdentitySession.getUserByName() 46%
      - SchedulerSession.cancelTimersForProcessInstance() 41%


      Does anyone recognize the symptoms?

      Many thanks in advance,

      Johan

        • 1. Re: TaskInstance.end() hogs CPU time
          koen.aers

          It is difficult to draw conclusions without more detail. It is normal that a lot of time is spent in the TaskInstance.end() method because a lot of bookkeeping is done in that method. OTOH both the other percentages are probably dependent on your particular process that you are testint.

          Regards,
          Koen

          • 2. Re: TaskInstance.end() hogs CPU time
            johan.parent

            Hi Koen,

            Many thanks for your answer!

            You're are right of course, below the relevant code and definition.

            I've run into the exact same problem using a HSQLDB as well as a Sybase backend.

            The process definition is (IMHO) simple:

            <?xml version="1.0" encoding="UTF-8"?>
            
            <process-definition xmlns="urn:jbpm.org:jpdl-3.1" name="oe_process">
             <swimlane name="Prescriber">
             <assignment expression="user(doc1)"></assignment>
             </swimlane>
            
             <swimlane name="OrderEntryPeople">
             <assignment expression="user(oe1)" />
             </swimlane>
            
             <start-state name="Prescribe">
             <task swimlane='PrescriberTask' />
             <transition name="" to="Oe">
             </transition>
             </start-state>
            
             <task-node name="Oe">
             <task name="OeTask" swimlane="OrderEntryPeople">
             </task>
             <transition name="" to="Sign"></transition>
             </task-node>
            
            
             <task-node name="Sign">
             <task name="SignTask" swimlane="Prescriber"></task>
             <transition name="" to="end"></transition>
             </task-node>
            
             <end-state name="end"></end-state>
            
            </process-definition>
            


            As is the actual client code that consumes all the CPU time:

             public void processHandle(String processName) {
             // The code in this method could be the content of a message driven bean.
            
             // Lookup the pojo persistence context-builder that is configured above
             createSession();
            
             System.out.println(jbpmContext.getActorId());
            
             try {
             jbpmContext.setActorId(actorName);
            
             // First, we need to get the process instance back out of the database.
             // There are several options to know what process instance we are dealing
             // with here. The easiest in this simple test case is just to look for
             // the full list of process instances. That should give us only one
             // result. So let's look up the process definition.
            
             ProcessDefinition processDefinition = graphSession.findLatestProcessDefinition(processName);
            
             // Now we search for all the tasks waiting for our actor
             List tasksActor = taskMgmtSession.findTaskInstances(actorName);
            
             if (verboseFlag)
             System.out.println("ID: " + id + " got " + tasksActor.size() + " tasks waiting");
            
             if (tasksActor.size() > 0) {
             for (int i=0; i<tasksActor.size(); i++) {
             TaskInstance instance = (TaskInstance) tasksActor.get(i);
            
             if (verboseFlag) {
             System.out.println("ID: " + id + " Token positioned in " + instance.getName() + " " + instance.getId());
             System.out.println("Values: " + instance.getVariable("userName") + " " + instance.getVariable("UUID") );
             }
            
             // Skip already finished instances
             if (instance.hasEnded()) {
             System.out.println("Tasks has already been processed. CHECK THIS!!!!");
             } else {
             // Now we can do our work here and mark the end of this task
             instance.end();
             }
            
             // Now we can update the state of the execution in the database
             jbpmContext.save(instance);
             }
             }
             } finally {
             // Tear down the pojo persistence context.
             closeSession();
             }
             }
            


            To be complete I'll add the utility methods too:

             protected void createContext() {
             jbpmContext = jbpmConfiguration.createJbpmContext();
             }
            
             protected void closeContext() {
             jbpmContext.close();
             }
            
             protected void createSession() {
             createContext();
             initializeMembers();
             }
            
             protected void closeSession() {
             closeContext();
             resetMembers();
             }
            
             protected void initializeMembers() {
             session = jbpmContext.getSession();
             graphSession = jbpmContext.getGraphSession();
             taskMgmtSession = jbpmContext.getTaskMgmtSession();
             schedulerSession = jbpmContext.getSchedulerSession();
             contextSession = jbpmContext.getContextSession();
             }
            
             protected void resetMembers() {
             session = null;
             graphSession = null;
             taskMgmtSession = null;
             schedulerSession = null;
             contextSession = null;
             }
            



            Additional runs show that the observed decrease in performance (aka cpu hogging) coincides with a rapid increase in mem usage. I wonder whether I'm using the jbpm api correctly.

            Regards,

            Johan

            • 3. Re: TaskInstance.end() hogs CPU time
              koen.aers

              Johan,

              This client method is part of another loop, I presume? Are you creating more than one JbpmConfiguration outside this loop?
              The only thing that you should change is to create the context within the try-finally block instead of before it. But the rest of your process/code combo looks pretty normal to me.
              Maybe somebody else has more insight. In any case, if the problem persists, it would be good to exactly provide us the testbed because it could indicate a bug.
              Btw. What version of jBPM are you using? And on what platform?

              Regards,
              Koen

              • 4. Re: TaskInstance.end() hogs CPU time
                johan.parent

                Koen,

                The method was initially in a loop, but since it is supposed to handle all the instances it only called once in my test program.

                I initialize the jbpmcConfiguration like this:

                 static JbpmConfiguration jbpmConfiguration = JbpmConfiguration.getInstance();
                


                I'll follow your suggestion and move it (together with all the related code) within a try-catch block. Unfortunately, I won't be able to try before Monday.

                I use 3.1.2 on a XP box.

                Many thanks for your prompt reply Koen!

                Regards,

                Johan

                I

                • 5. Re: TaskInstance.end() hogs CPU time
                  johan.parent

                  No progress with this problem! I ran the Websale example with more success so I guess the problem resides in the way I have defined the identities or the assignment(s) then. After all the hibernate code that eat up all the time relates exactly to this.

                  <identity>
                   <!-- 2 doctors -->
                   <user id="1" name="doc1" email="doc1work" password="crunchcrunch" />
                   <user id="2" name="doc2" email="doc1@work" password="canthereyoubert,theresabananainmyear" />
                  
                   <!-- 2 OE people -->
                   <user id="3" name="oe1" email="oe1@work" password="ernie,theresabananainyourear" />
                   <user id="4" name="oe2" email="oe2@work" password="mayday mayday" />
                  
                   <!-- 3 groups -->
                   <group name="doctors" type="hierachy" />
                   <group name="oeteam" type="hierachy" />
                   <group name="patients" type="organisation" />
                  
                   <!-- Assign groups -->
                   <membership user="doc1" group="doctors" />
                   <membership user="doc2" group="doctors" />
                  
                   <membership user="oe1" group="oeteam" />
                   <membership user="oe2" group="oeteam" />
                  
                  </identity>
                  


                  Any suggestion, really ANY, will be much appreciated!

                  Regards,

                  Johan

                  ps: the process def. in at the beginning of this thread (which is long enough already...)