State events fire order

[jbaton]

Hi all,

jbpm newbie, I wanted to know the order in which the events were fired for a state, I got the following order

NodeEnter -> BeforeSignal -> NodeLeave -> AfterSignal

Which looks surprising, as I was expecting

NodeEnter -> BeforeSignal -> AfterSignal -> NodeLeave

that looks more natural.

Is this a bug of my test program or is this really the actual implementation ?

Thanks


JBaton

[cpob]

I got a different order.


You have to have a BEFORE SIGNAL, before you can even leave the node, then you leave the node, then you enter the NEXT NODE,a nd then it's the after signal.

Below is the processdefinition.xml I used

<?xml version="1.0" encoding="UTF-8"?>

<process-definition
 xmlns="urn:jbpm.org:jpdl-3.1"
 name="simpleactions">
 <start-state name="start">
 <task>
 <controller>
 <variable name="color" />
 <variable name="size" />
 </controller>
 </task>
 <transition name="to_state" to="first">
 <action name="action" class="com.sample.action.MessageActionHandler">
 <message>Going to the first state!</message>
 </action>
 </transition>
 <transition name="to node" to="node1"></transition>
 </start-state>
 <state name="first">
 <transition name="to_end" to="end">
 <action name="action" class="com.sample.action.MessageActionHandler">
 <message>About to finish!</message>
 </action>
 </transition>
 </state>
 <end-state name="end"></end-state>
 <task-node name="node1">
 <task name="task1"></task>
 <event type="before-signal">
 <action name="action1" class="com.sample.action.MessageActionHandler">
 <message>BEFORE SIGNAL</message>
 </action>
 </event>
 <event type="after-signal">
 <action name="after signal action" class="com.sample.action.MessageActionHandler">
 <message>AFTER-SIGNAL</message>
 </action>
 </event>
 <event type="node-enter">
 <action name="node enter action" class="com.sample.action.MessageActionHandler">
 <message>NODE ENTER</message>
 </action>
 </event>
 <event type="node-leave">
 <action name="Node Leave Action" class="com.sample.action.MessageActionHandler">
 <message>Node LEAVE</message>
 </action>
 </event>
 <transition name="from node" to="end"></transition>
 </task-node>
</process-definition>

[cpob]

Sorry, I forgot to post my log:

12:46:16,671 DEBUG [GraphElement] event 'before-signal' on 'StartState(start)' for 'Token(/)'
12:46:16,671 DEBUG [GraphElement] event 'node-leave' on 'StartState(start)' for'Token(/)'
12:46:16,671 DEBUG [GraphElement] event 'transition' on 'Transition(to node)' for 'Token(/)'
12:46:16,671 DEBUG [GraphElement] event 'node-enter' on 'TaskNode(node1)' for 'Token(/)'
12:46:16,671 WARN [StatefulPersistenceContext] Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks ==
12:46:16,671 DEBUG [GraphElement] executing action 'action[node enter action]'
12:46:16,681 DEBUG [VariableContainer] create variable 'message' in 'TokenVariableMap1b7a261' with value 'NODE ENTER'
12:46:16,681 DEBUG [GraphElement] event 'task-create' on 'Task(task1)' for 'Token(/)'
12:46:16,681 DEBUG [GraphElement] event 'after-signal' on 'StartState(start)' for 'Token(/)'

[jbaton]

Hi cpob,

Thanks for your help.

