[jboss-jira] [JBoss JIRA] Commented: (JBPM-1042) org.jbpm.JbpmException: token '1' can't be locked by 'job[1]' cause it's already locked by 'token[1]'

Jeff Johnson (JIRA) jira-events at lists.jboss.org
Thu Aug 16 17:10:01 EDT 2007


    [ http://jira.jboss.com/jira/browse/JBPM-1042?page=comments#action_12372658 ] 
            
Jeff Johnson commented on JBPM-1042:
------------------------------------

I used jobExecutorDbTest as the starting point to the test case.  I plagarized heavily. 
The changes are:
1. Only creates one process instances.  Eliminates the issues associated with multiple job executor threads running.  You can change nbrOfThreads to 1 and still get the same behavior. I don't this this failure has anything to do with mulitiple job executor threads or hibernate session issues.
2. The process definition is simpler. It only contains a start node, node1, node2, and end  node.

My biased, novice opinion FWIW: Leave it open. It is slightly different test case, perhaps simpler case. Based on my review of the discussions and the JIRA reports, I think there are multiple issues that interact with each other. I tried to create a test case that isolates one specific problem. With luck solving this problem might make some of the other things more deterministic and simpler to debug. 

Looks like Node.execute(ExecutionContext context) change noticeable from 3.2GA (which I haven't used)
Just a little more detail.
In 3.2.1 Node.execute() calls org.jbpm.graph.def.GraphElement.executeAction().  This is the code that locks the token and then actually makes the call to action.execute().  Notice that the lock isn't unlocked until the finally block.  
// GraphElement
public void executeAction(Action action, ExecutionContext executionContext) {
    Token token = executionContext.getToken();

    // create action log
    ActionLog actionLog = new ActionLog(action);
    token.startCompositeLog(actionLog);

    try {
      // update the execution context
      executionContext.setAction(action);

      // execute the action
      log.debug("executing action '"+action+"'");
      String lockOwnerId = "token["+token.getId()+"]"; 
      try {
        token.lock(lockOwnerId);   // THIS IS WERE IT GETS LOCKED
        
        if (UserCodeInterceptorConfig.userCodeInterceptor!=null) {
          UserCodeInterceptorConfig.userCodeInterceptor.executeAction(action, executionContext);
        } else {
          action.execute(executionContext);
        }

      } finally {
        token.unlock(lockOwnerId);
      }
   
    } catch (Exception exception) {
      // NOTE that Error's are not caught because that might halt the JVM and mask the original Error.
      log.error("action threw exception: "+exception.getMessage(), exception);
      
      // log the action exception 
      actionLog.setException(exception);
   
      // if an exception handler is available
      raiseException(exception, executionContext);
      
    } finally {
      executionContext.setAction(null);
      token.endCompositeLog();
    }
  }

The problem comes in Node.enter() in the fragment below.  

   // execute the node
    if (isAsync) {
      ExecuteNodeJob job = createAsyncContinuationJob(token);
      MessageService messageService = (MessageService) 
             Services.getCurrentService(Services.SERVICENAME_MESSAGE);
      messageService.send(job);
      token.lock(job.toString());    //####  OOPS! THE TOKEN IS ALREADY LOCKED! #####
    } else {
      execute(executionContext);
    }
 

> org.jbpm.JbpmException: token '1' can't be locked by 'job[1]' cause it's already locked by 'token[1]'
> -----------------------------------------------------------------------------------------------------
>
>                 Key: JBPM-1042
>                 URL: http://jira.jboss.com/jira/browse/JBPM-1042
>             Project: JBoss jBPM
>          Issue Type: Bug
>          Components: Core Engine
>    Affects Versions:  jBPM jPDL 3.2.1
>         Environment: jBPM 3.2.1
> Java 1.6 update 2
> Windows XP
> Run as a standalone Java application. No app server.
> Use the standard test framework and configuration. (HyperSonic, etc).  Same behavior with Oracle 10g
>            Reporter: Jeff Johnson
>         Assigned To: Tom Baeyens
>         Attachments: SimpleAsyncProcessTest.java
>
>
> org.jbpm.JbpmException: token '1' can't be locked by 'job[1]' cause it's already locked by 'token[1]' is thrown  when a node has an ActionHandler that propagates execution via  ExecutionContext.leaveNode() to a node that is marked as async="true".
> My ActionHandler.execute() method: 
>     public void execute(ExecutionContext executionContext) throws Exception
>     {
>       // Normally would do stuff here
>       // Leave via the default transition
>       // When this test case was written, this method would throw when 
>       // it tried to enter Node2 because it would try to lock the token but 
>       // it is already locked.
>       executionContext.leaveNode();
>     }
>   }
> Section 9.5 of the user guide states: "Note the difference
> between an action that is placed in an event versus an action that is placed in a node. Actions that are put in an event
> are executed when the event fires. Actions on events have no way to influence the flow of control of the process.
> It is similar to the observer pattern. On the other hand, an action that is put on a node has the responsibility of propagating the execution.
> The execute() method from Node does not propagate the execution context if there is a custom action associated with the node. Based on this code and the documentation above, I concluded that I must propagate the execution inside my action handler.
> // From org.jbpm.graph.def.Node.execute()
> public void execute(ExecutionContext executionContext) {
>     // if there is a custom action associated with this node
>     if (action!=null) {
>       try {
>         // execute the action
>         executeAction(action, executionContext);
>       } catch (Exception exception) {
>         // NOTE that Error's are not caught because that might halt the JVM and mask the original Error.
>         // search for an exception handler or throw to the client
>         raiseException(exception, executionContext);
>       }
>     } else {
>       // let this node handle the token
>       // the default behaviour is to leave the node over the default transition.
>       leave(executionContext);
>     }
>   }
> However this appears to conflict with the comments for Token.lock()
>  /**
>    * locks a process instance for further execution.  A locked token 
>    * cannot continue execution.  This is a non-persistent
>    * operation.  This is used to prevent tokens being propagated during 
>    * the execution of actions.
>    * @see #unlock(String) 
>    */
>   public void lock(String lockOwnerId) {
> Originally this test case failed in jBPM 3.2.1 with the following exception
>  * org.jbpm.JbpmException: token '1' can't be locked by 'job[1]' cause it's already locked by 'token[1]'
>   at org.jbpm.graph.exe.Token.lock(Token.java:646)
>   at org.jbpm.graph.def.Node.enter(Node.java:316)
>   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>   at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
>   at java.lang.reflect.Method.invoke(Unknown Source)
>   at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
>   at org.jbpm.graph.def.Node$$EnhancerByCGLIB$$cc789161.enter(<generated>)
>   at org.jbpm.graph.def.Transition.take(Transition.java:151)
>   at org.jbpm.graph.def.Node.leave(Node.java:393)
>   at org.jbpm.graph.def.Node.leave(Node.java:357)
>   at org.jbpm.graph.exe.ExecutionContext.leaveNode(ExecutionContext.java:120)
>   at org.jbpm.job.executor.SimpleAsyncProcessTest$AsyncAction.execute(SimpleAsyncProcessTest.java:57)
>   at org.jbpm.graph.def.Action.execute(Action.java:122)
>   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>   at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
>   at java.lang.reflect.Method.invoke(Unknown Source)
>   at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
>   at org.jbpm.graph.def.Action$$EnhancerByCGLIB$$4852cc95.execute(<generated>)
>   at org.jbpm.graph.def.GraphElement.executeAction(GraphElement.java:255)
>   at org.jbpm.graph.def.Node.execute(Node.java:338)
>   at org.jbpm.graph.def.Node.enter(Node.java:318)
>   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>   at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
>   at java.lang.reflect.Method.invoke(Unknown Source)
>   at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
>   at org.jbpm.graph.def.Node$$EnhancerByCGLIB$$cc789161.enter(<generated>)
>   at org.jbpm.graph.def.Transition.take(Transition.java:151)
>   at org.jbpm.graph.def.Node.leave(Node.java:393)
>   at org.jbpm.graph.node.StartState.leave(StartState.java:70)
>   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>   at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
>   at java.lang.reflect.Method.invoke(Unknown Source)
>   at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:157)
>   at org.jbpm.graph.def.Node$$EnhancerByCGLIB$$cc789161.leave(<generated>)
>   at org.jbpm.graph.exe.Token.signal(Token.java:194)
>   at org.jbpm.graph.exe.Token.signal(Token.java:139)
>   at org.jbpm.graph.exe.ProcessInstance.signal(ProcessInstance.java:270)
>   at org.jbpm.job.executor.SimpleAsyncProcessTest.launchProcess(SimpleAsyncProcessTest.java:112)
>   at org.jbpm.job.executor.SimpleAsyncProcessTest.testConsecutiveAycnActionHandlers(SimpleAsyncProcessTest.java:69)
>   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>   at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
>   at java.lang.reflect.Method.invoke(Unknown Source)
>   at junit.framework.TestCase.runTest(TestCase.java:154)
>   at junit.framework.TestCase.runBare(TestCase.java:127)
>   at junit.framework.TestResult$1.protect(TestResult.java:106)
>   at junit.framework.TestResult.runProtected(TestResult.java:124)
>   at junit.framework.TestResult.run(TestResult.java:109)
>   at junit.framework.TestCase.run(TestCase.java:118)
>   at junit.framework.TestSuite.runTest(TestSuite.java:208)
>   at junit.framework.TestSuite.run(TestSuite.java:203)
>   at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
>   at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
>   at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
>   at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
>   at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
>   at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        



More information about the jboss-jira mailing list