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

Tuesday, 13 November 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@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@346072
  | 2007-11-13 14:34:44,878 DEBUG [org.jbpm.svc.Services] closing service
'persistence': org.jbpm.persistence.db.DbPersistenceService@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@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@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@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@19666a
  | 2007-11-13 14:34:44,925 DEBUG [org.jbpm.JbpmContext] closing jbpmContext
org.jbpm.JbpmContext@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@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@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@565388'
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.Services] closing service
'persistence': org.jbpm.persistence.db.DbPersistenceService@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@b1221b
  | 2007-11-13 14:34:44,941 DEBUG [org.jbpm.svc.Services] closing service
'logging': org.jbpm.logging.db.DbLoggingService@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@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@93efc3
  | 2007-11-13 14:34:45,003 DEBUG [org.jbpm.JbpmContext] closing jbpmContext
org.jbpm.JbpmContext@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@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@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@101cc3e'
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.Services] closing service
'persistence': org.jbpm.persistence.db.DbPersistenceService@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@1e5484b
  | 2007-11-13 14:34:45,019 DEBUG [org.jbpm.svc.Services] closing service
'logging': org.jbpm.logging.db.DbLoggingService@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@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@fe331c
  | 2007-11-13 14:34:45,050 DEBUG [org.jbpm.svc.Services] closing service
'persistence': org.jbpm.persistence.db.DbPersistenceService@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@162d2df
  | 2007-11-13 14:34:45,066 DEBUG [org.jbpm.svc.Services] closing service
'scheduler': org.jbpm.scheduler.db.DbSchedulerService@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#...

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

2026

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

[JBoss Seam] - jbpm timer transaction issues