[jboss-user] [JBoss Seam] - jbpm timer transaction issues

pbrewer_uk do-not-reply at jboss.com
Tue Nov 13 09:53:23 EST 2007


I'm using Seam 2.0.0.GA with jbpm 3.2.1.GA and have a simple timer process that simple creates a task and if it is not completed by a user within 1 minute a timer fires and progresses the workflow automatically, writing out messages to the logs as it goes:


  | <?xml version="1.0" encoding="UTF-8"?>
  | <process-definition xmlns="urn:jbpm.org:jpdl-3.1"
  |                     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
  |                     xsi:schemaLocation="urn:jbpm.org:jpdl-3.1 http://jbpm.org/jpdl-3.1.xsd"
  |                     name="timerTest">
  | 
  |    <start-state name="start">
  |       <transition name="" to="timerTest" />
  |    </start-state>
  | 
  |    <task-node name="timerTest">
  |       <event type="node-enter">
  |         <action expression="#{timerTestWorkflow.logNodeEnter}" />
  |       </event>
  |       <event type="node-leave">
  |         <action expression="#{timerTestWorkflow.logNodeLeave}" />
  |       </event>
  |       <task name="timerTestTask" description="TimerTestTask">
  |         <assignment actor-id="admin" />
  |         <event type="task-create">
  |           <action expression="#{timerTestWorkflow.logTaskCreate}" />
  |         </event>
  |         <event type="timer-create">
  |           <action expression="#{timerTestWorkflow.logTimerCreate}" />
  |         </event>
  |         <timer duedate="1 minute" transition="finished">
  |           <action expression="#{timerTestWorkflow.logTimerFired}" />
  |         </timer>
  |       </task>
  |       <transition name="finished" to="end" />
  |    </task-node>
  | 
  |    <end-state name="end"></end-state>
  | </process-definition>
  | 

