[jboss-user] [JBoss jBPM] - Re: [JBPM 3.2] Timer-Repeat does not work
syngolis
do-not-reply at jboss.com
Tue Jun 12 09:45:48 EDT 2007
Thanks for your reply.
@mputz: I already saw this issue and I thought it does not affect me. Its about the repeat functionality to accept "yes" or "no" as value. But I am not sure if my last CVS update wasn't before this fix-date an maybe it affects my problem, so I will do this at once.
Here comes the complete log:
2007-06-12 12:33:01,093 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:01,093 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:01,093 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:01,093 DEBUG [org.jbpm.JbpmContext] closing JbpmContext
| 2007-06-12 12:33:01,093 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService at 1a9b92e
| 2007-06-12 12:33:01,093 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService at 1bcac12
| 2007-06-12 12:33:01,093 DEBUG [org.jboss.ejb.StatelessSessionContainer] Useless invocation of remove() for stateless session bean
| 2007-06-12 12:33:01,093 DEBUG [org.jboss.ejb.StatelessSessionContainer] Useless invocation of remove() for stateless session bean
| 2007-06-12 12:33:04,593 DEBUG [org.jboss.ejb.txtimer.TimerImpl] run: [id=1,target=[target=jboss.j2ee:jndiName=local/TimerServiceBean at 22519108,service=EJB],remaining=0,periode=0,active]
| 2007-06-12 12:33:04,593 DEBUG [org.jboss.ejb.txtimer.TimerImpl] setTimerState: in_timeout
| 2007-06-12 12:33:04,625 DEBUG [org.jbpm.scheduler.ejbtimer.TimerServiceBean] ejb timer [id=1,target=[target=jboss.j2ee:jndiName=local/TimerServiceBean at 22519108,service=EJB],remaining=-32,periode=0,in_timeout] fires
| 2007-06-12 12:33:04,640 DEBUG [org.jbpm.ejb.impl.CommandServiceBean] handing over the command execution to the command service
| 2007-06-12 12:33:04,640 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]'
| 2007-06-12 12:33:04,640 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at 1d3c9ab
| 2007-06-12 12:33:04,640 DEBUG [org.jbpm.ejb.impl.CommandServiceBean] executing org.jbpm.scheduler.ejbtimer.ExecuteTimerCommand at 15d1f6a
| 2007-06-12 12:33:04,640 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4840015399485440
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.job.Job#38]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.SQL] select job0_.ID_ as ID1_147_0_, job0_.VERSION_ as VERSION3_147_0_, job0_.DUEDATE_ as DUEDATE4_147_0_, job0_.PROCESSINSTANCE_ as PROCESSI5_147_0_, job0_.TOKEN_ as TOKEN6_147_0_, job0_.TASKINSTANCE_ as TASKINST7_147_0_, job0_.ISSUSPENDED_ as ISSUSPEN8_147_0_, job0_.ISEXCLUSIVE_ as ISEXCLUS9_147_0_, job0_.LOCKOWNER_ as LOCKOWNER10_147_0_, job0_.LOCKTIME_ as LOCKTIME11_147_0_, job0_.EXCEPTION_ as EXCEPTION12_147_0_, job0_.RETRIES_ as RETRIES13_147_0_, job0_.NAME_ as NAME14_147_0_, job0_.REPEAT_ as REPEAT15_147_0_, job0_.TRANSITIONNAME_ as TRANSIT16_147_0_, job0_.ACTION_ as ACTION17_147_0_, job0_.GRAPHELEMENTTYPE_ as GRAPHEL18_147_0_, job0_.GRAPHELEMENT_ as GRAPHEL19_147_0_, job0_.NODE_ as NODE20_147_0_, job0_.CLASS_ as CLASS2_147_0_ from JBPM_JOB job0_ where job0_.ID_=?
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.job.Job#38]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.job.Timer#38]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.job.Timer#38]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.loader.Loader] done entity load
| 2007-06-12 12:33:04,640 DEBUG [org.jbpm.scheduler.ejbtimer.ExecuteTimerCommand] executing timer 38
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.node.TaskNode#554]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.Node#554
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.Node.events#554
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.Event#99
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.Event#98
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.exe.Token#176]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.graph.exe.Token#176]
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:04,640 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.SQL] select token0_.ID_ as ID1_142_0_, token0_.VERSION_ as VERSION2_142_0_, token0_.NAME_ as NAME3_142_0_, token0_.START_ as START4_142_0_, token0_.END_ as END5_142_0_, token0_.NODEENTER_ as NODEENTER6_142_0_, token0_.NEXTLOGINDEX_ as NEXTLOGI7_142_0_, token0_.ISABLETOREACTIVATEPARENT_ as ISABLETO8_142_0_, token0_.ISTERMINATIONIMPLICIT_ as ISTERMIN9_142_0_, token0_.ISSUSPENDED_ as ISSUSPE10_142_0_, token0_.LOCK_ as LOCK11_142_0_, token0_.NODE_ as NODE12_142_0_, token0_.PROCESSINSTANCE_ as PROCESS13_142_0_, token0_.PARENT_ as PARENT14_142_0_, token0_.SUBPROCESSINSTANCE_ as SUBPROC15_142_0_ from JBPM_TOKEN token0_ where token0_.ID_=?
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.graph.exe.Token#176]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.graph.exe.Token#176]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.graph.exe.Token#176]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] done entity load
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.exe.ProcessInstance#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.graph.exe.ProcessInstance#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.SQL] select processins0_.ID_ as ID1_141_0_, processins0_.VERSION_ as VERSION2_141_0_, processins0_.KEY_ as KEY3_141_0_, processins0_.START_ as START4_141_0_, processins0_.END_ as END5_141_0_, processins0_.ISSUSPENDED_ as ISSUSPEN6_141_0_, processins0_.PROCESSDEFINITION_ as PROCESSD7_141_0_, processins0_.ROOTTOKEN_ as ROOTTOKEN8_141_0_, processins0_.SUPERPROCESSTOKEN_ as SUPERPRO9_141_0_ from JBPM_PROCESSINSTANCE processins0_ where processins0_.ID_=?
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.graph.exe.ProcessInstance#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.graph.exe.ProcessInstance#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.graph.exe.ProcessInstance#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] done entity load
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] loading collection: [org.jbpm.graph.exe.ProcessInstance.runtimeActions#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.SQL] select runtimeact0_.PROCESSINSTANCE_ as PROCESSI6_1_, runtimeact0_.ID_ as ID1_1_, runtimeact0_.PROCESSINSTANCEINDEX_ as PROCESSI8_1_, runtimeact0_.ID_ as ID1_143_0_, runtimeact0_.VERSION_ as VERSION2_143_0_, runtimeact0_.EVENTTYPE_ as EVENTTYPE3_143_0_, runtimeact0_.TYPE_ as TYPE4_143_0_, runtimeact0_.GRAPHELEMENT_ as GRAPHELE5_143_0_, runtimeact0_.PROCESSINSTANCE_ as PROCESSI6_143_0_, runtimeact0_.ACTION_ as ACTION7_143_0_ from JBPM_RUNTIMEACTION runtimeact0_ where runtimeact0_.PROCESSINSTANCE_=?
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [org.jbpm.graph.exe.ProcessInstance.runtimeActions#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.CollectionLoadContext] 1 collections were found in result set for role: org.jbpm.graph.exe.ProcessInstance.runtimeActions
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.CollectionLoadContext] collection fully initialized: [org.jbpm.graph.exe.ProcessInstance.runtimeActions#109]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.CollectionLoadContext] 1 collections initialized for role: org.jbpm.graph.exe.ProcessInstance.runtimeActions
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] done loading collection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.def.ProcessDefinition#108]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.ProcessDefinition#108
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.ProcessDefinition.events#108
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
| 2007-06-12 12:33:04,656 DEBUG [org.jbpm.job.Timer] executing timer 'timer(reminder,12:33:04,000)'
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.def.Action#206]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.Action#206
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache miss
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.graph.def.Action#206]
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.SQL] select action0_.ID_ as ID1_129_0_, action0_.NAME_ as NAME3_129_0_, action0_.ISPROPAGATIONALLOWED_ as ISPROPAG4_129_0_, action0_.ACTIONEXPRESSION_ as ACTIONEX5_129_0_, action0_.ISASYNC_ as ISASYNC6_129_0_, action0_.REFERENCEDACTION_ as REFERENC7_129_0_, action0_.ACTIONDELEGATION_ as ACTIONDE8_129_0_, action0_.EVENT_ as EVENT9_129_0_, action0_.PROCESSDEFINITION_ as PROCESS10_129_0_, action0_.TIMERNAME_ as TIMERNAME11_129_0_, action0_.DUEDATE_ as DUEDATE12_129_0_, action0_.REPEAT_ as REPEAT13_129_0_, action0_.TRANSITIONNAME_ as TRANSIT14_129_0_, action0_.TIMERACTION_ as TIMERAC15_129_0_, action0_.EXPRESSION_ as EXPRESSION16_129_0_, action0_.class as class129_0_ from JBPM_ACTION action0_ where action0_.ID_=?
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:04,656 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.graph.def.Action#206]
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.graph.def.Action#206]
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [org.jbpm.graph.def.Action#206]
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Caching: org.jbpm.graph.def.Action#206
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.graph.def.Action#206]
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.loader.Loader] done entity load
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.instantiation.Delegation#166]
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.instantiation.Delegation#166
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache miss
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.instantiation.Delegation#166]
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:04,671 DEBUG [org.hibernate.SQL] select delegation0_.ID_ as ID1_131_0_, delegation0_.CLASSNAME_ as CLASSNAME2_131_0_, delegation0_.CONFIGURATION_ as CONFIGUR3_131_0_, delegation0_.CONFIGTYPE_ as CONFIGTYPE4_131_0_, delegation0_.PROCESSDEFINITION_ as PROCESSD5_131_0_ from JBPM_DELEGATION delegation0_ where delegation0_.ID_=?
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.instantiation.Delegation#166]
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.instantiation.Delegation#166]
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [org.jbpm.instantiation.Delegation#166]
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Caching: org.jbpm.instantiation.Delegation#166
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.instantiation.Delegation#166]
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:04,687 DEBUG [org.hibernate.loader.Loader] done entity load
| 2007-06-12 12:33:04,703 INFO [STDOUT] Timer executed
| 2007-06-12 12:33:04,703 DEBUG [org.jbpm.job.Timer] updated timer for repetition 'timer(reminder,12:33:14,000)' in '9297' millis
| 2007-06-12 12:33:04,703 DEBUG [org.jbpm.JbpmContext] closing JbpmContext
| 2007-06-12 12:33:04,703 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService at 131b732
| 2007-06-12 12:33:04,703 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService at f250f3
| 2007-06-12 12:33:04,703 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.events#554], was: [org.jbpm.graph.def.Node.events#554] (initialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.exceptionHandlers#554], was: [org.jbpm.graph.def.Node.exceptionHandlers#554] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.leavingTransitions#554], was: [org.jbpm.graph.def.Node.leavingTransitions#554] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.arrivingTransitions#554], was: [org.jbpm.graph.def.Node.arrivingTransitions#554] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.node.TaskNode.tasks#554], was: [org.jbpm.graph.node.TaskNode.tasks#554] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Event.actions#99], was: [org.jbpm.graph.def.Event.actions#99] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Event.actions#98], was: [org.jbpm.graph.def.Event.actions#98] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.exe.Token.children#176], was: [org.jbpm.graph.exe.Token.children#176] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.exe.Token.comments#176], was: [org.jbpm.graph.exe.Token.comments#176] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.exe.ProcessInstance.runtimeActions#109], was: [org.jbpm.graph.exe.ProcessInstance.runtimeActions#109] (initialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.exe.ProcessInstance.instances#109], was: [org.jbpm.graph.exe.ProcessInstance.instances#109] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.events#108], was: [org.jbpm.graph.def.ProcessDefinition.events#108] (initialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#108], was: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#108] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.nodes#108], was: [org.jbpm.graph.def.ProcessDefinition.nodes#108] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.actions#108], was: [org.jbpm.graph.def.ProcessDefinition.actions#108] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.definitions#108], was: [org.jbpm.graph.def.ProcessDefinition.definitions#108] (uninitialized)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 1 updates, 0 deletions to 9 objects
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 16 collections
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] listing entities:
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.def.ProcessDefinition{startState=org.jbpm.graph.def.Node#552, events=[], definitions=<uninitialized>, actions=<uninitialized>, description=null, nodes=<uninitialized>, exceptionHandlers=<uninitialized>, isTerminationImplicit=false, name=test, id=108, version=10}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.exe.ProcessInstance{key=null, start=2007-06-12 12:32:28, instances=<uninitialized>, runtimeActions=[], isSuspended=false, end=null, superProcessToken=null, rootToken=org.jbpm.graph.exe.Token#176, id=109, processDefinition=org.jbpm.graph.def.ProcessDefinition#108, version=1}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.node.TaskNode{signal=4, events=[org.jbpm.graph.def.Event#98, org.jbpm.graph.def.Event#99], action=null, leavingTransitions=<uninitialized>, isAsyncExclusive=false, superState=null, tasks=<uninitialized>, createTasks=true, id=554, processDefinition=org.jbpm.graph.def.ProcessDefinition#108, isAsync=false, endTasks=false, description=null, exceptionHandlers=<uninitialized>, name=sometask, arrivingTransitions=<uninitialized>}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.def.Event{actions=<uninitialized>, graphElement=org.jbpm.graph.node.TaskNode#554, eventType=node-enter, id=99}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.def.Action{isPropagationAllowed=true, actionExpression=null, event=null, actionDelegation=org.jbpm.instantiation.Delegation#166, referencedAction=null, name=null, id=206, processDefinition=null, isAsync=false}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.job.Timer{processInstance=org.jbpm.graph.exe.ProcessInstance#109, action=org.jbpm.graph.def.Action#206, repeat=10 seconds, isSuspended=false, isExclusive=false, lockOwner=null, lockTime=null, dueDate=2007-06-12 12:33:14, graphElement=org.jbpm.graph.node.TaskNode#554, token=org.jbpm.graph.exe.Token#176, id=38, version=0, taskInstance=null, exception=null, retries=1, transitionName=null, name=reminder}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.exe.Token{comments=<uninitialized>, processInstance=org.jbpm.graph.exe.ProcessInstance#109, subProcessInstance=null, start=2007-06-12 12:32:28, isSuspended=false, end=null, node=org.jbpm.graph.def.Node#554, id=176, version=2, nextLogIndex=9, lock=null, name=null, isTerminationImplicit=false, children=<uninitialized>, parent=null, isAbleToReactivateParent=true, nodeEnter=2007-06-12 12:32:34}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.def.Event{actions=<uninitialized>, graphElement=org.jbpm.graph.node.TaskNode#554, eventType=node-leave, id=98}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.pretty.Printer] org.jbpm.instantiation.Delegation{configType=null, configuration=null, className=de.isogmbh.isoworkflow.action.MessageActionHandler, id=166, processDefinition=org.jbpm.graph.def.ProcessDefinition#108}
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:04,765 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:04,781 DEBUG [org.hibernate.SQL] update JBPM_JOB set VERSION_=?, DUEDATE_=?, PROCESSINSTANCE_=?, TOKEN_=?, TASKINSTANCE_=?, ISSUSPENDED_=?, ISEXCLUSIVE_=?, LOCKOWNER_=?, LOCKTIME_=?, EXCEPTION_=?, RETRIES_=?, NAME_=?, REPEAT_=?, TRANSITIONNAME_=?, ACTION_=?, GRAPHELEMENTTYPE_=?, GRAPHELEMENT_=? where ID_=? and VERSION_=?
| 2007-06-12 12:33:04,781 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:04,781 DEBUG [org.hibernate.jdbc.ConnectionManager] skipping aggressive-release due to flush cycle
| 2007-06-12 12:33:04,781 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:04,781 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:04,812 DEBUG [org.jboss.ejb.txtimer.TimerImpl] commit: [id=1,target=[target=jboss.j2ee:jndiName=local/TimerServiceBean at 22519108,service=EJB],remaining=-219,periode=0,in_timeout]
| 2007-06-12 12:33:04,812 DEBUG [org.jboss.ejb.txtimer.TimerImpl] setTimerState: expired
| 2007-06-12 12:33:04,812 DEBUG [org.jboss.ejb.txtimer.TimerImpl] killTimer: [id=1,target=[target=jboss.j2ee:jndiName=local/TimerServiceBean at 22519108,service=EJB],remaining=-219,periode=0,expired]
| 2007-06-12 12:33:06,250 DEBUG [org.jbpm.ejb.impl.CommandServiceBean] handing over the command execution to the command service
| 2007-06-12 12:33:06,250 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]'
| 2007-06-12 12:33:06,250 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext at 1aa824c
| 2007-06-12 12:33:06,250 DEBUG [org.jbpm.ejb.impl.CommandServiceBean] executing de.isogmbh.isoworkflow.core.commands.GetActorTaskInstancesCommand at 1504e7b
| 2007-06-12 12:33:06,250 DEBUG [org.jbpm.persistence.db.DbPersistenceServiceFactory] creating persistence service
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4840015406080000
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.SQL] select taskinstan0_.ID_ as ID1_148_, taskinstan0_.VERSION_ as VERSION3_148_, taskinstan0_.NAME_ as NAME4_148_, taskinstan0_.DESCRIPTION_ as DESCRIPT5_148_, taskinstan0_.ACTORID_ as ACTORID6_148_, taskinstan0_.CREATE_ as CREATE7_148_, taskinstan0_.START_ as START8_148_, taskinstan0_.END_ as END9_148_, taskinstan0_.DUEDATE_ as DUEDATE10_148_, taskinstan0_.PRIORITY_ as PRIORITY11_148_, taskinstan0_.ISCANCELLED_ as ISCANCE12_148_, taskinstan0_.ISSUSPENDED_ as ISSUSPE13_148_, taskinstan0_.ISOPEN_ as ISOPEN14_148_, taskinstan0_.ISSIGNALLING_ as ISSIGNA15_148_, taskinstan0_.ISBLOCKING_ as ISBLOCKING16_148_, taskinstan0_.TASK_ as TASK17_148_, taskinstan0_.TOKEN_ as TOKEN18_148_, taskinstan0_.PROCINST_ as PROCINST19_148_, taskinstan0_.SWIMLANINSTANCE_ as SWIMLAN20_148_, taskinstan0_.TASKMGMTINSTANCE_ as TASKMGM21_148_ from JBPM_TASKINSTANCE taskinstan0_ where taskinstan0_.ACTORID_=? and taskinstan0_.ISSUSPENDED_<>1 and taskinstan0_.ISOPEN_=1
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.loader.hql.QueryLoader] bindNamedParameters() ernie -> actorId [1]
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.taskmgmt.exe.TaskInstance#229]
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.taskmgmt.exe.TaskInstance#231]
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 2007-06-12 12:33:06,250 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.taskmgmt.exe.TaskInstance#229]
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.taskmgmt.exe.TaskInstance#229]
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.taskmgmt.exe.TaskInstance#231]
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.taskmgmt.exe.TaskInstance#231]
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.taskmgmt.exe.TaskMgmtInstance#215]
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.taskmgmt.exe.TaskMgmtInstance#215]
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.SQL] select taskmgmtin0_.ID_ as ID1_144_0_, taskmgmtin0_.VERSION_ as VERSION3_144_0_, taskmgmtin0_.PROCESSINSTANCE_ as PROCESSI4_144_0_, taskmgmtin0_.TASKMGMTDEFINITION_ as TASKMGMT5_144_0_ from JBPM_MODULEINSTANCE taskmgmtin0_ where taskmgmtin0_.ID_=? and taskmgmtin0_.CLASS_='T'
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.taskmgmt.exe.TaskMgmtInstance#215]
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
| 2007-06-12 12:33:06,265 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4053554#4053554
Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4053554
More information about the jboss-user
mailing list