4 Replies Latest reply on Jul 15, 2009 3:54 PM by arpan25

    errors with the example websale workflow

    arpan25 Jul 13, 2009 4:39 PM

      HI,

      I am working with JBpm-3.2.6.SP1. I want to know if the websale process should be visible automatically when I install jbpm and login to the jbpm-console ?

      I cannot see it though..I see it only after I import it and deploy it in eclipse ..

      After deploying, when i click evaluate on the Create New Websale order task, i get the following errors :

      Error completing task: An exception of type "org.jbpm.JbpmException" was thrown. The message is: ejb timer entity lookup problem
      Closing the database context failed: An exception of type org.hibernate.exception.DataException was thrown, with the message: could not insert: [org.jbpm.graph.log.ActionLog]

      Can anyone help me with this ?

      • 1443 Views
      • Tags:
        • 1. Re: errors with the example websale workflow
          kukeltje
          kukeltje Jul 13, 2009 10:19 PM (in response to arpan25)

          Depends on what setup you use (e.g. which database)

          Regarding the second error (and in more general) you have to provide more data, *full* stacktraces etc

            • Actions
          • 2. Re: errors with the example websale workflow
            arpan25 Jul 15, 2009 2:33 PM (in response to arpan25)

            Hi,

            I am using MySQL.

            I am getting the following error when i click on Evaluate button for the Create new websale order task.

            Error completing task: An exception of type "org.jbpm.JbpmException" was thrown. The message is: ejb timer entity lookup problem
            Closing the database context failed: An exception of type org.hibernate.exception.DataException was thrown, with the message: could not insert: [org.jbpm.graph.log.ActionLog]

            The server log is as follows

            2009-07-15 14:25:30,075 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
            2009-07-15 14:25:30,078 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext@7d53d8
            2009-07-15 14:25:30,078 DEBUG [org.jbpm.persistence.jta.JtaDbPersistenceService] beginning null
            2009-07-15 14:25:30,079 DEBUG [org.jbpm.persistence.db.DbPersistenceService] using current hibernate session
            2009-07-15 14:25:30,079 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
            2009-07-15 14:25:30,079 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 5110506824003584
            2009-07-15 14:25:30,079 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.ProcessDefinition#10
            2009-07-15 14:25:30,079 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:30,080 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:30,081 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
            2009-07-15 14:25:30,081 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
            2009-07-15 14:25:30,081 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.events#10], was: [org.jbpm.graph.def.ProcessDefinition.events#10] (uninitialized)
            2009-07-15 14:25:30,081 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#10], was: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#10] (uninitialized)
            2009-07-15 14:25:30,081 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.nodes#10], was: [org.jbpm.graph.def.ProcessDefinition.nodes#10] (uninitialized)
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.actions#10], was: [org.jbpm.graph.def.ProcessDefinition.actions#10] (uninitialized)
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.definitions#10], was: [org.jbpm.graph.def.ProcessDefinition.definitions#10] (uninitialized)
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 5 collections
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.pretty.Printer] listing entities:
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.def.ProcessDefinition{id=10, nodes=, events=, description=null, name=websale, isTerminationImplicit=false, startState=org.jbpm.graph.def.Node#54, definitions=, actions=, version=2, exceptionHandlers=}
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:30,082 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:30,083 DEBUG [org.hibernate.SQL]
            /* named HQL query GraphSession.findAllProcessInstancesForDefinition */ select
            processins0_.ID_ as ID1_20_,
            processins0_.VERSION_ as VERSION2_20_,
            processins0_.KEY_ as KEY3_20_,
            processins0_.START_ as START4_20_,
            processins0_.END_ as END5_20_,
            processins0_.ISSUSPENDED_ as ISSUSPEN6_20_,
            processins0_.PROCESSDEFINITION_ as PROCESSD7_20_,
            processins0_.ROOTTOKEN_ as ROOTTOKEN8_20_,
            processins0_.SUPERPROCESSTOKEN_ as SUPERPRO9_20_
            from
            JBPM_PROCESSINSTANCE processins0_
            where
            processins0_.PROCESSDEFINITION_=?
            order by
            processins0_.START_ desc
            2009-07-15 14:25:30,085 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:30,085 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.graph.exe.ProcessInstance#20]
            2009-07-15 14:25:30,087 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:30,087 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:30,087 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:30,087 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:30,087 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.graph.exe.ProcessInstance#20]
            2009-07-15 14:25:30,088 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.graph.exe.ProcessInstance#20]
            2009-07-15 14:25:30,088 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:30,169 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext@7d53d8
            2009-07-15 14:25:30,170 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.jta.JtaDbPersistenceService@99e8f8
            2009-07-15 14:25:30,170 DEBUG [org.jbpm.persistence.jta.JtaDbPersistenceService] committing org.jboss.tm.usertx.client.ServerVMClientUserTransaction@1ef0b44
            2009-07-15 14:25:30,170 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
            2009-07-15 14:25:30,170 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
            2009-07-15 14:25:30,171 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.events#10], was: [org.jbpm.graph.def.ProcessDefinition.events#10] (uninitialized)
            2009-07-15 14:25:30,171 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#10], was: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#10] (uninitialized)
            2009-07-15 14:25:30,171 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.nodes#10], was: [org.jbpm.graph.def.ProcessDefinition.nodes#10] (uninitialized)
            2009-07-15 14:25:30,171 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.actions#10], was: [org.jbpm.graph.def.ProcessDefinition.actions#10] (uninitialized)
            2009-07-15 14:25:30,171 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.definitions#10], was: [org.jbpm.graph.def.ProcessDefinition.definitions#10] (uninitialized)
            2009-07-15 14:25:30,172 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.exe.ProcessInstance.runtimeActions#20], was: [org.jbpm.graph.exe.ProcessInstance.runtimeActions#20] (uninitialized)
            2009-07-15 14:25:30,172 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.exe.ProcessInstance.instances#20], was: [org.jbpm.graph.exe.ProcessInstance.instances#20] (uninitialized)
            2009-07-15 14:25:30,172 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
            2009-07-15 14:25:30,172 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 7 collections
            2009-07-15 14:25:30,172 DEBUG [org.hibernate.pretty.Printer] listing entities:
            2009-07-15 14:25:30,173 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.exe.ProcessInstance{processDefinition=org.jbpm.graph.def.ProcessDefinition#10, id=20, superProcessToken=null, start=2009-07-15 14:16:23, isSuspended=false, runtimeActions=, rootToken=org.jbpm.graph.exe.Token#20, instances=, end=null, key=null, version=1}
            2009-07-15 14:25:30,173 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.def.ProcessDefinition{id=10, nodes=, events=, description=null, name=websale, isTerminationImplicit=false, startState=org.jbpm.graph.def.Node#54, definitions=, actions=, version=2, exceptionHandlers=}
            2009-07-15 14:25:30,174 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:30,180 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService@1afcfd4
            2009-07-15 14:25:30,181 DEBUG [org.jbpm.svc.Services] closing service 'authentication': org.jbpm.security.authentication.DefaultAuthenticationService@175705e
            2009-07-15 14:25:33,383 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
            2009-07-15 14:25:33,383 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext@192d7d0
            2009-07-15 14:25:33,383 DEBUG [org.jbpm.persistence.jta.JtaDbPersistenceService] beginning null
            2009-07-15 14:25:33,384 DEBUG [org.jbpm.persistence.db.DbPersistenceService] using current hibernate session
            2009-07-15 14:25:33,384 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
            2009-07-15 14:25:33,384 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 5110506837540864
            2009-07-15 14:25:33,384 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.ProcessDefinition#10
            2009-07-15 14:25:33,384 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,385 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,386 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,386 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,386 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,387 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.graph.exe.Token
            */ insert
            into
            JBPM_TOKEN
            (VERSION_, NAME_, START_, END_, NODEENTER_, NEXTLOGINDEX_, ISABLETOREACTIVATEPARENT_, ISTERMINATIONIMPLICIT_, ISSUSPENDED_, LOCK_, NODE_, PROCESSINSTANCE_, PARENT_, SUBPROCESSINSTANCE_)
            values
            (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
            2009-07-15 14:25:33,389 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 21
            2009-07-15 14:25:33,389 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,389 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,389 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,390 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,390 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,390 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,390 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.graph.exe.ProcessInstance
            */ insert
            into
            JBPM_PROCESSINSTANCE
            (VERSION_, KEY_, START_, END_, ISSUSPENDED_, PROCESSDEFINITION_, ROOTTOKEN_, SUPERPROCESSTOKEN_)
            values
            (?, ?, ?, ?, ?, ?, ?, ?)
            2009-07-15 14:25:33,392 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 21
            2009-07-15 14:25:33,392 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,392 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,392 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,392 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.ProcessDefinition.definitions#10
            2009-07-15 14:25:33,392 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,393 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.module.def.ModuleDefinition#28
            2009-07-15 14:25:33,393 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,393 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,393 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.module.def.ModuleDefinition#29
            2009-07-15 14:25:33,393 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,393 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,393 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.module.def.ModuleDefinition#30
            2009-07-15 14:25:33,394 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,394 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,394 DEBUG [org.jbpm.graph.def.GraphElement] event 'process-start' on ProcessDefinition(websale) for Token(/)
            2009-07-15 14:25:33,395 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.ProcessDefinition.events#10
            2009-07-15 14:25:33,395 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,395 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.def.Node#54]
            2009-07-15 14:25:33,395 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.Node#54
            2009-07-15 14:25:33,395 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,396 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,397 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.taskmgmt.def.Task#26]
            2009-07-15 14:25:33,397 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.taskmgmt.def.Task#26
            2009-07-15 14:25:33,397 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,397 WARN [org.hibernate.engine.StatefulPersistenceContext.ProxyWarnLog] Narrowing proxy to class org.jbpm.graph.node.StartState - this operation breaks ==
            2009-07-15 14:25:33,398 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,398 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,398 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,399 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,399 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.taskmgmt.exe.TaskInstance
            */ insert
            into
            JBPM_TASKINSTANCE
            (VERSION_, NAME_, DESCRIPTION_, ACTORID_, CREATE_, START_, END_, DUEDATE_, PRIORITY_, ISCANCELLED_, ISSUSPENDED_, ISOPEN_, ISSIGNALLING_, ISBLOCKING_, TASK_, TOKEN_, PROCINST_, SWIMLANINSTANCE_, TASKMGMTINSTANCE_, CLASS_)
            values
            (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, 'T')
            2009-07-15 14:25:33,405 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 27
            2009-07-15 14:25:33,405 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,405 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,406 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,406 DEBUG [org.jbpm.graph.def.GraphElement] event 'task-create' on Task(Create new web sale order) for Token(/)
            2009-07-15 14:25:33,406 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.taskmgmt.def.Task.events#26
            2009-07-15 14:25:33,407 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,407 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.node.StartState#54]
            2009-07-15 14:25:33,407 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache lookup: org.jbpm.graph.def.Node.events#54
            2009-07-15 14:25:33,407 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] Cache hit
            2009-07-15 14:25:33,408 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.taskmgmt.def.Swimlane#17]
            2009-07-15 14:25:33,409 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.taskmgmt.def.Swimlane#17]
            2009-07-15 14:25:33,409 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,409 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,410 DEBUG [org.hibernate.SQL]
            /* load org.jbpm.taskmgmt.def.Swimlane */ select
            swimlane0_.ID_ as ID1_16_0_,
            swimlane0_.NAME_ as NAME2_16_0_,
            swimlane0_.ACTORIDEXPRESSION_ as ACTORIDE3_16_0_,
            swimlane0_.POOLEDACTORSEXPRESSION_ as POOLEDAC4_16_0_,
            swimlane0_.ASSIGNMENTDELEGATION_ as ASSIGNME5_16_0_,
            swimlane0_.TASKMGMTDEFINITION_ as TASKMGMT6_16_0_
            from
            JBPM_SWIMLANE swimlane0_
            where
            swimlane0_.ID_=?
            2009-07-15 14:25:33,411 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:33,411 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.taskmgmt.def.Swimlane#17]
            2009-07-15 14:25:33,412 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:33,412 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,412 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,412 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,413 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.taskmgmt.def.Swimlane#17]
            2009-07-15 14:25:33,413 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.taskmgmt.def.Swimlane#17]
            2009-07-15 14:25:33,413 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,413 DEBUG [org.hibernate.loader.Loader] done entity load
            2009-07-15 14:25:33,414 DEBUG [org.jbpm.taskmgmt.exe.TaskInstance] assigning task 'Create new web sale order' to 'user'
            2009-07-15 14:25:33,414 DEBUG [org.jbpm.graph.def.GraphElement] event 'task-assign' on Task(Create new web sale order) for Token(/)
            2009-07-15 14:25:33,414 DEBUG [org.jbpm.svc.Services] executing default save operations
            2009-07-15 14:25:33,414 DEBUG [org.jbpm.svc.save.HibernateSaveOperation] saving process instance
            2009-07-15 14:25:33,452 DEBUG [org.jbpm.svc.save.SaveLogsOperation] posting logs to logging service.
            2009-07-15 14:25:33,453 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,453 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,453 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,453 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.graph.log.ProcessInstanceCreateLog
            */ insert
            into
            JBPM_LOG
            (INDEX_, DATE_, TOKEN_, PARENT_, CLASS_)
            values
            (?, ?, ?, ?, 'I')
            2009-07-15 14:25:33,455 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 472
            2009-07-15 14:25:33,455 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,456 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,456 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,456 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,457 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,457 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,458 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.taskmgmt.log.TaskCreateLog
            */ insert
            into
            JBPM_LOG
            (INDEX_, DATE_, TOKEN_, PARENT_, TASKINSTANCE_, TASKACTORID_, CLASS_)
            values
            (?, ?, ?, ?, ?, ?, '1')
            2009-07-15 14:25:33,461 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 473
            2009-07-15 14:25:33,464 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,465 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,469 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,470 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,470 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,470 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,471 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.taskmgmt.log.TaskAssignLog
            */ insert
            into
            JBPM_LOG
            (INDEX_, DATE_, TOKEN_, PARENT_, TASKINSTANCE_, TASKOLDACTORID_, TASKACTORID_, CLASS_)
            values
            (?, ?, ?, ?, ?, ?, ?, '2')
            2009-07-15 14:25:33,473 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 474
            2009-07-15 14:25:33,473 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,473 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,473 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,474 DEBUG [org.jbpm.svc.save.CascadeSaveOperation] cascading save of 'ProcessInstance(21)'
            2009-07-15 14:25:33,474 DEBUG [org.jbpm.JbpmContext] closing jbpmContext org.jbpm.JbpmContext@192d7d0
            2009-07-15 14:25:33,474 DEBUG [org.jbpm.svc.Services] closing service 'persistence': org.jbpm.persistence.jta.JtaDbPersistenceService@f4104f
            2009-07-15 14:25:33,475 DEBUG [org.jbpm.persistence.jta.JtaDbPersistenceService] committing org.jboss.tm.usertx.client.ServerVMClientUserTransaction@1ef0b44
            2009-07-15 14:25:33,475 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
            2009-07-15 14:25:33,476 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,480 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,480 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,480 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.context.exe.ContextInstance
            */ insert
            into
            JBPM_MODULEINSTANCE
            (VERSION_, PROCESSINSTANCE_, CLASS_)
            values
            (?, ?, 'C')
            2009-07-15 14:25:33,492 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 25
            2009-07-15 14:25:33,492 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,492 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,493 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,493 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,493 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,494 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,494 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.taskmgmt.exe.TaskMgmtInstance
            */ insert
            into
            JBPM_MODULEINSTANCE
            (VERSION_, PROCESSINSTANCE_, TASKMGMTDEFINITION_, CLASS_)
            values
            (?, ?, ?, 'T')
            2009-07-15 14:25:33,496 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 26
            2009-07-15 14:25:33,496 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,496 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,496 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,497 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] executing identity-insert immediately
            2009-07-15 14:25:33,498 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,498 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,498 DEBUG [org.hibernate.SQL]
            /* insert org.jbpm.taskmgmt.exe.SwimlaneInstance
            */ insert
            into
            JBPM_SWIMLANEINSTANCE
            (VERSION_, NAME_, ACTORID_, SWIMLANE_, TASKMGMTINSTANCE_)
            values
            (?, ?, ?, ?, ?)
            2009-07-15 14:25:33,500 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] Natively generated identity: 11
            2009-07-15 14:25:33,500 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,500 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,501 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,502 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
            2009-07-15 14:25:33,502 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.events#10], was: [org.jbpm.graph.def.ProcessDefinition.events#10] (initialized)
            2009-07-15 14:25:33,502 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#10], was: [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers#10] (uninitialized)
            2009-07-15 14:25:33,503 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.nodes#10], was: [org.jbpm.graph.def.ProcessDefinition.nodes#10] (uninitialized)
            2009-07-15 14:25:33,503 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.actions#10], was: [org.jbpm.graph.def.ProcessDefinition.actions#10] (uninitialized)
            2009-07-15 14:25:33,504 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.ProcessDefinition.definitions#10], was: [org.jbpm.graph.def.ProcessDefinition.definitions#10] (initialized)
            2009-07-15 14:25:33,505 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.exe.ProcessInstance.instances#21], was: [] (initialized)
            2009-07-15 14:25:33,508 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.file.def.FileDefinition.processFiles#29], was: [org.jbpm.file.def.FileDefinition.processFiles#29] (uninitialized)
            2009-07-15 14:25:33,509 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.taskmgmt.def.TaskMgmtDefinition.swimlanes#30], was: [org.jbpm.taskmgmt.def.TaskMgmtDefinition.swimlanes#30] (uninitialized)
            2009-07-15 14:25:33,528 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.taskmgmt.def.TaskMgmtDefinition.tasks#30], was: [org.jbpm.taskmgmt.def.TaskMgmtDefinition.tasks#30] (uninitialized)
            2009-07-15 14:25:33,529 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.events#54], was: [org.jbpm.graph.def.Node.events#54] (initialized)
            2009-07-15 14:25:33,529 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.exceptionHandlers#54], was: [org.jbpm.graph.def.Node.exceptionHandlers#54] (uninitialized)
            2009-07-15 14:25:33,529 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.leavingTransitions#54], was: [org.jbpm.graph.def.Node.leavingTransitions#54] (uninitialized)
            2009-07-15 14:25:33,529 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.graph.def.Node.arrivingTransitions#54], was: [org.jbpm.graph.def.Node.arrivingTransitions#54] (uninitialized)
            2009-07-15 14:25:33,530 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.taskmgmt.def.Task.events#26], was: [org.jbpm.taskmgmt.def.Task.events#26] (initialized)
            2009-07-15 14:25:33,530 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.taskmgmt.def.Task.exceptionHandlers#26], was: [org.jbpm.taskmgmt.def.Task.exceptionHandlers#26] (uninitialized)
            2009-07-15 14:25:33,531 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.taskmgmt.def.Swimlane.tasks#17], was: [org.jbpm.taskmgmt.def.Swimlane.tasks#17] (uninitialized)
            2009-07-15 14:25:33,532 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances#26], was: [] (initialized)
            2009-07-15 14:25:33,532 DEBUG [org.hibernate.engine.Collections] Collection found: [org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#26], was: [] (initialized)
            2009-07-15 14:25:33,532 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 3 updates, 0 deletions to 16 objects
            2009-07-15 14:25:33,532 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 3 (re)creations, 0 updates, 0 removals to 18 collections
            2009-07-15 14:25:33,532 DEBUG [org.hibernate.pretty.Printer] listing entities:
            2009-07-15 14:25:33,533 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.log.TaskCreateLog{id=473, index=1, token=org.jbpm.graph.exe.Token#21, taskActorId=null, parent=null, date=2009-07-15 14:25:33, taskInstance=org.jbpm.taskmgmt.exe.TaskInstance#27}
            2009-07-15 14:25:33,534 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.log.ProcessInstanceCreateLog{id=472, index=0, token=org.jbpm.graph.exe.Token#21, parent=null, date=2009-07-15 14:25:33}
            2009-07-15 14:25:33,534 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.def.Task{swimlane=org.jbpm.taskmgmt.def.Swimlane#17, taskController=null, condition=null, taskNode=null, events=[], pooledActorsExpression=null, startState=org.jbpm.graph.node.StartState#54, isBlocking=false, exceptionHandlers=, id=26, processDefinition=org.jbpm.graph.def.ProcessDefinition#10, actorIdExpression=null, isSignalling=true, taskMgmtDefinition=null, description=null, priority=3, name=Create new web sale order, dueDate=null, assignmentDelegation=null}
            2009-07-15 14:25:33,535 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.log.TaskAssignLog{id=474, index=2, taskNewActorId=user, token=org.jbpm.graph.exe.Token#21, parent=null, taskOldActorId=null, date=2009-07-15 14:25:33, taskInstance=org.jbpm.taskmgmt.exe.TaskInstance#27}
            2009-07-15 14:25:33,535 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.def.Swimlane{id=17, actorIdExpression=null, taskMgmtDefinition=org.jbpm.taskmgmt.def.TaskMgmtDefinition#30, pooledActorsExpression=null, name=buyer, tasks=, assignmentDelegation=null}
            2009-07-15 14:25:33,540 DEBUG [org.hibernate.pretty.Printer] org.jbpm.context.def.ContextDefinition{processDefinition=org.jbpm.graph.def.ProcessDefinition#10, id=28, name=org.jbpm.context.def.ContextDefinition}
            2009-07-15 14:25:33,540 DEBUG [org.hibernate.pretty.Printer] org.jbpm.file.def.FileDefinition{processFiles=, processDefinition=org.jbpm.graph.def.ProcessDefinition#10, id=29, name=org.jbpm.file.def.FileDefinition}
            2009-07-15 14:25:33,541 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.node.StartState{superState=null, processDefinition=org.jbpm.graph.def.ProcessDefinition#10, id=54, isAsyncExclusive=false, events=[], description=null, arrivingTransitions=, name=Create new web sale order, action=null, isAsync=false, leavingTransitions=, exceptionHandlers=}
            2009-07-15 14:25:33,541 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.def.TaskMgmtDefinition{swimlanes=, processDefinition=org.jbpm.graph.def.ProcessDefinition#10, id=30, name=org.jbpm.taskmgmt.def.TaskMgmtDefinition, tasks=, startTask=org.jbpm.taskmgmt.def.Task#26}
            2009-07-15 14:25:33,541 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.exe.TaskMgmtInstance{id=26, taskMgmtDefinition=org.jbpm.taskmgmt.def.TaskMgmtDefinition#30, swimlaneInstances=[org.jbpm.taskmgmt.exe.SwimlaneInstance#11], taskInstances=[org.jbpm.taskmgmt.exe.TaskInstance#27], processInstance=org.jbpm.graph.exe.ProcessInstance#21, version=0}
            2009-07-15 14:25:33,541 DEBUG [org.hibernate.pretty.Printer] org.jbpm.context.exe.ContextInstance{id=25, processInstance=org.jbpm.graph.exe.ProcessInstance#21, tokenVariableMaps=null, version=0}
            2009-07-15 14:25:33,542 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.exe.ProcessInstance{processDefinition=org.jbpm.graph.def.ProcessDefinition#10, id=21, superProcessToken=null, start=2009-07-15 14:25:33, isSuspended=false, runtimeActions=null, rootToken=org.jbpm.graph.exe.Token#21, instances=[org.jbpm.module.exe.ModuleInstance#25, org.jbpm.module.exe.ModuleInstance#26], end=null, key=null, version=1}
            2009-07-15 14:25:33,542 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.exe.Token{isSuspended=false, isTerminationImplicit=false, lock=null, children=null, parent=null, processInstance=org.jbpm.graph.exe.ProcessInstance#21, nextLogIndex=3, version=0, id=21, node=org.jbpm.graph.def.Node#54, nodeEnter=null, subProcessInstance=null, start=2009-07-15 14:25:33, name=null, isAbleToReactivateParent=true, comments=null, end=null}
            2009-07-15 14:25:33,542 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.exe.SwimlaneInstance{id=11, swimlane=org.jbpm.taskmgmt.def.Swimlane#17, actorId=user, name=buyer, taskMgmtInstance=org.jbpm.taskmgmt.exe.TaskMgmtInstance#26, pooledActors=null, version=0}
            2009-07-15 14:25:33,543 DEBUG [org.hibernate.pretty.Printer] org.jbpm.taskmgmt.exe.TaskInstance{task=org.jbpm.taskmgmt.def.Task#26, isCancelled=false, isSuspended=false, processInstance=org.jbpm.graph.exe.ProcessInstance#21, isBlocking=false, pooledActors=null, variableInstances=null, create=2009-07-15 14:25:33, version=0, isOpen=true, id=27, swimlaneInstance=org.jbpm.taskmgmt.exe.SwimlaneInstance#11, isSignalling=true, token=org.jbpm.graph.exe.Token#21, start=null, description=null, actorId=user, priority=3, name=Create new web sale order, taskMgmtInstance=org.jbpm.taskmgmt.exe.TaskMgmtInstance#26, dueDate=null, comments=null, end=null}
            2009-07-15 14:25:33,544 DEBUG [org.hibernate.pretty.Printer] org.jbpm.graph.def.ProcessDefinition{id=10, nodes=, events=[], description=null, name=websale, isTerminationImplicit=false, startState=org.jbpm.graph.def.Node#54, definitions=[org.jbpm.module.def.ModuleDefinition#28, org.jbpm.module.def.ModuleDefinition#29, org.jbpm.module.def.ModuleDefinition#30], actions=, version=2, exceptionHandlers=}
            2009-07-15 14:25:33,544 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,544 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,544 DEBUG [org.hibernate.SQL]
            /* update
            org.jbpm.graph.exe.Token */ update
            JBPM_TOKEN
            set
            VERSION_=?,
            NAME_=?,
            START_=?,
            END_=?,
            NODEENTER_=?,
            NEXTLOGINDEX_=?,
            ISABLETOREACTIVATEPARENT_=?,
            ISTERMINATIONIMPLICIT_=?,
            ISSUSPENDED_=?,
            LOCK_=?,
            NODE_=?,
            PROCESSINSTANCE_=?,
            PARENT_=?,
            SUBPROCESSINSTANCE_=?
            where
            ID_=?
            and VERSION_=?
            2009-07-15 14:25:33,724 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,725 DEBUG [org.hibernate.jdbc.ConnectionManager] skipping aggressive-release due to flush cycle
            2009-07-15 14:25:33,725 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,725 DEBUG [org.hibernate.SQL]
            /* update
            org.jbpm.graph.exe.ProcessInstance */ update
            JBPM_PROCESSINSTANCE
            set
            VERSION_=?,
            KEY_=?,
            START_=?,
            END_=?,
            ISSUSPENDED_=?,
            PROCESSDEFINITION_=?,
            ROOTTOKEN_=?,
            SUPERPROCESSTOKEN_=?
            where
            ID_=?
            and VERSION_=?
            2009-07-15 14:25:33,727 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,727 DEBUG [org.hibernate.jdbc.ConnectionManager] skipping aggressive-release due to flush cycle
            2009-07-15 14:25:33,727 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,727 DEBUG [org.hibernate.SQL]
            /* update
            org.jbpm.taskmgmt.exe.TaskInstance */ update
            JBPM_TASKINSTANCE
            set
            VERSION_=?,
            NAME_=?,
            DESCRIPTION_=?,
            ACTORID_=?,
            CREATE_=?,
            START_=?,
            END_=?,
            DUEDATE_=?,
            PRIORITY_=?,
            ISCANCELLED_=?,
            ISSUSPENDED_=?,
            ISOPEN_=?,
            ISSIGNALLING_=?,
            ISBLOCKING_=?,
            TASK_=?,
            TOKEN_=?,
            PROCINST_=?,
            SWIMLANINSTANCE_=?,
            TASKMGMTINSTANCE_=?
            where
            ID_=?
            and VERSION_=?
            2009-07-15 14:25:33,730 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,730 DEBUG [org.hibernate.jdbc.ConnectionManager] skipping aggressive-release due to flush cycle
            2009-07-15 14:25:33,730 DEBUG [org.hibernate.persister.collection.AbstractCollectionPersister] Inserting collection: [org.jbpm.graph.exe.ProcessInstance.instances#21]
            2009-07-15 14:25:33,730 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,730 DEBUG [org.hibernate.SQL]
            /* create one-to-many row org.jbpm.graph.exe.ProcessInstance.instances */ update
            JBPM_MODULEINSTANCE
            set
            PROCESSINSTANCE_=?,
            NAME_=?
            where
            ID_=?
            2009-07-15 14:25:33,731 DEBUG [org.hibernate.jdbc.AbstractBatcher] reusing prepared statement
            2009-07-15 14:25:33,731 DEBUG [org.hibernate.SQL]
            /* create one-to-many row org.jbpm.graph.exe.ProcessInstance.instances */ update
            JBPM_MODULEINSTANCE
            set
            PROCESSINSTANCE_=?,
            NAME_=?
            where
            ID_=?
            2009-07-15 14:25:33,731 DEBUG [org.hibernate.persister.collection.AbstractCollectionPersister] done inserting collection: 2 rows inserted
            2009-07-15 14:25:33,731 DEBUG [org.hibernate.jdbc.AbstractBatcher] Executing batch size: 2
            2009-07-15 14:25:33,733 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,733 DEBUG [org.hibernate.jdbc.ConnectionManager] skipping aggressive-release due to flush cycle
            2009-07-15 14:25:33,733 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,733 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,749 DEBUG [org.jbpm.svc.Services] closing service 'tx': org.jbpm.tx.TxService@f2818d
            2009-07-15 14:25:33,749 DEBUG [org.jbpm.svc.Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@1177565
            2009-07-15 14:25:33,749 DEBUG [org.jbpm.svc.Services] closing service 'authentication': org.jbpm.security.authentication.DefaultAuthenticationService@11c4ef6
            2009-07-15 14:25:33,777 DEBUG [org.jbpm.configuration.JbpmContextInfo] creating jbpm context with service factories '[message, tx, scheduler, authentication, persistence, logging]'
            2009-07-15 14:25:33,777 DEBUG [org.jbpm.JbpmContext] creating org.jbpm.JbpmContext@1841ae5
            2009-07-15 14:25:33,777 DEBUG [org.jbpm.persistence.jta.JtaDbPersistenceService] beginning null
            2009-07-15 14:25:33,778 DEBUG [org.jbpm.persistence.db.DbPersistenceService] using current hibernate session
            2009-07-15 14:25:33,778 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
            2009-07-15 14:25:33,778 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 5110506839154688
            2009-07-15 14:25:33,778 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.graph.exe.ProcessInstance#21]
            2009-07-15 14:25:33,778 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,778 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,779 DEBUG [org.hibernate.SQL]
            /* load org.jbpm.graph.exe.ProcessInstance */ select
            processins0_.ID_ as ID1_20_0_,
            processins0_.VERSION_ as VERSION2_20_0_,
            processins0_.KEY_ as KEY3_20_0_,
            processins0_.START_ as START4_20_0_,
            processins0_.END_ as END5_20_0_,
            processins0_.ISSUSPENDED_ as ISSUSPEN6_20_0_,
            processins0_.PROCESSDEFINITION_ as PROCESSD7_20_0_,
            processins0_.ROOTTOKEN_ as ROOTTOKEN8_20_0_,
            processins0_.SUPERPROCESSTOKEN_ as SUPERPRO9_20_0_
            from
            JBPM_PROCESSINSTANCE processins0_
            where
            processins0_.ID_=?
            2009-07-15 14:25:33,781 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:33,781 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.graph.exe.ProcessInstance#21]
            2009-07-15 14:25:33,782 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:33,782 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,782 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,782 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,783 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.graph.exe.ProcessInstance#21]
            2009-07-15 14:25:33,784 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.graph.exe.ProcessInstance#21]
            2009-07-15 14:25:33,784 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,784 DEBUG [org.hibernate.loader.Loader] done entity load
            2009-07-15 14:25:33,785 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.graph.exe.Token#21]
            2009-07-15 14:25:33,785 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.graph.exe.Token#21]
            2009-07-15 14:25:33,785 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,785 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,785 DEBUG [org.hibernate.SQL]
            /* load org.jbpm.graph.exe.Token */ select
            token0_.ID_ as ID1_21_0_,
            token0_.VERSION_ as VERSION2_21_0_,
            token0_.NAME_ as NAME3_21_0_,
            token0_.START_ as START4_21_0_,
            token0_.END_ as END5_21_0_,
            token0_.NODEENTER_ as NODEENTER6_21_0_,
            token0_.NEXTLOGINDEX_ as NEXTLOGI7_21_0_,
            token0_.ISABLETOREACTIVATEPARENT_ as ISABLETO8_21_0_,
            token0_.ISTERMINATIONIMPLICIT_ as ISTERMIN9_21_0_,
            token0_.ISSUSPENDED_ as ISSUSPE10_21_0_,
            token0_.LOCK_ as LOCK11_21_0_,
            token0_.NODE_ as NODE12_21_0_,
            token0_.PROCESSINSTANCE_ as PROCESS13_21_0_,
            token0_.PARENT_ as PARENT14_21_0_,
            token0_.SUBPROCESSINSTANCE_ as SUBPROC15_21_0_
            from
            JBPM_TOKEN token0_
            where
            token0_.ID_=?
            2009-07-15 14:25:33,974 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:33,974 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.graph.exe.Token#21]
            2009-07-15 14:25:33,975 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:33,975 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,975 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,976 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,976 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.graph.exe.Token#21]
            2009-07-15 14:25:33,976 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.graph.exe.Token#21]
            2009-07-15 14:25:33,976 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,977 DEBUG [org.hibernate.loader.Loader] done entity load
            2009-07-15 14:25:33,977 DEBUG [org.hibernate.loader.Loader] loading collection: [org.jbpm.graph.exe.Token.comments#21]
            2009-07-15 14:25:33,977 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,977 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,977 DEBUG [org.hibernate.SQL]
            /* load one-to-many org.jbpm.graph.exe.Token.comments */ select
            comments0_.TOKEN_ as TOKEN6_1_,
            comments0_.ID_ as ID1_1_,
            comments0_.TOKENINDEX_ as TOKENINDEX8_1_,
            comments0_.ID_ as ID1_19_0_,
            comments0_.VERSION_ as VERSION2_19_0_,
            comments0_.ACTORID_ as ACTORID3_19_0_,
            comments0_.TIME_ as TIME4_19_0_,
            comments0_.MESSAGE_ as MESSAGE5_19_0_,
            comments0_.TOKEN_ as TOKEN6_19_0_,
            comments0_.TASKINSTANCE_ as TASKINST7_19_0_
            from
            JBPM_COMMENT comments0_
            where
            comments0_.TOKEN_=?
            2009-07-15 14:25:33,979 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:33,979 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [org.jbpm.graph.exe.Token.comments#21]
            2009-07-15 14:25:33,979 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:33,979 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:33,979 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:33,980 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:33,980 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections were found in result set for role: org.jbpm.graph.exe.Token.comments
            2009-07-15 14:25:33,980 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] collection fully initialized: [org.jbpm.graph.exe.Token.comments#21]
            2009-07-15 14:25:33,980 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections initialized for role: org.jbpm.graph.exe.Token.comments
            2009-07-15 14:25:33,980 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:33,980 DEBUG [org.hibernate.loader.Loader] done loading collection
            2009-07-15 14:25:33,980 DEBUG [org.hibernate.loader.Loader] loading collection: [org.jbpm.graph.exe.Token.children#21]
            2009-07-15 14:25:33,981 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:33,981 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:33,981 DEBUG [org.hibernate.SQL]
            /* load one-to-many org.jbpm.graph.exe.Token.children */ select
            children0_.PARENT_ as PARENT14_1_,
            children0_.ID_ as ID1_1_,
            children0_.NAME_ as NAME3_1_,
            children0_.ID_ as ID1_21_0_,
            children0_.VERSION_ as VERSION2_21_0_,
            children0_.NAME_ as NAME3_21_0_,
            children0_.START_ as START4_21_0_,
            children0_.END_ as END5_21_0_,
            children0_.NODEENTER_ as NODEENTER6_21_0_,
            children0_.NEXTLOGINDEX_ as NEXTLOGI7_21_0_,
            children0_.ISABLETOREACTIVATEPARENT_ as ISABLETO8_21_0_,
            children0_.ISTERMINATIONIMPLICIT_ as ISTERMIN9_21_0_,
            children0_.ISSUSPENDED_ as ISSUSPE10_21_0_,
            children0_.LOCK_ as LOCK11_21_0_,
            children0_.NODE_ as NODE12_21_0_,
            children0_.PROCESSINSTANCE_ as PROCESS13_21_0_,
            children0_.PARENT_ as PARENT14_21_0_,
            children0_.SUBPROCESSINSTANCE_ as SUBPROC15_21_0_
            from
            JBPM_TOKEN children0_
            where
            children0_.PARENT_=?
            2009-07-15 14:25:34,144 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:34,144 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [org.jbpm.graph.exe.Token.children#21]
            2009-07-15 14:25:34,144 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections were found in result set for role: org.jbpm.graph.exe.Token.children
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] collection fully initialized: [org.jbpm.graph.exe.Token.children#21]
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections initialized for role: org.jbpm.graph.exe.Token.children
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:34,145 DEBUG [org.hibernate.loader.Loader] done loading collection
            2009-07-15 14:25:34,146 DEBUG [org.hibernate.loader.Loader] loading collection: [org.jbpm.graph.exe.ProcessInstance.instances#21]
            2009-07-15 14:25:34,146 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:34,146 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:34,146 DEBUG [org.hibernate.SQL]
            /* load one-to-many org.jbpm.graph.exe.ProcessInstance.instances */ select
            instances0_.PROCESSINSTANCE_ as PROCESSI4_1_,
            instances0_.ID_ as ID1_1_,
            instances0_.NAME_ as NAME6_1_,
            instances0_.ID_ as ID1_23_0_,
            instances0_.VERSION_ as VERSION3_23_0_,
            instances0_.PROCESSINSTANCE_ as PROCESSI4_23_0_,
            instances0_.TASKMGMTDEFINITION_ as TASKMGMT5_23_0_,
            instances0_.CLASS_ as CLASS2_23_0_
            from
            JBPM_MODULEINSTANCE instances0_
            where
            instances0_.PROCESSINSTANCE_=?
            2009-07-15 14:25:34,148 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:34,148 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [org.jbpm.graph.exe.ProcessInstance.instances#21]
            2009-07-15 14:25:34,148 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.module.exe.ModuleInstance#25]
            2009-07-15 14:25:34,148 DEBUG [org.hibernate.loader.Loader] found row of collection: [org.jbpm.graph.exe.ProcessInstance.instances#21]
            2009-07-15 14:25:34,149 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.module.exe.ModuleInstance#26]
            2009-07-15 14:25:34,149 DEBUG [org.hibernate.loader.Loader] found row of collection: [org.jbpm.graph.exe.ProcessInstance.instances#21]
            2009-07-15 14:25:34,149 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:34,149 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:34,149 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:34,150 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:34,150 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.context.exe.ContextInstance#25]
            2009-07-15 14:25:34,150 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.context.exe.ContextInstance#25]
            2009-07-15 14:25:34,150 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.taskmgmt.exe.TaskMgmtInstance#26]
            2009-07-15 14:25:34,150 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.taskmgmt.exe.TaskMgmtInstance#26]
            2009-07-15 14:25:34,151 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections were found in result set for role: org.jbpm.graph.exe.ProcessInstance.instances
            2009-07-15 14:25:34,151 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] collection fully initialized: [org.jbpm.graph.exe.ProcessInstance.instances#21]
            2009-07-15 14:25:34,151 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections initialized for role: org.jbpm.graph.exe.ProcessInstance.instances
            2009-07-15 14:25:34,151 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:34,151 DEBUG [org.hibernate.loader.Loader] done loading collection
            2009-07-15 14:25:34,151 DEBUG [org.hibernate.loader.Loader] loading collection: [org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#26]
            2009-07-15 14:25:34,206 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:34,206 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:34,207 DEBUG [org.hibernate.SQL]
            /* load one-to-many org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances */ select
            taskinstan0_.TASKMGMTINSTANCE_ as TASKMGM21_1_,
            taskinstan0_.ID_ as ID1_1_,
            taskinstan0_.ID_ as ID1_27_0_,
            taskinstan0_.VERSION_ as VERSION3_27_0_,
            taskinstan0_.NAME_ as NAME4_27_0_,
            taskinstan0_.DESCRIPTION_ as DESCRIPT5_27_0_,
            taskinstan0_.ACTORID_ as ACTORID6_27_0_,
            taskinstan0_.CREATE_ as CREATE7_27_0_,
            taskinstan0_.START_ as START8_27_0_,
            taskinstan0_.END_ as END9_27_0_,
            taskinstan0_.DUEDATE_ as DUEDATE10_27_0_,
            taskinstan0_.PRIORITY_ as PRIORITY11_27_0_,
            taskinstan0_.ISCANCELLED_ as ISCANCE12_27_0_,
            taskinstan0_.ISSUSPENDED_ as ISSUSPE13_27_0_,
            taskinstan0_.ISOPEN_ as ISOPEN14_27_0_,
            taskinstan0_.ISSIGNALLING_ as ISSIGNA15_27_0_,
            taskinstan0_.ISBLOCKING_ as ISBLOCKING16_27_0_,
            taskinstan0_.TASK_ as TASK17_27_0_,
            taskinstan0_.TOKEN_ as TOKEN18_27_0_,
            taskinstan0_.PROCINST_ as PROCINST19_27_0_,
            taskinstan0_.SWIMLANINSTANCE_ as SWIMLAN20_27_0_,
            taskinstan0_.TASKMGMTINSTANCE_ as TASKMGM21_27_0_
            from
            JBPM_TASKINSTANCE taskinstan0_
            where
            taskinstan0_.TASKMGMTINSTANCE_=?
            2009-07-15 14:25:34,210 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:34,210 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#26]
            2009-07-15 14:25:34,211 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.taskmgmt.exe.TaskInstance#27]
            2009-07-15 14:25:34,213 DEBUG [org.hibernate.loader.Loader] found row of collection: [org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#26]
            2009-07-15 14:25:34,213 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:34,213 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:34,213 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:34,213 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:34,214 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [org.jbpm.taskmgmt.exe.TaskInstance#27]
            2009-07-15 14:25:34,214 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [org.jbpm.taskmgmt.exe.TaskInstance#27]
            2009-07-15 14:25:34,215 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections were found in result set for role: org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances
            2009-07-15 14:25:34,215 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] collection fully initialized: [org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances#26]
            2009-07-15 14:25:34,215 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections initialized for role: org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances
            2009-07-15 14:25:34,215 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:34,215 DEBUG [org.hibernate.loader.Loader] done loading collection
            2009-07-15 14:25:34,238 DEBUG [org.hibernate.loader.Loader] loading collection: [org.jbpm.taskmgmt.exe.TaskInstance.pooledActors#27]
            2009-07-15 14:25:34,238 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:34,238 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:34,239 DEBUG [org.hibernate.SQL]
            /* load collection org.jbpm.taskmgmt.exe.TaskInstance.pooledActors */ select
            pooledacto0_.TASKINSTANCE_ as TASKINST1_1_,
            pooledacto0_.POOLEDACTOR_ as POOLEDAC2_1_,
            pooledacto1_.ID_ as ID1_29_0_,
            pooledacto1_.VERSION_ as VERSION2_29_0_,
            pooledacto1_.ACTORID_ as ACTORID3_29_0_,
            pooledacto1_.SWIMLANEINSTANCE_ as SWIMLANE4_29_0_
            from
            JBPM_TASKACTORPOOL pooledacto0_
            left outer join
            JBPM_POOLEDACTOR pooledacto1_
            on pooledacto0_.POOLEDACTOR_=pooledacto1_.ID_
            where
            pooledacto0_.TASKINSTANCE_=?
            2009-07-15 14:25:34,241 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [org.jbpm.taskmgmt.exe.TaskInstance.pooledActors#27]
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections were found in result set for role: org.jbpm.taskmgmt.exe.TaskInstance.pooledActors
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] collection fully initialized: [org.jbpm.taskmgmt.exe.TaskInstance.pooledActors#27]
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.engine.loading.CollectionLoadContext] 1 collections initialized for role: org.jbpm.taskmgmt.exe.TaskInstance.pooledActors
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.loader.Loader] done loading collection
            2009-07-15 14:25:34,366 DEBUG [org.hibernate.impl.SessionImpl] initializing proxy: [org.jbpm.taskmgmt.exe.SwimlaneInstance#11]
            2009-07-15 14:25:34,367 DEBUG [org.hibernate.loader.Loader] loading entity: [org.jbpm.taskmgmt.exe.SwimlaneInstance#11]
            2009-07-15 14:25:34,367 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-07-15 14:25:34,367 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
            2009-07-15 14:25:34,367 DEBUG [org.hibernate.SQL]
            /* load org.jbpm.taskmgmt.exe.SwimlaneInstance */ select
            swimlanein0_.ID_ as ID1_30_0_,
            swimlanein0_.VERSION_ as VERSION2_30_0_,
            swimlanein0_.NAME_ as NAME3_30_0_,
            swimlanein0_.ACTORID_ as ACTORID4_30_0_,
            swimlanein0_.SWIMLANE_ as SWIMLANE5_30_0_,
            swimlanein0_.TASKMGMTINSTANCE_ as TASKMGMT6_30_0_
            from
            JBPM_SWIMLANEINSTANCE swimlanein0_
            where
            swimlanein0_.ID_=?
            2009-07-15 14:25:34,368 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-07-15 14:25:34,369 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[org.jbpm.taskmgmt.exe.SwimlaneInstance#11]
            2009-07-15 14:25:34,369 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-07-15 14:25:34,369 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-07-15 14:25:34,369 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
            2009-07-15 14:25:34,369 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-07-15 14:25:34,370

              • Actions
            • 3. Re: errors with the example websale workflow
              kukeltje
              kukeltje Jul 15, 2009 3:21 PM (in response to arpan25)

              Arpan,

              Where is the error in the stacktrace? I only see DEBUG, no errors.

                • Actions
              • 4. Re: errors with the example websale workflow
                arpan25 Jul 15, 2009 3:54 PM (in response to arpan25)

                HI,

                I am wondering as well, the log does not show any errors, still i get an error message...Can you tell me what could be possibly wrong ?

                  • Actions