However, when the timer fires I get the following exception, and the workflow doesn't complete.


  | 2007-11-13 14:34:44,863 DEBUG [org.jbpm.job.executor.JobExecutorThread] acquiring jobs for execution...
  | 2007-11-13 14:34:44,863 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
  | 2007-11-13 14:34:44,863 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at 346072
  | 2007-11-13 14:34:44,863 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service
  | 2007-11-13 14:34:44,863 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session
  | 2007-11-13 14:34:44,863 DEBUG [org.jbpm.job.executor.JobExecutorThread] querying for acquirable job...
  | 2007-11-13 14:34:44,863 DEBUG [org.jbpm.job.executor.JobExecutorThread] trying to obtain a lock for 'timer(timerTestTask,07-11-13 14:34:42,667,TaskInstance: 9,Token: 15)'
  | 2007-11-13 14:34:44,878 WARN  [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks ==
  | 2007-11-13 14:34:44,878 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.taskmgmt.def.Task.exceptionHandlers#1619]
  | 2007-11-13 14:34:44,878 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,878 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized from cache
  | 2007-11-13 14:34:44,878 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext at 346072
  | 2007-11-13 14:34:44,878 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService at 1457b0f
  | 2007-11-13 14:34:44,878 DEBUG [org.jbpm.persistence.db.DbPersistenceService] flushing hibernate session SessionImpl(PersistenceContext[entityKeys=[EntityKey[org.jbpm.job.Job#9], EntityKey[org.jbpm.graph.exe.Token#15], EntityKey[org.jbpm.taskmgmt.exe.TaskInstance#9], EntityKey[org.jbpm.taskmgmt.def.Task#1619]],collectionKeys=[CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.variableInstances#9], CollectionKey[org.jbpm.taskmgmt.def.Task.events#1619], CollectionKey[org.jbpm.graph.exe.Token.children#15], CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.comments#9], CollectionKey[org.jbpm.taskmgmt.def.Task.exceptionHandlers#1619], CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.pooledActors#9], CollectionKey[org.jbpm.graph.exe.Token.comments#15]]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]])
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService at 2a3502
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.job.executor.JobExecutorThread] obtained locks on following jobs: [timer(timerTestTask,07-11-13 14:34:42,667,TaskInstance: 9,Token: 15)]
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at fe331c
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session
  | 2007-11-13 14:34:44,894 DEBUG [org.jbpm.job.executor.JobExecutorThread] executing job timer(timerTestTask,07-11-13 14:34:42,667,TaskInstance: 9,Token: 15)
  | 2007-11-13 14:34:44,894 WARN  [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] Narrowing proxy to class org.jbpm.graph.node.TaskNode - this operation breaks ==
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.taskmgmt.def.Task.exceptionHandlers#1619]
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized from cache
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.taskmgmt.def.Task.events#1619]
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized from cache
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.exe.ProcessInstance.runtimeActions#15]
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,894 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Node.exceptionHandlers#7373]
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized from cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Node.events#7373]
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized from cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#567]
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized from cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.ProcessDefinition.events#567]
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized from cache
  | 2007-11-13 14:34:44,910 DEBUG [org.jbpm.job.Timer] executing timer 'timer(timerTestTask,07-11-13 14:34:42,667,TaskInstance: 9,Token: 15)'
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.exe.ProcessInstance.instances#15]
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,910 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,910 DEBUG [org.jbpm.graph.def.GraphElement] executing action 'action[#{timerTestWorkflow.logTimerFired}]'
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at 17084b8
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at 19666a
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext at 19666a
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session
  | 2007-11-13 14:34:44,925 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.taskmgmt.exe.TaskInstance.variableInstances#9]
  | 2007-11-13 14:34:44,925 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,925 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,925 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.exe.ProcessInstance.instances#15]
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.context.exe.ContextInstance.tokenVariableMaps#29]
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.context.exe.TokenVariableMap.variableInstances#13]
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,941 INFO  [uk.co.iblocks.midas.workflow.TimerTestWorkflow] logTimerFired
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext at 17084b8
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.Services] executing default save operations
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.save.SaveLogsOperation] flushing logs to logging service.
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance at 565388'
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.Services] executing default save operations
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.save.SaveLogsOperation] flushing logs to logging service.
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance at 565388'
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService at 1f3ca88
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.persistence.db.DbPersistenceService] flushing hibernate session SessionImpl(PersistenceContext[entityKeys=[EntityKey[org.jbpm.graph.exe.Token#15], EntityKey[org.jbpm.taskmgmt.exe.TaskInstance#9], EntityKey[org.jbpm.context.exe.TokenVariableMap#13], EntityKey[org.jbpm.graph.exe.ProcessInstance#15], EntityKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance#30], EntityKey[org.jbpm.module.exe.ModuleInstance#29]],collectionKeys=[CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.variableInstances#9], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#30], CollectionKey[org.jbpm.graph.exe.ProcessInstance.runtimeActions#15], CollectionKey[org.jbpm.graph.exe.Token.children#15], CollectionKey[org.jbpm.context.exe.ContextInstance.tokenVariableMaps#29], CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.comments#9], CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.pooledActors#9], CollectionKey[org.jbpm.graph.exe.Token.comments#15], CollectionKey[org.jbpm.graph.exe.ProcessInstance.instances#15], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances#30], CollectionKey[org.jbpm.context.exe.TokenVariableMap.variableInstances#13]]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]])
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService at b1221b
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService at 1362c68
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Node.leavingTransitions#7373]
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,941 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Transition.exceptionHandlers#9566]
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,956 DEBUG [org.jbpm.graph.def.GraphElement] event 'before-signal' on 'TaskNode(timerTest)' for 'Token(/)'
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#30]
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,956 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,972 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-leave' on 'TaskNode(timerTest)' for 'Token(/)'
  | 2007-11-13 14:34:44,972 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Event.actions#1272]
  | 2007-11-13 14:34:44,972 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:44,972 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:44,972 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:44,972 DEBUG [org.jbpm.graph.def.GraphElement] executing action 'action[#{timerTestWorkflow.logNodeLeave}]'
  | 2007-11-13 14:34:44,972 DEBUG [org.jbpm.graph.exe.Token] token[15] is locked by token[15]
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at 655c61
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at 93efc3
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext at 93efc3
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.persistence.db.DbPersistenceService] creating hibernate session
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.exe.ProcessInstance.instances#15]
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.context.exe.ContextInstance.tokenVariableMaps#29]
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.context.exe.TokenVariableMap.variableInstances#13]
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:45,003 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:45,003 INFO  [uk.co.iblocks.midas.workflow.TimerTestWorkflow] logNodeLeave
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext at 655c61
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.Services] executing default save operations
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.save.SaveLogsOperation] flushing logs to logging service.
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance at 101cc3e'
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.Services] executing default save operations
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.save.SaveLogsOperation] flushing logs to logging service.
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance at 101cc3e'
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService at 4c61c2
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.persistence.db.DbPersistenceService] flushing hibernate session SessionImpl(PersistenceContext[entityKeys=[EntityKey[org.jbpm.graph.exe.Token#15], EntityKey[org.jbpm.context.exe.TokenVariableMap#13], EntityKey[org.jbpm.graph.exe.ProcessInstance#15], EntityKey[org.jbpm.module.exe.ModuleInstance#30], EntityKey[org.jbpm.module.exe.ModuleInstance#29]],collectionKeys=[CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#30], CollectionKey[org.jbpm.graph.exe.ProcessInstance.runtimeActions#15], CollectionKey[org.jbpm.graph.exe.Token.children#15], CollectionKey[org.jbpm.context.exe.ContextInstance.tokenVariableMaps#29], CollectionKey[org.jbpm.graph.exe.Token.comments#15], CollectionKey[org.jbpm.graph.exe.ProcessInstance.instances#15], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances#30], CollectionKey[org.jbpm.context.exe.TokenVariableMap.variableInstances#13]]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]])
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService at 1e5484b
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService at 1ed55b9
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.graph.exe.Token] token[15] is unlocked by token[15]
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.graph.def.GraphElement] event 'transition' on 'Transition(finished)' for 'Token(/)'
  | 2007-11-13 14:34:45,019 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Transition.events#9566]
  | 2007-11-13 14:34:45,019 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:45,019 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Node.exceptionHandlers#7374]
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:45,034 DEBUG [org.jbpm.graph.def.GraphElement] event 'node-enter' on 'EndState(end)' for 'Token(/)'
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.def.Node.events#7374]
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [org.jbpm.graph.exe.Token.children#15]
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
  | 2007-11-13 14:34:45,034 TRACE [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
  | 2007-11-13 14:34:45,034 DEBUG [org.jbpm.graph.def.GraphElement] event 'process-end' on 'ProcessDefinition(timerTest)' for 'Token(/)'
  | 2007-11-13 14:34:45,034 ERROR [org.jbpm.db.JobSession] org.hibernate.TransactionException: could not register synchronization
  | 2007-11-13 14:34:45,034 DEBUG [org.jbpm.job.executor.JobExecutorThread] exception while executing 'timer(timerTestTask,07-11-13 14:34:42,667,TaskInstance: 9,Token: 15)'
  | org.jbpm.JbpmException: couldn't delete jobs for 'org.jbpm.graph.exe.ProcessInstance at d208f1'
  | 	at org.jbpm.db.JobSession.deleteJobsForProcessInstance(JobSession.java:211)
  | 	at org.jbpm.scheduler.db.DbSchedulerService.deleteTimersByProcessInstance(DbSchedulerService.java:54)
  | 	at org.jbpm.graph.exe.ProcessInstance.end(ProcessInstance.java:330)
  | 	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.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:173)
  | 	at org.jbpm.graph.exe.ProcessInstance_$$_javassist_174.end(ProcessInstance_$$_javassist_174.java)
  | 	at org.jbpm.graph.exe.Token.notifyParentOfTokenEnd(Token.java:332)
  | 	at org.jbpm.graph.exe.Token.end(Token.java:304)
  | 	at org.jbpm.graph.exe.Token.end(Token.java:254)
  | 	at org.jbpm.graph.node.EndState.execute(EndState.java:59)
  | 	at org.jbpm.graph.def.Node.enter(Node.java:319)
  | 	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.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:173)
  | 	at org.jbpm.graph.def.Node_$$_javassist_169.enter(Node_$$_javassist_169.java)
  | 	at org.jbpm.graph.def.Transition.take(Transition.java:151)
  | 	at org.jbpm.graph.def.Node.leave(Node.java:394)
  | 	at org.jbpm.graph.node.TaskNode.leave(TaskNode.java:209)
  | 	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.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:173)
  | 	at org.jbpm.graph.def.Node_$$_javassist_169.leave(Node_$$_javassist_169.java)
  | 	at org.jbpm.graph.exe.Token.signal(Token.java:195)
  | 	at org.jbpm.graph.exe.Token.signal(Token.java:158)
  | 	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.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:173)
  | 	at org.jbpm.graph.exe.Token_$$_javassist_105.signal(Token_$$_javassist_105.java)
  | 	at org.jbpm.job.Timer.execute(Timer.java:93)
  | 	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.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:173)
  | 	at org.jbpm.job.Job_$$_javassist_173.execute(Job_$$_javassist_173.java)
  | 	at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:164)
  | 	at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64)
  | Caused by: org.hibernate.TransactionException: could not register synchronization
  | 	at org.hibernate.transaction.JTATransaction.registerSynchronization(JTATransaction.java:309)
  | 	at org.jbpm.db.JobSession.deleteJobsForProcessInstance(JobSession.java:208)
  | 	... 45 more
  | Caused by: java.lang.NullPointerException
  | 	at org.hibernate.transaction.JTATransaction.registerSynchronization(JTATransaction.java:306)
  | 	... 46 more
  | 2007-11-13 14:34:45,050 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext at fe331c
  | 2007-11-13 14:34:45,050 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService at 200022
  | 2007-11-13 14:34:45,050 DEBUG [org.jbpm.persistence.db.DbPersistenceService] flushing hibernate session SessionImpl(PersistenceContext[entityKeys=[EntityKey[org.jbpm.taskmgmt.exe.TaskInstance#9], EntityKey[org.jbpm.graph.def.Action#3053], EntityKey[org.jbpm.graph.exe.Token#15], EntityKey[org.jbpm.graph.def.Event#1272], EntityKey[org.jbpm.graph.def.Action#3054], EntityKey[org.jbpm.graph.def.Event#1271], EntityKey[org.jbpm.graph.def.Event#1274], EntityKey[org.jbpm.taskmgmt.def.Task#1619], EntityKey[org.jbpm.graph.def.Event#1273], EntityKey[org.jbpm.graph.def.ProcessDefinition#567], EntityKey[org.jbpm.graph.def.Event#1275], EntityKey[org.jbpm.graph.node.TaskNode#7373], EntityKey[org.jbpm.graph.def.Node#7374], EntityKey[org.jbpm.graph.def.Transition#9566], EntityKey[org.jbpm.module.exe.ModuleInstance#30], EntityKey[org.jbpm.module.exe.ModuleInstance#29], EntityKey[org.jbpm.job.Job#9], EntityKey[org.jbpm.graph.exe.ProcessInstance#15]],collectionKeys=[CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.variableInstances#9], CollectionKey[org.jbpm.taskmgmt.def.Task.events#1619], CollectionKey[org.jbpm.graph.exe.Token.children#15], CollectionKey[org.jbpm.context.exe.ContextInstance.tokenVariableMaps#29], CollectionKey[org.jbpm.graph.def.Event.actions#1274], CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.comments#9], CollectionKey[org.jbpm.graph.def.Transition.events#9566], CollectionKey[org.jbpm.graph.def.Event.actions#1275], CollectionKey[org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#567], CollectionKey[org.jbpm.graph.def.Event.actions#1272], CollectionKey[org.jbpm.graph.def.ProcessDefinition.nodes#567], CollectionKey[org.jbpm.graph.def.Event.actions#1273], CollectionKey[org.jbpm.graph.def.Node.leavingTransitions#7374], CollectionKey[org.jbpm.graph.def.Node.leavingTransitions#7373], CollectionKey[org.jbpm.graph.def.Event.actions#1271], CollectionKey[org.jbpm.graph.def.ProcessDefinition.events#567], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances#30], CollectionKey[org.jbpm.graph.node.TaskNode.tasks#7373], CollectionKey[org.jbpm.graph.exe.Token.comments#15], CollectionKey[org.jbpm.graph.exe.ProcessInstance.instances#15], CollectionKey[org.jbpm.graph.def.ProcessDefinition.definitions#567], CollectionKey[org.jbpm.graph.exe.ProcessInstance.runtimeActions#15], CollectionKey[org.jbpm.graph.def.Node.events#7373], CollectionKey[org.jbpm.taskmgmt.def.Task.exceptionHandlers#1619], CollectionKey[org.jbpm.taskmgmt.exe.TaskInstance.pooledActors#9], CollectionKey[org.jbpm.graph.def.Node.exceptionHandlers#7374], CollectionKey[org.jbpm.graph.def.Node.events#7374], CollectionKey[org.jbpm.graph.def.Node.exceptionHandlers#7373], CollectionKey[org.jbpm.graph.def.Node.arrivingTransitions#7373], CollectionKey[org.jbpm.graph.def.Node.arrivingTransitions#7374], CollectionKey[org.jbpm.graph.def.ProcessDefinition.actions#567], CollectionKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#30], CollectionKey[org.jbpm.graph.def.Transition.exceptionHandlers#9566]]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]])
  | 2007-11-13 14:34:45,066 DEBUG [org.jbpm.persistence.db.DbPersistenceService] closing hibernate session
  | 2007-11-13 14:34:45,066 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService at 162d2df
  | 2007-11-13 14:34:45,066 DEBUG [org.jbpm.svc.Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService at 1023556
  | 

If anyone has any idea's how to solve or workaround this problem I would be very grateful. If you need any further info (e.g. configuration etc) please do not hesitate to ask.

BTW I've also tried using jBpm 3.2.2 which has the same issue.

Thanks in advance, 
Pete

View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4104152#4104152

Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4104152




More information about the jboss-user mailing list