8 Replies Latest reply on Jun 14, 2007 5:33 AM by kukeltje

    [JBPM 3.2] Timer-Repeat does not work

    syngolis

      Hello,

      i am working with jbpm 3.2 from CVS in an enterprise environment (JBoss 4.0.5.GA). I use the jbpm-enterprise.jar for ejb communication.

      Everything works fine, except the repeat-functionality of the timers. I use the following simple process:

      <process-definition
       xmlns="" name="test">
       <swimlane name="initiator"></swimlane>
       <start-state name="start">
       <task name="task" swimlane="initiator"></task>
       <transition name="" to="sometask"></transition>
       </start-state>
       <end-state name="end1"></end-state>
       <task-node name="sometask">
       <timer name="reminder" duedate="30 seconds" repeat="10 seconds" >
       <action class='MessageActionHandler' />
       </timer>
       <task name="task1" swimlane="initiator"></task>
       <transition name="" to="end1"></transition>
       </task-node>
      </process-definition>


      After execution of the task-node, a job for the timer is created and it becomes executed at the duedate. The job keeps staying in db but there is no further timer execution (repeat after 10 sec).
      With jbpm 3.1.4 (no ejb) i got no such problems

      jbpm.cfg.xml:
      <service name="scheduler" factory="org.jbpm.scheduler.ejbtimer.EjbSchedulerServiceFactory" />


      The following excerpt is from jboss logs (hibernate messages ignored):

      2007-06-12 12:33:04,593 DEBUG [org.jboss.ejb.txtimer.TimerImpl] run: [id=1,target=[target=jboss.j2ee:jndiName=local/TimerServiceBean@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@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@1d3c9ab
      2007-06-12 12:33:04,640 DEBUG [org.jbpm.ejb.impl.CommandServiceBean] executing org.jbpm.scheduler.ejbtimer.ExecuteTimerCommand@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.jbpm.scheduler.ejbtimer.ExecuteTimerCommand] executing timer 38
      
      [...]
      
      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,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@131b732
      2007-06-12 12:33:04,703 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService@f250f3
      
      [...]
      
      2007-06-12 12:33:04,812 DEBUG [org.jboss.ejb.txtimer.TimerImpl] commit: [id=1,target=[target=jboss.j2ee:jndiName=local/TimerServiceBean@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:
      


      Is it correct, that the timer becomes expired (setTimerState: expired)?

      Does anyone has an idea, why my timers are not repeated?

      Many thanks in advance for your help!

        • 1. Re: [JBPM 3.2] Timer-Repeat does not work
          mputz
          • 2. Re: [JBPM 3.2] Timer-Repeat does not work
            kukeltje

            What happens (analyzing the code according to the debug) is that the timer is executed as an ejbtimer, but a normal timer is recreated.... strange...

            Can you post the [....] part between ,703 and ,812 and some lines after that as well.

            • 3. Re: [JBPM 3.2] Timer-Repeat does not work
              syngolis

              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@1a9b92e
              2007-06-12 12:33:01,093 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService@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@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@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@1d3c9ab
              2007-06-12 12:33:04,640 DEBUG [org.jbpm.ejb.impl.CommandServiceBean] executing org.jbpm.scheduler.ejbtimer.ExecuteTimerCommand@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@131b732
              2007-06-12 12:33:04,703 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService@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@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@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@1aa824c
              2007-06-12 12:33:06,250 DEBUG [org.jbpm.ejb.impl.CommandServiceBean] executing de.isogmbh.isoworkflow.core.commands.GetActorTaskInstancesCommand@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)


              • 4. Re: [JBPM 3.2] Timer-Repeat does not work
                syngolis

                Got it! After I checked out the new CVS-Sources the error disappeared.

                I think this point goes to mputz. Thank you for the hint.

                • 5. Re: [JBPM 3.2] Timer-Repeat does not work
                  mputz

                  Hey, good to hear it works for you - and that JIRA fixes actually solve the issues they address ;-)

                  Have fun!

                  • 6. Re: [JBPM 3.2] Timer-Repeat does not work
                    kukeltje

                    syngolis,

                    Can you send me a debug log of a working example. I want to compare that to my analysis of the code. Where I suspect that a default timer is 'recreated' and not an ejbtimer.

                    Ronald

                    • 7. Re: [JBPM 3.2] Timer-Repeat does not work
                      syngolis

                      i tried to send it to your jbpm.org mail adress. i hope you got it.

                      • 8. Re: [JBPM 3.2] Timer-Repeat does not work
                        kukeltje

                        Yep, but without attachment, read my reply in your mail