Using your xml in my (process-runner) program, I get the following log (truncated for page's sanity)

13:34:13,964 [Thread-0] DEBUG GraphElement : event 'process-start' on 'ProcessDefinition(cpob)' for 'Token(/)'
*** signal ! ***
13:34:13,964 [Thread-0] DEBUG GraphElement : event 'before-signal' on 'StartState(start)' for 'Token(/)'
13:34:13,964 [Thread-0] DEBUG GraphElement : event 'node-leave' on 'StartState(start)' for 'Token(/)'
13:34:13,964 [Thread-0] DEBUG GraphElement : event 'transition' on 'Transition(to_state)' for 'Token(/)'
13:34:13,964 [Thread-0] DEBUG GraphElement : executing action 'action[action]'
13:34:14,042 [Thread-0] DEBUG VariableContainer : create variable 'message' in 'TokenVariableMap18b81e3' with value 'Going to the first state!'
13:34:14,073 [Thread-0] DEBUG Converters : adding converter 'D', 'org.jbpm.context.exe.converter.DoubleToStringConverter'
13:34:14,073 [Thread-0] DEBUG Converters : adding converter 'C', 'org.jbpm.context.exe.converter.CharacterToStringConverter'
13:34:14,089 [Thread-0] DEBUG Converters : adding converter 'B', 'org.jbpm.context.exe.converter.BooleanToStringConverter'
13:34:14,089 [Thread-0] DEBUG Converters : adding converter 'Y', 'org.jbpm.context.exe.converter.BytesToByteArrayConverter'
13:34:14,104 [Thread-0] DEBUG Converters : adding converter 'A', 'org.jbpm.context.exe.converter.DateToLongConverter'
13:34:14,104 [Thread-0] DEBUG Converters : adding converter 'R', 'org.jbpm.context.exe.converter.SerializableToByteArrayConverter'
13:34:14,104 [Thread-0] DEBUG Converters : adding converter 'I', 'org.jbpm.context.exe.converter.IntegerToLongConverter'
13:34:14,104 [Thread-0] DEBUG Converters : adding converter 'H', 'org.jbpm.context.exe.converter.ShortToLongConverter'
13:34:14,104 [Thread-0] DEBUG Converters : adding converter 'G', 'org.jbpm.context.exe.converter.FloatToDoubleConverter'
13:34:14,120 [Thread-0] DEBUG Converters : adding converter 'F', 'org.jbpm.context.exe.converter.FloatToStringConverter'
13:34:14,120 [Thread-0] DEBUG Converters : adding converter 'E', 'org.jbpm.context.exe.converter.ByteToLongConverter'
13:34:14,151 [Thread-0] DEBUG GraphElement : event 'node-enter' on 'State(first)' for 'Token(/)'
13:34:14,151 [Thread-0] DEBUG GraphElement : event 'after-signal' on 'StartState(start)' for 'Token(/)'
*** signal ! ***
13:34:14,151 [Thread-0] DEBUG GraphElement : event 'before-signal' on 'State(first)' for 'Token(/)'
13:34:14,151 [Thread-0] DEBUG GraphElement : event 'node-leave' on 'State(first)' for 'Token(/)'
13:34:14,151 [Thread-0] DEBUG GraphElement : event 'transition' on 'Transition(to_end)' for 'Token(/)'
13:34:14,151 [Thread-0] DEBUG GraphElement : executing action 'action[action]'
13:34:14,167 [Thread-0] DEBUG VariableContainer : update variable 'message' in 'TokenVariableMap18b81e3' to value 'About to finish!'
13:34:14,167 [Thread-0] DEBUG GraphElement : event 'node-enter' on 'EndState(end)' for 'Token(/)'
13:34:14,167 [Thread-0] DEBUG GraphElement : event 'process-end' on 'ProcessDefinition(cpob)' for 'Token(/)'
13:34:14,167 [Thread-0] DEBUG GraphElement : event 'after-signal' on 'State(first)' for 'Token(/)'

The program's main part is as simple as that

...
while(!instance.hasEnded()){
 System.out.println("*** signal ! ***");
 instance.signal();
}

As you can see, I get the same order than previously.

nodeEnter > beforeSignal > nodeLeave > afterSignal

But I was wondering about some logs having exactly the same time, I did a program that writes the running class name to a disk and to my surprise, the launch order is still the odd looking one.

In my opinion, it would had been more intuitive to have something like
nodeEnter > (signal sent) > beforeSignal > afterSignal > nodeLeave

Although I don't get the use of the *Signal methods, should look deeper into the documentation.

Thanks Cpob


JBaton

[kukeltje]

Read the logging again....

The token is in state "first", then you signal it and get the following logs:

13:34:14,151 [Thread-0] DEBUG GraphElement : event 'before-signal' on 'State(first)' for 'Token(/)'
13:34:14,151 [Thread-0] DEBUG GraphElement : event 'node-leave' on 'State(first)' for 'Token(/)'
13:34:14,151 [Thread-0] DEBUG GraphElement : event 'transition' on 'Transition(to_end)' for 'Token(/)'
13:34:14,151 [Thread-0] DEBUG GraphElement : executing action 'action[action]'
13:34:14,167 [Thread-0] DEBUG VariableContainer : update variable 'message' in 'TokenVariableMap18b81e3' to value 'About to finish!'
13:34:14,167 [Thread-0] DEBUG GraphElement : event 'node-enter' on 'EndState(end)' for 'Token(/)'
13:34:14,167 [Thread-0] DEBUG GraphElement : event 'process-end' on 'ProcessDefinition(cpob)' for 'Token(/)'
13:34:14,167 [Thread-0] DEBUG GraphElement : event 'after-signal' on 'State(first)' for 'Token(/)'

Which is correct, you get a
- before signal (which is a way of telling the system: 'hey there is a signal comming'
- then you leave state "first"
- you are taking the "to_end" transition"
- you enter state "end"
- the process ends
- the signal is completely processed

So there is nothing wrong with your logging, you just read it wrong.

Remember, jBPM does nothing unless you signal it in one way or another. If you start reading the log from the moment you signal it, everything is correct

[cpob]

What you need to think about is separation of processes. You need to ignore the node enter on to your Node(First) That happened with the previous signal, and does not happen in the signal while your token is in 'First'

For example, we have a simple graph, made of 2 simple nodes, A and B.

Currently your token is on A.

You would then signal the token. Before Signal gets fired.
The signal would cause the token to leave A. Leave Node (for node A) fires
The token would then enter Node B Node Enter (for node B) fires
The token would then be done signalling After Signal

You're going to see node leave/enter for 2 separate nodes across a signal event, since that signal causes the transition.

The signal method is just a way to tell the token to move to the next node/state/etc on a specific transition). You have to signal the token (ending a task does this as well), for it to move to the next node, which is why you have to have a begin signal before you can have a leave node.

[jbaton]

Cpob, kukeltje, thanks a lot for your help and the clarity of your explanations


JBaton