Task assignment handler not being called second time through
iterrell Feb 23, 2006 10:10 AMI have a process with a task in a loop, and although the assignment handler gets called the first time, it doesn't get called any subsequent times. Here's an example process that shows the behavior:
<process-definition name="Task Loop Test"> <swimlane name='sl'> <assignment class='com.gallium.sandbox.delegation.TaskAssignmentHandler' /> </swimlane> <start-state name="start"> <transition name="go" to="mytask" /> </start-state> <task-node name="mytask"> <task name='myTask' swimlane='sl' /> <transition name="again" to="wait" /> <transition name="done" to="end" /> </task-node> <state name="wait"> <timer duedate="20 seconds" transition="continue" /> <transition name="continue" to="mytask" /> </state> <end-state name="end"/> </process-definition>
Here's my assignment handler:
public void assign(Assignable ass, ExecutionContext ctx) throws Exception { log.debug("****************"); log.debug("Assigning to Ian"); log.debug("****************"); ass.setActorId("ian"); }
Here's my log for leaving the start state:
2006-02-23 09:58:42,375 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, scheduler, logging, persistence, authentication]' 2006-02-23 09:58:42,375 DEBUG [org.jbpm.JbpmContext] creating JbpmContext 2006-02-23 09:58:42,375 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service 2006-02-23 09:58:42,375 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session 2006-02-23 09:58:42,375 DEBUG [org.jbpm.persistence.db.DbPersistenceService] beginning hibernate transaction 2006-02-23 09:58:42,406 DEBUG [org.jbpm.graph.def.GraphElement] event 'before-signal' on 'StartState(start)' for 'Token(/)' 2006-02-23 09:58:42,421 WARN [org.hibernate.engine.StatefulPersistenceContext] Narrowing proxy to class org.jbpm.graph.node.StartState - this operation breaks == 2006-02-23 09:58:42,421 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-leave' on 'StartState(start)' for 'Token(/)' 2006-02-23 09:58:42,421 DEBUG [org.jbpm.graph.def.GraphElement] event 'transition' on 'Transition(go)' for 'Token(/)' 2006-02-23 09:58:42,421 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-enter' on 'TaskNode(mytask)' for 'Token(/)' 2006-02-23 09:58:42,421 WARN [org.hibernate.engine.StatefulPersistenceContext] Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks == 2006-02-23 09:58:42,921 DEBUG [org.jbpm.graph.def.GraphElement] event 'task-create' on 'Task(myTask)' for 'Token(/)' 2006-02-23 09:58:42,953 DEBUG [long] **************** 2006-02-23 09:58:42,953 DEBUG [long] Assigning to Ian 2006-02-23 09:58:42,953 DEBUG [long] **************** 2006-02-23 09:58:42,953 DEBUG [org.jbpm.graph.def.GraphElement] event 'task-assign' on 'Task(myTask)' for 'Token(/)' 2006-02-23 09:58:42,953 DEBUG [org.jbpm.graph.def.GraphElement] event 'after-signal' on 'StartState(start)' for 'Token(/)' 2006-02-23 09:58:42,953 DEBUG [org.jbpm.svc.Services] executing default save operations 2006-02-23 09:58:42,953 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance 2006-02-23 09:58:42,953 DEBUG [org.jbpm.svc.save.SaveLogsOperation] flushing logs to logging service. 2006-02-23 09:58:42,953 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance@1ba3afe' 2006-02-23 09:58:42,984 DEBUG [org.jbpm.JbpmContext] closing JbpmContext 2006-02-23 09:58:42,984 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@14cf1b9 2006-02-23 09:58:42,984 DEBUG [org.jbpm.persistence.db.DbPersistenceService] committing hibernate transaction 2006-02-23 09:58:43,171 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session 2006-02-23 09:58:43,187 DEBUG [org.jbpm.svc.Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@1c33b55
It enters the task node and correctly calls the swimlane's assignment handler.
Here I end the task with a transition to "wait:"
2006-02-23 09:59:08,656 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, scheduler, logging, persistence, authentication]' 2006-02-23 09:59:08,656 DEBUG [org.jbpm.JbpmContext] creating JbpmContext 2006-02-23 09:59:08,656 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service 2006-02-23 09:59:08,656 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session 2006-02-23 09:59:08,656 DEBUG [org.jbpm.persistence.db.DbPersistenceService] beginning hibernate transaction 2006-02-23 09:59:08,781 DEBUG [org.jbpm.graph.def.GraphElement] event 'task-end' on 'Task(myTask)' for 'Token(/)' 2006-02-23 09:59:08,796 DEBUG [org.jbpm.taskmgmt.exe.TaskInstance] completion of task 'myTask' results in taking transition 'Transition(again)' 2006-02-23 09:59:08,796 DEBUG [org.jbpm.graph.def.GraphElement] event 'before-signal' on 'TaskNode(mytask)' for 'Token(/)' 2006-02-23 09:59:08,796 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-leave' on 'TaskNode(mytask)' for 'Token(/)' 2006-02-23 09:59:08,796 DEBUG [org.jbpm.graph.def.GraphElement] event 'transition' on 'Transition(again)' for 'Token(/)' 2006-02-23 09:59:08,812 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-enter' on 'State(wait)' for 'Token(/)' 2006-02-23 09:59:08,812 WARN [org.hibernate.engine.StatefulPersistenceContext] Narrowing proxy to class org.jbpm.graph.node.State - this operation breaks == 2006-02-23 09:59:08,875 DEBUG [org.jbpm.graph.def.GraphElement] executing action 'CreateTimerAction(130cda4)' 2006-02-23 09:59:08,875 DEBUG [org.jbpm.graph.def.GraphElement] event 'timer-create' on 'State(wait)' for 'Token(/)' 2006-02-23 09:59:08,890 DEBUG [org.jbpm.graph.def.GraphElement] event 'after-signal' on 'TaskNode(mytask)' for 'Token(/)' 2006-02-23 09:59:08,890 DEBUG [org.jbpm.svc.Services] executing default save operations 2006-02-23 09:59:08,890 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance 2006-02-23 09:59:08,890 DEBUG [org.jbpm.svc.save.SaveLogsOperation] flushing logs to logging service. 2006-02-23 09:59:08,890 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance@5e60f2' 2006-02-23 09:59:08,921 DEBUG [org.jbpm.JbpmContext] closing JbpmContext 2006-02-23 09:59:08,921 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@2720f6 2006-02-23 09:59:08,921 DEBUG [org.jbpm.persistence.db.DbPersistenceService] committing hibernate transaction 2006-02-23 09:59:08,984 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session 2006-02-23 09:59:08,984 DEBUG [org.jbpm.svc.Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService@5353c8 2006-02-23 09:59:08,984 DEBUG [org.jbpm.svc.Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@a19cc5
Here's a clip to show that it was saved properly and the scheduler finds the timer:
2006-02-23 09:59:11,234 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, scheduler, logging, persistence, authentication]' 2006-02-23 09:59:11,328 DEBUG [org.jbpm.JbpmContext] creating JbpmContext 2006-02-23 09:59:11,328 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service 2006-02-23 09:59:11,328 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session 2006-02-23 09:59:11,328 DEBUG [org.jbpm.persistence.db.DbPersistenceService] beginning hibernate transaction 2006-02-23 09:59:11,328 DEBUG [org.jbpm.scheduler.impl.SchedulerThread] checking for timers 2006-02-23 09:59:11,328 DEBUG [org.jbpm.scheduler.impl.SchedulerThread] found timer timer(wait,09:59:28,000) 2006-02-23 09:59:11,406 DEBUG [org.jbpm.JbpmContext] closing JbpmContext 2006-02-23 09:59:11,406 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@10df8c7 2006-02-23 09:59:11,406 DEBUG [org.jbpm.persistence.db.DbPersistenceService] committing hibernate transaction 2006-02-23 09:59:11,406 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session
And here's the execution of the timer:
2006-02-23 09:59:28,000 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, scheduler, logging, persistence, authentication]' 2006-02-23 09:59:28,000 DEBUG [org.jbpm.JbpmContext] creating JbpmContext 2006-02-23 09:59:28,000 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service 2006-02-23 09:59:28,000 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session 2006-02-23 09:59:28,000 DEBUG [org.jbpm.persistence.db.DbPersistenceService] beginning hibernate transaction 2006-02-23 09:59:28,000 DEBUG [org.jbpm.scheduler.impl.SchedulerThread] checking for timers 2006-02-23 09:59:28,000 DEBUG [org.jbpm.scheduler.impl.SchedulerThread] found timer timer(wait,09:59:28,000) 2006-02-23 09:59:28,000 DEBUG [org.jbpm.scheduler.impl.SchedulerThread] executing timer 'timer(wait,09:59:28,000)' 2006-02-23 09:59:28,015 DEBUG [org.jbpm.graph.def.GraphElement] event 'before-signal' on 'State(wait)' for 'Token(/)' 2006-02-23 09:59:28,015 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-leave' on 'State(wait)' for 'Token(/)' 2006-02-23 09:59:28,109 DEBUG [org.jbpm.graph.def.GraphElement] executing action 'CancelTimerAction(8d2e37)' 2006-02-23 09:59:28,109 DEBUG [org.jbpm.graph.def.GraphElement] event 'transition' on 'Transition(continue)' for 'Token(/)' 2006-02-23 09:59:28,109 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-enter' on 'TaskNode(mytask)' for 'Token(/)' 2006-02-23 09:59:28,109 WARN [org.hibernate.engine.StatefulPersistenceContext] Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks == 2006-02-23 09:59:28,109 DEBUG [org.jbpm.graph.def.GraphElement] event 'task-create' on 'Task(myTask)' for 'Token(/)' 2006-02-23 09:59:28,203 DEBUG [org.jbpm.graph.def.GraphElement] event 'task-assign' on 'Task(myTask)' for 'Token(/)' 2006-02-23 09:59:28,203 DEBUG [org.jbpm.graph.def.GraphElement] event 'after-signal' on 'State(wait)' for 'Token(/)' 2006-02-23 09:59:28,203 DEBUG [org.jbpm.svc.Services] executing default save operations 2006-02-23 09:59:28,203 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance 2006-02-23 09:59:28,203 DEBUG [org.jbpm.svc.save.SaveLogsOperation] flushing logs to logging service. 2006-02-23 09:59:28,203 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance@ffce21' 2006-02-23 09:59:28,234 DEBUG [org.jbpm.scheduler.impl.SchedulerThread] deleting timer 'timer(wait,09:59:28,000)' 2006-02-23 09:59:28,234 DEBUG [org.jbpm.JbpmContext] closing JbpmContext 2006-02-23 09:59:28,234 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@1246bec 2006-02-23 09:59:28,234 DEBUG [org.jbpm.persistence.db.DbPersistenceService] committing hibernate transaction 2006-02-23 09:59:28,296 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session 2006-02-23 09:59:28,296 DEBUG [org.jbpm.svc.Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService@1acc826 2006-02-23 09:59:28,296 DEBUG [org.jbpm.svc.Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@8843f5
It fires the task-assign event, it just doesn't call my custom code. Any ideas what's going on here, or any workaround? This is a critical part of my application, and all help is appreciated.
Thanks in advance,
Ian