12:03:16.413 [pool-1-thread-1] INFO  o.s.c.s.ClassPathXmlApplicationContext - Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@7d6bb63e: startup date [Thu Mar 31 12:03:16 PDT 2011]; root of context hierarchy
12:03:16.413 [pool-1-thread-1] INFO  o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/proferi-component.xml]
12:03:16.445 [pool-1-thread-1] INFO  o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/proferi-component-test.xml]
12:03:16.460 [pool-1-thread-1] INFO  o.s.b.f.s.DefaultListableBeanFactory - Overriding bean definition for bean 'processFlowService': replacing [Generic bean: class [com.proferi.core.NorbertProtobufService]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [META-INF/proferi-component.xml]] with [Generic bean: class [com.proferi.core.MockProtobufService]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [META-INF/proferi-component-test.xml]]
12:03:16.460 [pool-1-thread-1] INFO  o.s.b.f.s.DefaultListableBeanFactory - Overriding bean definition for bean 'connectionFactory': replacing [Generic bean: class [org.hornetq.jms.client.HornetQConnectionFactory]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [META-INF/proferi-component.xml]] with [Generic bean: class [org.hornetq.jms.client.HornetQConnectionFactory]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [META-INF/proferi-component-test.xml]]
12:03:16.476 [pool-1-thread-1] INFO  o.s.b.f.c.PropertyPlaceholderConfigurer - Loading properties file from class path resource [proferi-component.properties]
12:03:16.476 [pool-1-thread-1] INFO  o.s.b.f.s.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@1c944d4a: defining beans [processFlowManager,stepWorkItemHandler,stepActivationCallbackHandler,processEventListener,modelCache,modelFactory,droolsFlowAdapter,memberSetResolver,instanceCache,processFlowService,startProcessFlowHandler,getProcessFlowStatusHandler,stepCompletedServiceHandler,approvalCompletedServiceHandler,connectionFactory,protobufJmsListener,protobufConverter,messageHandler,cachedConnectionFactory,jmsTemplate,messageProducer,dataSource,transactionManager,entityManagerFactory,jpaAdapter,entityManager,org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0,testOutJmsTemplate,testInJmsTemplate,testInConverter,outListener,inSender,embeddedJmsBroker]; root of factory hierarchy
12:03:16.491 [pool-1-thread-1] DEBUG c.p.core.message.ProtobufJmsListener - invoking handleMessage on ProcessFlowMessageConsumer for a StepCompletedRequest
12:03:16.491 [pool-1-thread-1] DEBUG c.p.core.message.ProtobufJmsListener - invoking handleMessage on ProcessFlowMessageConsumer for a ApprovalCompletedRequest
12:03:16.491 [pool-1-thread-1] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Building JPA container EntityManagerFactory for persistence unit 'org.drools.persistence.jpa'
12:03:16.491 [pool-1-thread-1] DEBUG org.hibernate.ejb.Ejb3Configuration - Processing PersistenceUnitInfo [
	name: org.drools.persistence.jpa
	persistence provider classname: org.hibernate.ejb.HibernatePersistence
	classloader: sun.misc.Launcher$AppClassLoader@12360be0
	Temporary classloader: org.springframework.instrument.classloading.SimpleThrowawayClassLoader@1fca73bf
	excludeUnlistedClasses: false
	JTA datasource: null
	Non JTA datasource: org.apache.commons.dbcp.BasicDataSource@247510e7
	Transaction type: RESOURCE_LOCAL
	PU root URL: file:/C:/testSource/platform/process-flow/process-flow-service/target/classes/
	Jar files URLs []
	Managed classes names [
		org.drools.persistence.session.SessionInfo
		org.drools.persistence.processinstance.ProcessInstanceInfo
		org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable
		org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo
		org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable
		org.drools.persistence.processinstance.WorkItemInfo]
	Mapping files names []
	Properties [
		hibernate.max_fetch_depth: 3
		hibernate.hbm2ddl.auto: create]
12:03:16.491 [pool-1-thread-1] DEBUG org.hibernate.ejb.Ejb3Configuration - Detect class: true; detect hbm: true
12:03:16.491 [pool-1-thread-1] DEBUG org.hibernate.ejb.Ejb3Configuration - Detect class: true; detect hbm: true
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Searching mapped entities in jar/par: file:/C:/testSource/platform/process-flow/process-flow-service/target/classes/
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.CustomRuleFlowProcessFactory
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.DroolsFlowAdapter$1
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.DroolsFlowAdapter
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.DroolsStepNode
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.ProcessEventListener
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ConnectionProxy
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.DroolsNodeProxy
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.DroolsNodeProxyImpl
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.EndProxy
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ImpliedJoinProxy
12:03:16.491 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ImpliedSplitProxy$1
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ImpliedSplitProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ImpliedStepProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.Joiner
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.JoinProxy$1
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.JoinProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.NodeWrapper
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ProxyFactory$1
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ProxyFactory
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.ProxyType
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.SliceEndProxy$1
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.SliceEndProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.SliceStartProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.SplitProxy$1
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.SplitProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.Splitter
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.StartProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.StateProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.StepProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.WaitProxy
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.proxies.WrappingDroolsNodeProxyImpl
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.ProxyBuilder
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.StateNodeFactory
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.StepNodeFactory
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.StepWorkItemHandler
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.drools.UuidDataType
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.EventNodeInstance
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.ImpliedStepNodeInstance
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.NodeInstance$StatusType
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.NodeInstance
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.ProcessFlowInstance$StatusType
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.ProcessFlowInstance
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.ProcessObjectInstance
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.instances.StepNodeInstance
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.manager.ExternalEvent
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.manager.ProcessFlowManager
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.manager.StepActivationCallbackHandler
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.manager.StepApproval
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.manager.Terminator
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.message.AsyncStepActivationCallbackHandler
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.message.JmsProcessFlowMessageProducer
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.message.ProcessFlowMessageConsumer
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.message.ProcessFlowMessageProducer
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.service.ApprovalCompletedServiceHandler
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.service.GetProcessFlowStatusServiceHandler
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.service.ProcessFlowServiceUtils$1
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.service.ProcessFlowServiceUtils
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.service.StartProcessFlowServiceHandler
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.service.StepCompletedServiceHandler
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.utils.ApprovedStepNodeSupport
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - Filtering: com.proferi.process.utils.StepNodeSupport
12:03:16.507 [pool-1-thread-1] DEBUG o.h.ejb.packaging.AbstractJarVisitor - File Filter matched for META-INF/orm.xml
12:03:16.523 [pool-1-thread-1] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [file:///C:/testSource/platform/process-flow/process-flow-service/orm_1_0.xsd]
12:03:16.523 [pool-1-thread-1] DEBUG o.h.cfg.EJB3DTDEntityResolver - recognized EJB3 ORM namespace; attempting to resolve on classpath under org/hibernate/ejb
12:03:16.523 [pool-1-thread-1] DEBUG o.h.cfg.EJB3DTDEntityResolver - located [file:///C:/testSource/platform/process-flow/process-flow-service/orm_1_0.xsd] in classpath
12:03:16.523 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Execute first pass mapping processing
12:03:16.523 [pool-1-thread-1] INFO  o.h.cfg.annotations.QueryBinder - Binding Named query: ProcessInstancesWaitingForEvent => select processInstanceInfo.processInstanceId from ProcessInstanceInfo processInstanceInfo where :type in elements(processInstanceInfo.eventTypes)
12:03:16.523 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process hbm files
12:03:16.523 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process annotated classes
12:03:16.523 [pool-1-thread-1] INFO  org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: org.drools.persistence.session.SessionInfo
12:03:16.523 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column DTYPE. Unique false. Nullable false.
12:03:16.523 [pool-1-thread-1] DEBUG o.h.cfg.annotations.EntityBinder - Import with entity name SessionInfo
12:03:16.523 [pool-1-thread-1] INFO  o.h.cfg.annotations.EntityBinder - Bind entity org.drools.persistence.session.SessionInfo on table SessionInfo
12:03:16.523 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.session.SessionInfo property annotation
12:03:16.523 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.session.SessionInfo field annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.session.SessionInfo.id
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column id. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - id is an id
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for id
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property id
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Bind @Id on id
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.session.SessionInfo.lastModificationDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column lastModificationDate. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property lastModificationDate with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for lastModificationDate
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property lastModificationDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.session.SessionInfo.rulesByteArray
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column rulesByteArray. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property rulesByteArray with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for rulesByteArray
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property rulesByteArray
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.session.SessionInfo.startDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column startDate. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property startDate with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for startDate
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property startDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.session.SessionInfo.version
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column OPTLOCK. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - version is a version property
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property version with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for version
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property version
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Version name: version, unsavedValue: undefined
12:03:16.538 [pool-1-thread-1] INFO  org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column DTYPE. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.EntityBinder - Import with entity name ProcessInstanceInfo
12:03:16.538 [pool-1-thread-1] INFO  o.h.cfg.annotations.EntityBinder - Bind entity org.drools.persistence.processinstance.ProcessInstanceInfo on table ProcessInstanceInfo
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.ProcessInstanceInfo property annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.ProcessInstanceInfo field annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column InstanceId. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - processInstanceId is an id
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Bind @Id on processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column eventTypes. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column element. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column mapkey. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column InstanceId. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.CollectionBinder - Collection role: org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property eventTypes
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.externalVariables
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column externalVariables. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property externalVariables with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for externalVariables
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property externalVariables
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.lastModificationDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column lastModificationDate. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property lastModificationDate with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for lastModificationDate
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property lastModificationDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.lastReadDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column lastReadDate. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property lastReadDate with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for lastReadDate
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property lastReadDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.processId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column processId. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property processId with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for processId
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property processId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.processInstanceByteArray
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column processInstanceByteArray. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property processInstanceByteArray with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for processInstanceByteArray
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property processInstanceByteArray
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.startDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column startDate. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property startDate with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for startDate
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property startDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.state
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column state. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property state with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for state
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property state
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.variables
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column processInstanceId. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column variables. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column element. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column mapkey. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.CollectionBinder - Collection role: org.drools.persistence.processinstance.ProcessInstanceInfo.variables
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property variables
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.ProcessInstanceInfo.version
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column OPTLOCK. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - version is a version property
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property version with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for version
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property version
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Version name: version, unsavedValue: undefined
12:03:16.538 [pool-1-thread-1] INFO  org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column TYPE. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.EntityBinder - Import with entity name VariableInstanceInfo
12:03:16.538 [pool-1-thread-1] INFO  o.h.cfg.annotations.EntityBinder - Bind entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo on table VariableInstanceInfo
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Setting discriminator for entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo property annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo field annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo.id
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column id. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - id is an id
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for id
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property id
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Bind @Id on id
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo.name
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column name. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property name with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for name
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property name
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo.persister
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column persister. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property persister with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for persister
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property persister
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo.processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column processInstanceId. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property processInstanceId with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo.workItemId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column workItemId. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property workItemId with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for workItemId
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property workItemId
12:03:16.538 [pool-1-thread-1] INFO  org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.EntityBinder - Import with entity name JPAPersistedVariable
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable field annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable.entityClass
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column entityClass. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property entityClass with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for entityClass
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property entityClass
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable.entityId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column entityId. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property entityId with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for entityId
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property entityId
12:03:16.538 [pool-1-thread-1] INFO  org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.EntityBinder - Import with entity name SerializablePersistedVariable
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable field annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable.content
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column content. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property content with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for content
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property content
12:03:16.538 [pool-1-thread-1] INFO  org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: org.drools.persistence.processinstance.WorkItemInfo
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column DTYPE. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.EntityBinder - Import with entity name WorkItemInfo
12:03:16.538 [pool-1-thread-1] INFO  o.h.cfg.annotations.EntityBinder - Bind entity org.drools.persistence.processinstance.WorkItemInfo on table WorkItemInfo
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.WorkItemInfo property annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing org.drools.persistence.processinstance.WorkItemInfo field annotation
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.workItemId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column workItemId. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - workItemId is an id
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for workItemId
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property workItemId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Bind @Id on workItemId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.creationDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column creationDate. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property creationDate with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for creationDate
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property creationDate
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.externalVariables
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column externalVariables. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property externalVariables with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for externalVariables
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property externalVariables
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.name
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column name. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property name with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for name
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property name
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column processInstanceId. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property processInstanceId with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property processInstanceId
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.state
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column state. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property state with lazy=false
12:03:16.538 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for state
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property state
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column workItemId. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column variables. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column element. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column mapkey. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable true.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column null. Unique false. Nullable false.
12:03:16.538 [pool-1-thread-1] DEBUG o.h.cfg.annotations.CollectionBinder - Collection role: org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property variables
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.version
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column OPTLOCK. Unique false. Nullable true.
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - version is a version property
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property version with lazy=false
12:03:16.554 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for version
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property version
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Version name: version, unsavedValue: undefined
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.AnnotationBinder - Processing annotations of org.drools.persistence.processinstance.WorkItemInfo.workItemByteArray
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Ejb3Column - Binding column workItemByteArray. Unique false. Nullable true.
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - binding property workItemByteArray with lazy=false
12:03:16.554 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for workItemByteArray
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.PropertyBinder - Building property workItemByteArray
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - processing fk mappings (*ToOne and JoinedSubclass)
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing extends queue
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
12:03:16.554 [pool-1-thread-1] DEBUG o.hibernate.cfg.CollectionSecondPass - Second pass for collection: org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.CollectionBinder - Binding a OneToMany: org.drools.persistence.processinstance.WorkItemInfo.variables through a foreign key
12:03:16.554 [pool-1-thread-1] INFO  o.h.cfg.annotations.CollectionBinder - Mapping collection: org.drools.persistence.processinstance.WorkItemInfo.variables -> VariableInstanceInfo
12:03:16.554 [pool-1-thread-1] DEBUG o.hibernate.cfg.CollectionSecondPass - Mapped collection key: workItemId, index: name, one-to-many: org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo
12:03:16.554 [pool-1-thread-1] DEBUG o.hibernate.cfg.CollectionSecondPass - Second pass for collection: org.drools.persistence.processinstance.ProcessInstanceInfo.variables
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.CollectionBinder - Binding a OneToMany: org.drools.persistence.processinstance.ProcessInstanceInfo.variables through a foreign key
12:03:16.554 [pool-1-thread-1] INFO  o.h.cfg.annotations.CollectionBinder - Mapping collection: org.drools.persistence.processinstance.ProcessInstanceInfo.variables -> VariableInstanceInfo
12:03:16.554 [pool-1-thread-1] DEBUG o.hibernate.cfg.CollectionSecondPass - Mapped collection key: processInstanceId, index: name, one-to-many: org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo
12:03:16.554 [pool-1-thread-1] DEBUG o.hibernate.cfg.CollectionSecondPass - Second pass for collection: org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.annotations.CollectionBinder - Binding a collection of element: org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes
12:03:16.554 [pool-1-thread-1] DEBUG o.h.c.annotations.SimpleValueBinder - building SimpleValue for null
12:03:16.554 [pool-1-thread-1] DEBUG o.hibernate.cfg.CollectionSecondPass - Mapped collection key: InstanceId, element: element
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing association property references
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.WorkItemInfo
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.554 [pool-1-thread-1] INFO  o.h.cfg.AnnotationConfiguration - Hibernate Validator not found: ignoring
12:03:16.554 [pool-1-thread-1] DEBUG o.h.ejb.event.CallbackResolver - Adding update as PreUpdate callback for entity org.drools.persistence.processinstance.WorkItemInfo.
12:03:16.554 [pool-1-thread-1] DEBUG o.h.ejb.event.CallbackResolver - Adding update as PrePersist callback for entity org.drools.persistence.session.SessionInfo.
12:03:16.554 [pool-1-thread-1] DEBUG o.h.ejb.event.CallbackResolver - Adding update as PreUpdate callback for entity org.drools.persistence.session.SessionInfo.
12:03:16.554 [pool-1-thread-1] DEBUG o.h.ejb.event.CallbackResolver - Adding update as PreUpdate callback for entity org.drools.persistence.processinstance.ProcessInstanceInfo.
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.ejb.util.NamingHelper - No JNDI name configured for binding Ejb3Configuration
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Validator not present in classpath, ignoring event listener registration
12:03:16.554 [pool-1-thread-1] DEBUG o.h.c.s.HibernateSearchEventListenerRegister - Search not present in classpath, ignoring event listener registration.
12:03:16.554 [pool-1-thread-1] INFO  o.h.c.s.HibernateSearchEventListenerRegister - Unable to find org.hibernate.search.event.FullTextIndexEventListener on the classpath. Hibernate Search is not enabled.
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - Preparing to build session factory with filters : {}
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Execute first pass mapping processing
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process hbm files
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process annotated classes
12:03:16.554 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - processing fk mappings (*ToOne and JoinedSubclass)
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing extends queue
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing association property references
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.WorkItemInfo
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.554 [pool-1-thread-1] INFO  o.h.c.ConnectionProviderFactory - Initializing connection provider: org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider
12:03:16.554 [pool-1-thread-1] INFO  o.h.e.c.InjectedDataSourceConnectionProvider - Using provided datasource
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - RDBMS: H2, version: 1.3.148 (2010-12-12)
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - JDBC driver: H2 JDBC Driver, version: 1.3.148 (2010-12-12)
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.dialect.Dialect - Using dialect: org.hibernate.dialect.H2Dialect
12:03:16.554 [pool-1-thread-1] INFO  o.h.t.TransactionFactoryFactory - Transaction strategy: org.hibernate.transaction.JDBCTransactionFactory
12:03:16.554 [pool-1-thread-1] INFO  o.h.t.TransactionManagerLookupFactory - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Automatic flush during beforeCompletion(): disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Automatic session close at end of transaction: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - JDBC batch size: 15
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - JDBC batch updates for versioned data: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Scrollable result sets: enabled
12:03:16.554 [pool-1-thread-1] DEBUG org.hibernate.cfg.SettingsFactory - Wrap result sets: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - JDBC3 getGeneratedKeys(): enabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Connection release mode: auto
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Maximum outer join fetch depth: 3
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Default batch fetch size: 1
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Generate SQL with comments: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Order SQL updates by primary key: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Order SQL inserts for batching: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
12:03:16.554 [pool-1-thread-1] INFO  o.h.h.ast.ASTQueryTranslatorFactory - Using ASTQueryTranslatorFactory
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Query language substitutions: {}
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - JPA-QL strict compliance: enabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Second-level cache: enabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Query cache: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Cache region factory : org.hibernate.cache.impl.NoCachingRegionFactory
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Optimize cache for minimal puts: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Structured second-level cache entries: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Statistics: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Deleted entity synthetic identifier rollback: disabled
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Default entity-mode: pojo
12:03:16.554 [pool-1-thread-1] INFO  org.hibernate.cfg.SettingsFactory - Named query checking : enabled
12:03:16.569 [pool-1-thread-1] INFO  o.hibernate.impl.SessionFactoryImpl - building session factory
12:03:16.569 [pool-1-thread-1] DEBUG o.hibernate.impl.SessionFactoryImpl - Session factory constructed with filter configurations : {}
12:03:16.569 [pool-1-thread-1] DEBUG o.hibernate.impl.SessionFactoryImpl - instantiating session factory with properties: {java.runtime.name=Java(TM) SE Runtime Environment, sun.boot.library.path=C:\Java\jdk1.6.0_20\jre\bin, java.vm.version=16.3-b01, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=;, java.vm.name=Java HotSpot(TM) 64-Bit Server VM, file.encoding.pkg=sun.io, user.country=US, sun.java.launcher=SUN_STANDARD, sun.os.patch.level=, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\testSource\platform\process-flow\process-flow-service, java.runtime.version=1.6.0_20-b02, hibernate.ejb.discard_pc_on_close=false, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, basedir=C:\testSource\platform\process-flow\process-flow-service, java.endorsed.dirs=C:\Java\jdk1.6.0_20\jre\lib\endorsed, os.arch=amd64, surefire.real.class.path=C:\testSource\platform\process-flow\process-flow-service\target\surefire\surefirebooter8889461808117535765.jar, hibernate.connection.autocommit=true, java.io.tmpdir=C:\Users\brad\AppData\Local\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows 7, sun.jnu.encoding=Cp1252, java.library.path=C:\Java\jdk1.6.0_20\jre\bin;.;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Program Files\Common Files\Microsoft Shared\Windows Live;C:\Program Files (x86)\Common Files\Microsoft Shared\Windows Live;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\ThinkPad\Bluetooth Software\;C:\Program Files\ThinkPad\Bluetooth Software\syswow64;C:\Program Files\Intel\WiFi\bin\;C:\Program Files\Common Files\Intel\WirelessCommon\;C:\Program Files (x86)\Common Files\Lenovo;C:\Program Files (x86)\Common Files\Ulead Systems\MPEG;C:\Program Files (x86)\Lenovo\Access Connections\;C:\Program Files\Common Files\Lenovo;C:\Program Files (x86)\Lenovo\Client Security Solution;C:\Program Files\Lenovo\Client Security Solution;C:\Program Files\TortoiseSVN\bin;C:\maven\apache-maven-3.0.2\bin;C:\Ant\apache-ant-1.8.1\bin;C:\XEmacs\XEmacs-21.4.22\i586-pc-win32;C:\UnxUtils\usr\local\wbin;C:\Program Files (x86)\Windows Live\Shared;C:\ProtoC;C:\Program Files (x86)\QuickTime\QTSystem\, surefire.test.class.path=C:\testSource\platform\process-flow\process-flow-service\target\test-classes;C:\testSource\platform\process-flow\process-flow-service\target\classes;C:\Users\brad\.m2\repository\com\proferi\platform\process\process-flow-protocol\0.0.1-SNAPSHOT\process-flow-protocol-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\google\guava\guava\r08\guava-r08.jar;C:\Users\brad\.m2\repository\com\google\protobuf\protobuf-java\2.3.0\protobuf-java-2.3.0.jar;C:\Users\brad\.m2\repository\com\proferi\platform\platformtypes\0.0.1-SNAPSHOT\platformtypes-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\proferi\platform\platformcore\0.0.1-SNAPSHOT\platformcore-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-java-network\1.0.1-SNAPSHOT\norbert-java-network-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-java-cluster\1.0.1-SNAPSHOT\norbert-java-cluster-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-cluster\1.0.1-SNAPSHOT\norbert-cluster-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\org\apache\hadoop\zookeeper\3.3.0\zookeeper-3.3.0.jar;C:\Users\brad\.m2\repository\jline\jline\0.9.94\jline-0.9.94.jar;C:\Users\brad\.m2\repository\junit\junit\4.8.2\junit-4.8.2.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-network\1.0.1-SNAPSHOT\norbert-network-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\org\jboss\netty\netty\3.2.1.Final\netty-3.2.1.Final.jar;C:\Users\brad\.m2\repository\org\scala-lang\scala-library\2.8.1\scala-library-2.8.1.jar;C:\Users\brad\.m2\repository\org\springframework\spring-context\3.0.5.RELEASE\spring-context-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-expression\3.0.5.RELEASE\spring-expression-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-asm\3.0.5.RELEASE\spring-asm-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\javax\jms\jms\1.1\jms-1.1.jar;C:\Users\brad\.m2\repository\org\apache\commons\commons-daemon\1.0.5\commons-daemon-1.0.5.jar;C:\Users\brad\.m2\repository\com\proferi\platform\utilities\0.0.1-SNAPSHOT\utilities-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\fasterxml\uuid\java-uuid-generator\3.1.0\java-uuid-generator-3.1.0.jar;C:\Users\brad\.m2\repository\org\slf4j\slf4j-api\1.6.1\slf4j-api-1.6.1.jar;C:\Users\brad\.m2\repository\ch\qos\logback\logback-core\0.9.28\logback-core-0.9.28.jar;C:\Users\brad\.m2\repository\ch\qos\logback\logback-classic\0.9.28\logback-classic-0.9.28.jar;C:\Users\brad\.m2\repository\org\slf4j\jcl-over-slf4j\1.6.1\jcl-over-slf4j-1.6.1.jar;C:\Users\brad\.m2\repository\org\slf4j\log4j-over-slf4j\1.6.1\log4j-over-slf4j-1.6.1.jar;C:\Users\brad\.m2\repository\com\proferi\platform\appmodel\0.0.1-SNAPSHOT\appmodel-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\commons-lang\commons-lang\2.5\commons-lang-2.5.jar;C:\Users\brad\.m2\repository\org\springframework\spring-beans\3.0.5.RELEASE\spring-beans-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\xmlunit\xmlunit\1.3\xmlunit-1.3.jar;C:\Users\brad\.m2\repository\org\codehaus\btm\btm\1.3.2\btm-1.3.2.jar;C:\Users\brad\.m2\repository\org\apache\geronimo\specs\geronimo-jms_1.1_spec\1.0.1\geronimo-jms_1.1_spec-1.0.1.jar;C:\Users\brad\.m2\repository\org\apache\geronimo\specs\geronimo-jta_1.0.1B_spec\1.0.1\geronimo-jta_1.0.1B_spec-1.0.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-core\5.1.1\drools-core-5.1.1.jar;C:\Users\brad\.m2\repository\org\mvel\mvel2\2.0.16\mvel2-2.0.16.jar;C:\Users\brad\.m2\repository\org\drools\drools-api\5.1.1\drools-api-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-persistence-jpa\5.1.1\drools-persistence-jpa-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-compiler\5.1.1\drools-compiler-5.1.1.jar;C:\Users\brad\.m2\repository\org\antlr\antlr-runtime\3.1.3\antlr-runtime-3.1.3.jar;C:\Users\brad\.m2\repository\org\eclipse\jdt\core\compiler\ecj\3.5.1\ecj-3.5.1.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-entitymanager\3.4.0.GA\hibernate-entitymanager-3.4.0.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\ejb3-persistence\1.0.2.GA\ejb3-persistence-1.0.2.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-annotations\3.4.0.GA\hibernate-annotations-3.4.0.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-commons-annotations\3.1.0.GA\hibernate-commons-annotations-3.1.0.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-core\3.3.0.SP1\hibernate-core-3.3.0.SP1.jar;C:\Users\brad\.m2\repository\antlr\antlr\2.7.6\antlr-2.7.6.jar;C:\Users\brad\.m2\repository\commons-collections\commons-collections\3.1\commons-collections-3.1.jar;C:\Users\brad\.m2\repository\javax\persistence\persistence-api\1.0\persistence-api-1.0.jar;C:\Users\brad\.m2\repository\dom4j\dom4j\1.6.1\dom4j-1.6.1.jar;C:\Users\brad\.m2\repository\xml-apis\xml-apis\1.0.b2\xml-apis-1.0.b2.jar;C:\Users\brad\.m2\repository\javax\transaction\jta\1.1\jta-1.1.jar;C:\Users\brad\.m2\repository\com\h2database\h2\1.3.148\h2-1.3.148.jar;C:\Users\brad\.m2\repository\javassist\javassist\3.4.GA\javassist-3.4.GA.jar;C:\Users\brad\.m2\repository\org\drools\drools-bpmn2\5.1.1\drools-bpmn2-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-spring\5.1.1\drools-spring-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-decisiontables\5.1.1\drools-decisiontables-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-templates\5.1.1\drools-templates-5.1.1.jar;C:\Users\brad\.m2\repository\net\sourceforge\jexcelapi\jxl\2.6.10\jxl-2.6.10.jar;C:\Users\brad\.m2\repository\org\drools\drools-grid-core\5.1.1\drools-grid-core-5.1.1.jar;C:\Users\brad\.m2\repository\org\apache\mina\mina-core\2.0.0-M6\mina-core-2.0.0-M6.jar;C:\Users\brad\.m2\repository\org\springframework\spring-core\3.0.5.RELEASE\spring-core-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\log4j\log4j\1.2.9\log4j-1.2.9.jar;C:\Users\brad\.m2\repository\org\hornetq\hornetq-core\2.1.2.Final\hornetq-core-2.1.2.Final.jar;C:\Users\brad\.m2\repository\org\hornetq\hornetq-jms\2.1.2.Final\hornetq-jms-2.1.2.Final.jar;C:\Users\brad\.m2\repository\org\springframework\spring-jms\3.0.5.RELEASE\spring-jms-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\aopalliance\aopalliance\1.0\aopalliance-1.0.jar;C:\Users\brad\.m2\repository\org\springframework\spring-aop\3.0.5.RELEASE\spring-aop-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-tx\3.0.5.RELEASE\spring-tx-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-jdbc\3.0.5.RELEASE\spring-jdbc-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-orm\3.0.5.RELEASE\spring-orm-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-test\3.0.5.RELEASE\spring-test-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\postgresql\postgresql\9.0-801.jdbc4\postgresql-9.0-801.jdbc4.jar;C:\Users\brad\.m2\repository\commons-dbcp\commons-dbcp\1.4\commons-dbcp-1.4.jar;C:\Users\brad\.m2\repository\commons-pool\commons-pool\1.5.4\commons-pool-1.5.4.jar;, java.specification.name=Java Platform API Specification, java.class.version=50.0, sun.management.compiler=HotSpot 64-Bit Server Compiler, hibernate.transaction.factory_class=org.hibernate.transaction.JDBCTransactionFactory, os.version=6.1, user.home=C:\Users\brad, user.timezone=America/Los_Angeles, java.awt.printerjob=sun.awt.windows.WPrinterJob, hibernate.connection.release_mode=auto, java.specification.version=1.6, file.encoding=Cp1252, user.name=brad, java.class.path=C:\testSource\platform\process-flow\process-flow-service\target\test-classes;C:\testSource\platform\process-flow\process-flow-service\target\classes;C:\Users\brad\.m2\repository\com\proferi\platform\process\process-flow-protocol\0.0.1-SNAPSHOT\process-flow-protocol-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\google\guava\guava\r08\guava-r08.jar;C:\Users\brad\.m2\repository\com\google\protobuf\protobuf-java\2.3.0\protobuf-java-2.3.0.jar;C:\Users\brad\.m2\repository\com\proferi\platform\platformtypes\0.0.1-SNAPSHOT\platformtypes-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\proferi\platform\platformcore\0.0.1-SNAPSHOT\platformcore-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-java-network\1.0.1-SNAPSHOT\norbert-java-network-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-java-cluster\1.0.1-SNAPSHOT\norbert-java-cluster-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-cluster\1.0.1-SNAPSHOT\norbert-cluster-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\org\apache\hadoop\zookeeper\3.3.0\zookeeper-3.3.0.jar;C:\Users\brad\.m2\repository\jline\jline\0.9.94\jline-0.9.94.jar;C:\Users\brad\.m2\repository\junit\junit\4.8.2\junit-4.8.2.jar;C:\Users\brad\.m2\repository\com\linkedin\norbert\norbert-network\1.0.1-SNAPSHOT\norbert-network-1.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\org\jboss\netty\netty\3.2.1.Final\netty-3.2.1.Final.jar;C:\Users\brad\.m2\repository\org\scala-lang\scala-library\2.8.1\scala-library-2.8.1.jar;C:\Users\brad\.m2\repository\org\springframework\spring-context\3.0.5.RELEASE\spring-context-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-expression\3.0.5.RELEASE\spring-expression-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-asm\3.0.5.RELEASE\spring-asm-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\javax\jms\jms\1.1\jms-1.1.jar;C:\Users\brad\.m2\repository\org\apache\commons\commons-daemon\1.0.5\commons-daemon-1.0.5.jar;C:\Users\brad\.m2\repository\com\proferi\platform\utilities\0.0.1-SNAPSHOT\utilities-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\com\fasterxml\uuid\java-uuid-generator\3.1.0\java-uuid-generator-3.1.0.jar;C:\Users\brad\.m2\repository\org\slf4j\slf4j-api\1.6.1\slf4j-api-1.6.1.jar;C:\Users\brad\.m2\repository\ch\qos\logback\logback-core\0.9.28\logback-core-0.9.28.jar;C:\Users\brad\.m2\repository\ch\qos\logback\logback-classic\0.9.28\logback-classic-0.9.28.jar;C:\Users\brad\.m2\repository\org\slf4j\jcl-over-slf4j\1.6.1\jcl-over-slf4j-1.6.1.jar;C:\Users\brad\.m2\repository\org\slf4j\log4j-over-slf4j\1.6.1\log4j-over-slf4j-1.6.1.jar;C:\Users\brad\.m2\repository\com\proferi\platform\appmodel\0.0.1-SNAPSHOT\appmodel-0.0.1-SNAPSHOT.jar;C:\Users\brad\.m2\repository\commons-lang\commons-lang\2.5\commons-lang-2.5.jar;C:\Users\brad\.m2\repository\org\springframework\spring-beans\3.0.5.RELEASE\spring-beans-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\xmlunit\xmlunit\1.3\xmlunit-1.3.jar;C:\Users\brad\.m2\repository\org\codehaus\btm\btm\1.3.2\btm-1.3.2.jar;C:\Users\brad\.m2\repository\org\apache\geronimo\specs\geronimo-jms_1.1_spec\1.0.1\geronimo-jms_1.1_spec-1.0.1.jar;C:\Users\brad\.m2\repository\org\apache\geronimo\specs\geronimo-jta_1.0.1B_spec\1.0.1\geronimo-jta_1.0.1B_spec-1.0.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-core\5.1.1\drools-core-5.1.1.jar;C:\Users\brad\.m2\repository\org\mvel\mvel2\2.0.16\mvel2-2.0.16.jar;C:\Users\brad\.m2\repository\org\drools\drools-api\5.1.1\drools-api-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-persistence-jpa\5.1.1\drools-persistence-jpa-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-compiler\5.1.1\drools-compiler-5.1.1.jar;C:\Users\brad\.m2\repository\org\antlr\antlr-runtime\3.1.3\antlr-runtime-3.1.3.jar;C:\Users\brad\.m2\repository\org\eclipse\jdt\core\compiler\ecj\3.5.1\ecj-3.5.1.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-entitymanager\3.4.0.GA\hibernate-entitymanager-3.4.0.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\ejb3-persistence\1.0.2.GA\ejb3-persistence-1.0.2.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-annotations\3.4.0.GA\hibernate-annotations-3.4.0.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-commons-annotations\3.1.0.GA\hibernate-commons-annotations-3.1.0.GA.jar;C:\Users\brad\.m2\repository\org\hibernate\hibernate-core\3.3.0.SP1\hibernate-core-3.3.0.SP1.jar;C:\Users\brad\.m2\repository\antlr\antlr\2.7.6\antlr-2.7.6.jar;C:\Users\brad\.m2\repository\commons-collections\commons-collections\3.1\commons-collections-3.1.jar;C:\Users\brad\.m2\repository\javax\persistence\persistence-api\1.0\persistence-api-1.0.jar;C:\Users\brad\.m2\repository\dom4j\dom4j\1.6.1\dom4j-1.6.1.jar;C:\Users\brad\.m2\repository\xml-apis\xml-apis\1.0.b2\xml-apis-1.0.b2.jar;C:\Users\brad\.m2\repository\javax\transaction\jta\1.1\jta-1.1.jar;C:\Users\brad\.m2\repository\com\h2database\h2\1.3.148\h2-1.3.148.jar;C:\Users\brad\.m2\repository\javassist\javassist\3.4.GA\javassist-3.4.GA.jar;C:\Users\brad\.m2\repository\org\drools\drools-bpmn2\5.1.1\drools-bpmn2-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-spring\5.1.1\drools-spring-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-decisiontables\5.1.1\drools-decisiontables-5.1.1.jar;C:\Users\brad\.m2\repository\org\drools\drools-templates\5.1.1\drools-templates-5.1.1.jar;C:\Users\brad\.m2\repository\net\sourceforge\jexcelapi\jxl\2.6.10\jxl-2.6.10.jar;C:\Users\brad\.m2\repository\org\drools\drools-grid-core\5.1.1\drools-grid-core-5.1.1.jar;C:\Users\brad\.m2\repository\org\apache\mina\mina-core\2.0.0-M6\mina-core-2.0.0-M6.jar;C:\Users\brad\.m2\repository\org\springframework\spring-core\3.0.5.RELEASE\spring-core-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\log4j\log4j\1.2.9\log4j-1.2.9.jar;C:\Users\brad\.m2\repository\org\hornetq\hornetq-core\2.1.2.Final\hornetq-core-2.1.2.Final.jar;C:\Users\brad\.m2\repository\org\hornetq\hornetq-jms\2.1.2.Final\hornetq-jms-2.1.2.Final.jar;C:\Users\brad\.m2\repository\org\springframework\spring-jms\3.0.5.RELEASE\spring-jms-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\aopalliance\aopalliance\1.0\aopalliance-1.0.jar;C:\Users\brad\.m2\repository\org\springframework\spring-aop\3.0.5.RELEASE\spring-aop-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-tx\3.0.5.RELEASE\spring-tx-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-jdbc\3.0.5.RELEASE\spring-jdbc-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-orm\3.0.5.RELEASE\spring-orm-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\org\springframework\spring-test\3.0.5.RELEASE\spring-test-3.0.5.RELEASE.jar;C:\Users\brad\.m2\repository\postgresql\postgresql\9.0-801.jdbc4\postgresql-9.0-801.jdbc4.jar;C:\Users\brad\.m2\repository\commons-dbcp\commons-dbcp\1.4\commons-dbcp-1.4.jar;C:\Users\brad\.m2\repository\commons-pool\commons-pool\1.5.4\commons-pool-1.5.4.jar;, hibernate.bytecode.use_reflection_optimizer=false, hibernate.use_identifier_rollback=false, java.vm.specification.version=1.0, sun.arch.data.model=64, java.home=C:\Java\jdk1.6.0_20\jre, hibernate.dialect=org.hibernate.dialect.H2Dialect, java.specification.vendor=Sun Microsystems Inc., user.language=en, awt.toolkit=sun.awt.windows.WToolkit, java.vm.info=mixed mode, java.version=1.6.0_20, hibernate.transaction.flush_before_completion=false, java.ext.dirs=C:\Java\jdk1.6.0_20\jre\lib\ext;C:\Windows\Sun\Java\lib\ext, sun.boot.class.path=C:\Java\jdk1.6.0_20\jre\lib\endorsed\activation.jar;C:\Java\jdk1.6.0_20\jre\lib\endorsed\jaxb-api.jar;C:\Java\jdk1.6.0_20\jre\lib\endorsed\jaxws-api.jar;C:\Java\jdk1.6.0_20\jre\lib\endorsed\stax-api.jar;C:\Java\jdk1.6.0_20\jre\lib\resources.jar;C:\Java\jdk1.6.0_20\jre\lib\rt.jar;C:\Java\jdk1.6.0_20\jre\lib\sunrsasign.jar;C:\Java\jdk1.6.0_20\jre\lib\jsse.jar;C:\Java\jdk1.6.0_20\jre\lib\jce.jar;C:\Java\jdk1.6.0_20\jre\lib\charsets.jar;C:\Java\jdk1.6.0_20\jre\classes, java.vendor=Sun Microsystems Inc., localRepository=C:\Users\brad\.m2\repository, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, hibernate.connection.provider_class=org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider, hibernate.hbm2ddl.auto=create, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, hibernate.query.jpaql_strict_compliance=true, sun.desktop=windows, hibernate.max_fetch_depth=3, sun.cpu.isalist=amd64}
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister - Static SQL for entity: org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Version select: select id from VariableInstanceInfo where id =?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Snapshot select: select jpapersist_.id, jpapersist_.name as name90_, jpapersist_.persister as persister90_, jpapersist_.processInstanceId as processI5_90_, jpapersist_.workItemId as workItemId90_, jpapersist_.entityClass as entityCl7_90_, jpapersist_.entityId as entityId90_ from VariableInstanceInfo jpapersist_ where jpapersist_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Insert 0: insert into VariableInstanceInfo (name, persister, processInstanceId, workItemId, entityClass, entityId, TYPE, id) values (?, ?, ?, ?, ?, ?, 'JPAPersistedVariable', ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Update 0: update VariableInstanceInfo set name=?, persister=?, processInstanceId=?, workItemId=?, entityClass=?, entityId=? where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Delete 0: delete from VariableInstanceInfo where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Identity insert: insert into VariableInstanceInfo (id, name, persister, processInstanceId, workItemId, entityClass, entityId, TYPE) values (null, ?, ?, ?, ?, ?, ?, 'JPAPersistedVariable')
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister - Static SQL for entity: org.drools.persistence.processinstance.WorkItemInfo
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Version select: select OPTLOCK from WorkItemInfo where workItemId =?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Snapshot select: select workitemin_.workItemId, workitemin_.creationDate as creation2_91_, workitemin_.externalVariables as external3_91_, workitemin_.name as name91_, workitemin_.processInstanceId as processI5_91_, workitemin_.state as state91_, workitemin_.OPTLOCK as OPTLOCK91_, workitemin_.workItemByteArray as workItem8_91_ from WorkItemInfo workitemin_ where workitemin_.workItemId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Insert 0: insert into WorkItemInfo (creationDate, externalVariables, name, processInstanceId, state, OPTLOCK, workItemByteArray, workItemId) values (?, ?, ?, ?, ?, ?, ?, ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Update 0: update WorkItemInfo set creationDate=?, externalVariables=?, name=?, processInstanceId=?, state=?, OPTLOCK=?, workItemByteArray=? where workItemId=? and OPTLOCK=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Delete 0: delete from WorkItemInfo where workItemId=? and OPTLOCK=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Identity insert: insert into WorkItemInfo (workItemId, creationDate, externalVariables, name, processInstanceId, state, OPTLOCK, workItemByteArray) values (null, ?, ?, ?, ?, ?, ?, ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister - Static SQL for entity: org.drools.persistence.session.SessionInfo
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Version select: select OPTLOCK from SessionInfo where id =?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Snapshot select: select sessioninf_.id, sessioninf_.lastModificationDate as lastModi2_88_, sessioninf_.rulesByteArray as rulesByt3_88_, sessioninf_.startDate as startDate88_, sessioninf_.OPTLOCK as OPTLOCK88_ from SessionInfo sessioninf_ where sessioninf_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Insert 0: insert into SessionInfo (lastModificationDate, rulesByteArray, startDate, OPTLOCK, id) values (?, ?, ?, ?, ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Update 0: update SessionInfo set lastModificationDate=?, rulesByteArray=?, startDate=?, OPTLOCK=? where id=? and OPTLOCK=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Delete 0: delete from SessionInfo where id=? and OPTLOCK=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Identity insert: insert into SessionInfo (id, lastModificationDate, rulesByteArray, startDate, OPTLOCK) values (null, ?, ?, ?, ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister - Static SQL for entity: org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Version select: select id from VariableInstanceInfo where id =?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Snapshot select: select serializab_.id, serializab_.name as name90_, serializab_.persister as persister90_, serializab_.processInstanceId as processI5_90_, serializab_.workItemId as workItemId90_, serializab_.content as content90_ from VariableInstanceInfo serializab_ where serializab_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Insert 0: insert into VariableInstanceInfo (name, persister, processInstanceId, workItemId, content, TYPE, id) values (?, ?, ?, ?, ?, 'SerializablePersistedVariable', ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Update 0: update VariableInstanceInfo set name=?, persister=?, processInstanceId=?, workItemId=?, content=? where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Delete 0: delete from VariableInstanceInfo where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Identity insert: insert into VariableInstanceInfo (id, name, persister, processInstanceId, workItemId, content, TYPE) values (null, ?, ?, ?, ?, ?, 'SerializablePersistedVariable')
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister - Static SQL for entity: org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Version select: select id from VariableInstanceInfo where id =?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Snapshot select: select variablein_.id, variablein_.name as name90_, variablein_.persister as persister90_, variablein_.processInstanceId as processI5_90_, variablein_.workItemId as workItemId90_ from VariableInstanceInfo variablein_ where variablein_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Insert 0: insert into VariableInstanceInfo (name, persister, processInstanceId, workItemId, TYPE, id) values (?, ?, ?, ?, 'GEN', ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Update 0: update VariableInstanceInfo set name=?, persister=?, processInstanceId=?, workItemId=? where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Delete 0: delete from VariableInstanceInfo where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Identity insert: insert into VariableInstanceInfo (id, name, persister, processInstanceId, workItemId, TYPE) values (null, ?, ?, ?, ?, 'GEN')
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister - Static SQL for entity: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Version select: select OPTLOCK from ProcessInstanceInfo where InstanceId =?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Snapshot select: select processins_.InstanceId, processins_.externalVariables as external2_89_, processins_.lastModificationDate as lastModi3_89_, processins_.lastReadDate as lastRead4_89_, processins_.processId as processId89_, processins_.processInstanceByteArray as processI6_89_, processins_.startDate as startDate89_, processins_.state as state89_, processins_.OPTLOCK as OPTLOCK89_ from ProcessInstanceInfo processins_ where processins_.InstanceId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Insert 0: insert into ProcessInstanceInfo (externalVariables, lastModificationDate, lastReadDate, processId, processInstanceByteArray, startDate, state, OPTLOCK, InstanceId) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Update 0: update ProcessInstanceInfo set externalVariables=?, lastModificationDate=?, lastReadDate=?, processId=?, processInstanceByteArray=?, startDate=?, state=?, OPTLOCK=? where InstanceId=? and OPTLOCK=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Delete 0: delete from ProcessInstanceInfo where InstanceId=? and OPTLOCK=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.entity.AbstractEntityPersister -  Identity insert: insert into ProcessInstanceInfo (InstanceId, externalVariables, lastModificationDate, lastReadDate, processId, processInstanceByteArray, startDate, state, OPTLOCK) values (null, ?, ?, ?, ?, ?, ?, ?, ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - Static SQL for collection: org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  Row insert: insert into EventTypes (InstanceId, element) values (?, ?)
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  Row update: update EventTypes set element=? where InstanceId=? and element=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  Row delete: delete from EventTypes where InstanceId=? and element=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  One-shot delete: delete from EventTypes where InstanceId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - Static SQL for collection: org.drools.persistence.processinstance.ProcessInstanceInfo.variables
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  Row insert: update VariableInstanceInfo set processInstanceId=? where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  Row delete: update VariableInstanceInfo set processInstanceId=null where processInstanceId=? and id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  One-shot delete: update VariableInstanceInfo set processInstanceId=null where processInstanceId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - Static SQL for collection: org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  Row insert: update VariableInstanceInfo set workItemId=? where id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  Row delete: update VariableInstanceInfo set workItemId=null where workItemId=? and id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister -  One-shot delete: update VariableInstanceInfo set workItemId=null where workItemId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable: select jpapersist0_.id as id90_0_, jpapersist0_.name as name90_0_, jpapersist0_.persister as persister90_0_, jpapersist0_.processInstanceId as processI5_90_0_, jpapersist0_.workItemId as workItemId90_0_, jpapersist0_.entityClass as entityCl7_90_0_, jpapersist0_.entityId as entityId90_0_ from VariableInstanceInfo jpapersist0_ where jpapersist0_.id=? and jpapersist0_.TYPE='JPAPersistedVariable'
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable: select jpapersist0_.id as id90_0_, jpapersist0_.name as name90_0_, jpapersist0_.persister as persister90_0_, jpapersist0_.processInstanceId as processI5_90_0_, jpapersist0_.workItemId as workItemId90_0_, jpapersist0_.entityClass as entityCl7_90_0_, jpapersist0_.entityId as entityId90_0_ from VariableInstanceInfo jpapersist0_ where jpapersist0_.id=? and jpapersist0_.TYPE='JPAPersistedVariable'
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable: select jpapersist0_.id as id90_0_, jpapersist0_.name as name90_0_, jpapersist0_.persister as persister90_0_, jpapersist0_.processInstanceId as processI5_90_0_, jpapersist0_.workItemId as workItemId90_0_, jpapersist0_.entityClass as entityCl7_90_0_, jpapersist0_.entityId as entityId90_0_ from VariableInstanceInfo jpapersist0_ where jpapersist0_.id=? and jpapersist0_.TYPE='JPAPersistedVariable' for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable: select jpapersist0_.id as id90_0_, jpapersist0_.name as name90_0_, jpapersist0_.persister as persister90_0_, jpapersist0_.processInstanceId as processI5_90_0_, jpapersist0_.workItemId as workItemId90_0_, jpapersist0_.entityClass as entityCl7_90_0_, jpapersist0_.entityId as entityId90_0_ from VariableInstanceInfo jpapersist0_ where jpapersist0_.id=? and jpapersist0_.TYPE='JPAPersistedVariable' for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable: select jpapersist0_.id as id90_0_, jpapersist0_.name as name90_0_, jpapersist0_.persister as persister90_0_, jpapersist0_.processInstanceId as processI5_90_0_, jpapersist0_.workItemId as workItemId90_0_, jpapersist0_.entityClass as entityCl7_90_0_, jpapersist0_.entityId as entityId90_0_ from VariableInstanceInfo jpapersist0_ where jpapersist0_.id=? and jpapersist0_.TYPE='JPAPersistedVariable' for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable: select jpapersist0_.id as id90_0_, jpapersist0_.name as name90_0_, jpapersist0_.persister as persister90_0_, jpapersist0_.processInstanceId as processI5_90_0_, jpapersist0_.workItemId as workItemId90_0_, jpapersist0_.entityClass as entityCl7_90_0_, jpapersist0_.entityId as entityId90_0_ from VariableInstanceInfo jpapersist0_ where jpapersist0_.id=? and jpapersist0_.TYPE='JPAPersistedVariable'
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity org.drools.persistence.processinstance.variabletypes.JPAPersistedVariable: select jpapersist0_.id as id90_0_, jpapersist0_.name as name90_0_, jpapersist0_.persister as persister90_0_, jpapersist0_.processInstanceId as processI5_90_0_, jpapersist0_.workItemId as workItemId90_0_, jpapersist0_.entityClass as entityCl7_90_0_, jpapersist0_.entityId as entityId90_0_ from VariableInstanceInfo jpapersist0_ where jpapersist0_.id=? and jpapersist0_.TYPE='JPAPersistedVariable'
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.WorkItemInfo: select workitemin0_.workItemId as workItemId91_0_, workitemin0_.creationDate as creation2_91_0_, workitemin0_.externalVariables as external3_91_0_, workitemin0_.name as name91_0_, workitemin0_.processInstanceId as processI5_91_0_, workitemin0_.state as state91_0_, workitemin0_.OPTLOCK as OPTLOCK91_0_, workitemin0_.workItemByteArray as workItem8_91_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.WorkItemInfo: select workitemin0_.workItemId as workItemId91_0_, workitemin0_.creationDate as creation2_91_0_, workitemin0_.externalVariables as external3_91_0_, workitemin0_.name as name91_0_, workitemin0_.processInstanceId as processI5_91_0_, workitemin0_.state as state91_0_, workitemin0_.OPTLOCK as OPTLOCK91_0_, workitemin0_.workItemByteArray as workItem8_91_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.WorkItemInfo: select workitemin0_.workItemId as workItemId91_0_, workitemin0_.creationDate as creation2_91_0_, workitemin0_.externalVariables as external3_91_0_, workitemin0_.name as name91_0_, workitemin0_.processInstanceId as processI5_91_0_, workitemin0_.state as state91_0_, workitemin0_.OPTLOCK as OPTLOCK91_0_, workitemin0_.workItemByteArray as workItem8_91_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=? for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.WorkItemInfo: select workitemin0_.workItemId as workItemId91_0_, workitemin0_.creationDate as creation2_91_0_, workitemin0_.externalVariables as external3_91_0_, workitemin0_.name as name91_0_, workitemin0_.processInstanceId as processI5_91_0_, workitemin0_.state as state91_0_, workitemin0_.OPTLOCK as OPTLOCK91_0_, workitemin0_.workItemByteArray as workItem8_91_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=? for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.WorkItemInfo: select workitemin0_.workItemId as workItemId91_0_, workitemin0_.creationDate as creation2_91_0_, workitemin0_.externalVariables as external3_91_0_, workitemin0_.name as name91_0_, workitemin0_.processInstanceId as processI5_91_0_, workitemin0_.state as state91_0_, workitemin0_.OPTLOCK as OPTLOCK91_0_, workitemin0_.workItemByteArray as workItem8_91_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=? for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity org.drools.persistence.processinstance.WorkItemInfo: select workitemin0_.workItemId as workItemId91_1_, workitemin0_.creationDate as creation2_91_1_, workitemin0_.externalVariables as external3_91_1_, workitemin0_.name as name91_1_, workitemin0_.processInstanceId as processI5_91_1_, workitemin0_.state as state91_1_, workitemin0_.OPTLOCK as OPTLOCK91_1_, workitemin0_.workItemByteArray as workItem8_91_1_, variables1_.workItemId as workItemId3_, variables1_.id as id3_, variables1_.name as formula16_3_, variables1_.id as id90_0_, variables1_.name as name90_0_, variables1_.persister as persister90_0_, variables1_.processInstanceId as processI5_90_0_, variables1_.workItemId as workItemId90_0_, variables1_.entityClass as entityCl7_90_0_, variables1_.entityId as entityId90_0_, variables1_.content as content90_0_, variables1_.TYPE as TYPE90_0_ from WorkItemInfo workitemin0_ left outer join VariableInstanceInfo variables1_ on workitemin0_.workItemId=variables1_.workItemId where workitemin0_.workItemId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity org.drools.persistence.processinstance.WorkItemInfo: select workitemin0_.workItemId as workItemId91_1_, workitemin0_.creationDate as creation2_91_1_, workitemin0_.externalVariables as external3_91_1_, workitemin0_.name as name91_1_, workitemin0_.processInstanceId as processI5_91_1_, workitemin0_.state as state91_1_, workitemin0_.OPTLOCK as OPTLOCK91_1_, workitemin0_.workItemByteArray as workItem8_91_1_, variables1_.workItemId as workItemId3_, variables1_.id as id3_, variables1_.name as formula16_3_, variables1_.id as id90_0_, variables1_.name as name90_0_, variables1_.persister as persister90_0_, variables1_.processInstanceId as processI5_90_0_, variables1_.workItemId as workItemId90_0_, variables1_.entityClass as entityCl7_90_0_, variables1_.entityId as entityId90_0_, variables1_.content as content90_0_, variables1_.TYPE as TYPE90_0_ from WorkItemInfo workitemin0_ left outer join VariableInstanceInfo variables1_ on workitemin0_.workItemId=variables1_.workItemId where workitemin0_.workItemId=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.session.SessionInfo: select sessioninf0_.id as id88_0_, sessioninf0_.lastModificationDate as lastModi2_88_0_, sessioninf0_.rulesByteArray as rulesByt3_88_0_, sessioninf0_.startDate as startDate88_0_, sessioninf0_.OPTLOCK as OPTLOCK88_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.session.SessionInfo: select sessioninf0_.id as id88_0_, sessioninf0_.lastModificationDate as lastModi2_88_0_, sessioninf0_.rulesByteArray as rulesByt3_88_0_, sessioninf0_.startDate as startDate88_0_, sessioninf0_.OPTLOCK as OPTLOCK88_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.session.SessionInfo: select sessioninf0_.id as id88_0_, sessioninf0_.lastModificationDate as lastModi2_88_0_, sessioninf0_.rulesByteArray as rulesByt3_88_0_, sessioninf0_.startDate as startDate88_0_, sessioninf0_.OPTLOCK as OPTLOCK88_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=? for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.session.SessionInfo: select sessioninf0_.id as id88_0_, sessioninf0_.lastModificationDate as lastModi2_88_0_, sessioninf0_.rulesByteArray as rulesByt3_88_0_, sessioninf0_.startDate as startDate88_0_, sessioninf0_.OPTLOCK as OPTLOCK88_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=? for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.session.SessionInfo: select sessioninf0_.id as id88_0_, sessioninf0_.lastModificationDate as lastModi2_88_0_, sessioninf0_.rulesByteArray as rulesByt3_88_0_, sessioninf0_.startDate as startDate88_0_, sessioninf0_.OPTLOCK as OPTLOCK88_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=? for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity org.drools.persistence.session.SessionInfo: select sessioninf0_.id as id88_0_, sessioninf0_.lastModificationDate as lastModi2_88_0_, sessioninf0_.rulesByteArray as rulesByt3_88_0_, sessioninf0_.startDate as startDate88_0_, sessioninf0_.OPTLOCK as OPTLOCK88_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity org.drools.persistence.session.SessionInfo: select sessioninf0_.id as id88_0_, sessioninf0_.lastModificationDate as lastModi2_88_0_, sessioninf0_.rulesByteArray as rulesByt3_88_0_, sessioninf0_.startDate as startDate88_0_, sessioninf0_.OPTLOCK as OPTLOCK88_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=?
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable: select serializab0_.id as id90_0_, serializab0_.name as name90_0_, serializab0_.persister as persister90_0_, serializab0_.processInstanceId as processI5_90_0_, serializab0_.workItemId as workItemId90_0_, serializab0_.content as content90_0_ from VariableInstanceInfo serializab0_ where serializab0_.id=? and serializab0_.TYPE='SerializablePersistedVariable'
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable: select serializab0_.id as id90_0_, serializab0_.name as name90_0_, serializab0_.persister as persister90_0_, serializab0_.processInstanceId as processI5_90_0_, serializab0_.workItemId as workItemId90_0_, serializab0_.content as content90_0_ from VariableInstanceInfo serializab0_ where serializab0_.id=? and serializab0_.TYPE='SerializablePersistedVariable'
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable: select serializab0_.id as id90_0_, serializab0_.name as name90_0_, serializab0_.persister as persister90_0_, serializab0_.processInstanceId as processI5_90_0_, serializab0_.workItemId as workItemId90_0_, serializab0_.content as content90_0_ from VariableInstanceInfo serializab0_ where serializab0_.id=? and serializab0_.TYPE='SerializablePersistedVariable' for update
12:03:16.569 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable: select serializab0_.id as id90_0_, serializab0_.name as name90_0_, serializab0_.persister as persister90_0_, serializab0_.processInstanceId as processI5_90_0_, serializab0_.workItemId as workItemId90_0_, serializab0_.content as content90_0_ from VariableInstanceInfo serializab0_ where serializab0_.id=? and serializab0_.TYPE='SerializablePersistedVariable' for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable: select serializab0_.id as id90_0_, serializab0_.name as name90_0_, serializab0_.persister as persister90_0_, serializab0_.processInstanceId as processI5_90_0_, serializab0_.workItemId as workItemId90_0_, serializab0_.content as content90_0_ from VariableInstanceInfo serializab0_ where serializab0_.id=? and serializab0_.TYPE='SerializablePersistedVariable' for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable: select serializab0_.id as id90_0_, serializab0_.name as name90_0_, serializab0_.persister as persister90_0_, serializab0_.processInstanceId as processI5_90_0_, serializab0_.workItemId as workItemId90_0_, serializab0_.content as content90_0_ from VariableInstanceInfo serializab0_ where serializab0_.id=? and serializab0_.TYPE='SerializablePersistedVariable'
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity org.drools.persistence.processinstance.variabletypes.SerializablePersistedVariable: select serializab0_.id as id90_0_, serializab0_.name as name90_0_, serializab0_.persister as persister90_0_, serializab0_.processInstanceId as processI5_90_0_, serializab0_.workItemId as workItemId90_0_, serializab0_.content as content90_0_ from VariableInstanceInfo serializab0_ where serializab0_.id=? and serializab0_.TYPE='SerializablePersistedVariable'
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo: select variablein0_.id as id90_0_, variablein0_.name as name90_0_, variablein0_.persister as persister90_0_, variablein0_.processInstanceId as processI5_90_0_, variablein0_.workItemId as workItemId90_0_, variablein0_.entityClass as entityCl7_90_0_, variablein0_.entityId as entityId90_0_, variablein0_.content as content90_0_, variablein0_.TYPE as TYPE90_0_ from VariableInstanceInfo variablein0_ where variablein0_.id=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo: select variablein0_.id as id90_0_, variablein0_.name as name90_0_, variablein0_.persister as persister90_0_, variablein0_.processInstanceId as processI5_90_0_, variablein0_.workItemId as workItemId90_0_, variablein0_.entityClass as entityCl7_90_0_, variablein0_.entityId as entityId90_0_, variablein0_.content as content90_0_, variablein0_.TYPE as TYPE90_0_ from VariableInstanceInfo variablein0_ where variablein0_.id=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo: select variablein0_.id as id90_0_, variablein0_.name as name90_0_, variablein0_.persister as persister90_0_, variablein0_.processInstanceId as processI5_90_0_, variablein0_.workItemId as workItemId90_0_, variablein0_.entityClass as entityCl7_90_0_, variablein0_.entityId as entityId90_0_, variablein0_.content as content90_0_, variablein0_.TYPE as TYPE90_0_ from VariableInstanceInfo variablein0_ where variablein0_.id=? for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo: select variablein0_.id as id90_0_, variablein0_.name as name90_0_, variablein0_.persister as persister90_0_, variablein0_.processInstanceId as processI5_90_0_, variablein0_.workItemId as workItemId90_0_, variablein0_.entityClass as entityCl7_90_0_, variablein0_.entityId as entityId90_0_, variablein0_.content as content90_0_, variablein0_.TYPE as TYPE90_0_ from VariableInstanceInfo variablein0_ where variablein0_.id=? for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo: select variablein0_.id as id90_0_, variablein0_.name as name90_0_, variablein0_.persister as persister90_0_, variablein0_.processInstanceId as processI5_90_0_, variablein0_.workItemId as workItemId90_0_, variablein0_.entityClass as entityCl7_90_0_, variablein0_.entityId as entityId90_0_, variablein0_.content as content90_0_, variablein0_.TYPE as TYPE90_0_ from VariableInstanceInfo variablein0_ where variablein0_.id=? for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo: select variablein0_.id as id90_0_, variablein0_.name as name90_0_, variablein0_.persister as persister90_0_, variablein0_.processInstanceId as processI5_90_0_, variablein0_.workItemId as workItemId90_0_, variablein0_.entityClass as entityCl7_90_0_, variablein0_.entityId as entityId90_0_, variablein0_.content as content90_0_, variablein0_.TYPE as TYPE90_0_ from VariableInstanceInfo variablein0_ where variablein0_.id=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity org.drools.persistence.processinstance.variabletypes.VariableInstanceInfo: select variablein0_.id as id90_0_, variablein0_.name as name90_0_, variablein0_.persister as persister90_0_, variablein0_.processInstanceId as processI5_90_0_, variablein0_.workItemId as workItemId90_0_, variablein0_.entityClass as entityCl7_90_0_, variablein0_.entityId as entityId90_0_, variablein0_.content as content90_0_, variablein0_.TYPE as TYPE90_0_ from VariableInstanceInfo variablein0_ where variablein0_.id=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.ProcessInstanceInfo: select processins0_.InstanceId as InstanceId89_0_, processins0_.externalVariables as external2_89_0_, processins0_.lastModificationDate as lastModi3_89_0_, processins0_.lastReadDate as lastRead4_89_0_, processins0_.processId as processId89_0_, processins0_.processInstanceByteArray as processI6_89_0_, processins0_.startDate as startDate89_0_, processins0_.state as state89_0_, processins0_.OPTLOCK as OPTLOCK89_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.ProcessInstanceInfo: select processins0_.InstanceId as InstanceId89_0_, processins0_.externalVariables as external2_89_0_, processins0_.lastModificationDate as lastModi3_89_0_, processins0_.lastReadDate as lastRead4_89_0_, processins0_.processId as processId89_0_, processins0_.processInstanceByteArray as processI6_89_0_, processins0_.startDate as startDate89_0_, processins0_.state as state89_0_, processins0_.OPTLOCK as OPTLOCK89_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.ProcessInstanceInfo: select processins0_.InstanceId as InstanceId89_0_, processins0_.externalVariables as external2_89_0_, processins0_.lastModificationDate as lastModi3_89_0_, processins0_.lastReadDate as lastRead4_89_0_, processins0_.processId as processId89_0_, processins0_.processInstanceByteArray as processI6_89_0_, processins0_.startDate as startDate89_0_, processins0_.state as state89_0_, processins0_.OPTLOCK as OPTLOCK89_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=? for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.ProcessInstanceInfo: select processins0_.InstanceId as InstanceId89_0_, processins0_.externalVariables as external2_89_0_, processins0_.lastModificationDate as lastModi3_89_0_, processins0_.lastReadDate as lastRead4_89_0_, processins0_.processId as processId89_0_, processins0_.processInstanceByteArray as processI6_89_0_, processins0_.startDate as startDate89_0_, processins0_.state as state89_0_, processins0_.OPTLOCK as OPTLOCK89_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=? for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for entity org.drools.persistence.processinstance.ProcessInstanceInfo: select processins0_.InstanceId as InstanceId89_0_, processins0_.externalVariables as external2_89_0_, processins0_.lastModificationDate as lastModi3_89_0_, processins0_.lastReadDate as lastRead4_89_0_, processins0_.processId as processId89_0_, processins0_.processInstanceByteArray as processI6_89_0_, processins0_.startDate as startDate89_0_, processins0_.state as state89_0_, processins0_.OPTLOCK as OPTLOCK89_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=? for update
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity org.drools.persistence.processinstance.ProcessInstanceInfo: select processins0_.InstanceId as InstanceId89_1_, processins0_.externalVariables as external2_89_1_, processins0_.lastModificationDate as lastModi3_89_1_, processins0_.lastReadDate as lastRead4_89_1_, processins0_.processId as processId89_1_, processins0_.processInstanceByteArray as processI6_89_1_, processins0_.startDate as startDate89_1_, processins0_.state as state89_1_, processins0_.OPTLOCK as OPTLOCK89_1_, variables1_.processInstanceId as processI5_3_, variables1_.id as id3_, variables1_.name as formula17_3_, variables1_.id as id90_0_, variables1_.name as name90_0_, variables1_.persister as persister90_0_, variables1_.processInstanceId as processI5_90_0_, variables1_.workItemId as workItemId90_0_, variables1_.entityClass as entityCl7_90_0_, variables1_.entityId as entityId90_0_, variables1_.content as content90_0_, variables1_.TYPE as TYPE90_0_ from ProcessInstanceInfo processins0_ left outer join VariableInstanceInfo variables1_ on processins0_.InstanceId=variables1_.processInstanceId where processins0_.InstanceId=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity org.drools.persistence.processinstance.ProcessInstanceInfo: select processins0_.InstanceId as InstanceId89_1_, processins0_.externalVariables as external2_89_1_, processins0_.lastModificationDate as lastModi3_89_1_, processins0_.lastReadDate as lastRead4_89_1_, processins0_.processId as processId89_1_, processins0_.processInstanceByteArray as processI6_89_1_, processins0_.startDate as startDate89_1_, processins0_.state as state89_1_, processins0_.OPTLOCK as OPTLOCK89_1_, variables1_.processInstanceId as processI5_3_, variables1_.id as id3_, variables1_.name as formula17_3_, variables1_.id as id90_0_, variables1_.name as name90_0_, variables1_.persister as persister90_0_, variables1_.processInstanceId as processI5_90_0_, variables1_.workItemId as workItemId90_0_, variables1_.entityClass as entityCl7_90_0_, variables1_.entityId as entityId90_0_, variables1_.content as content90_0_, variables1_.TYPE as TYPE90_0_ from ProcessInstanceInfo processins0_ left outer join VariableInstanceInfo variables1_ on processins0_.InstanceId=variables1_.processInstanceId where processins0_.InstanceId=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.l.c.BasicCollectionLoader - Static select for collection org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes: select eventtypes0_.InstanceId as InstanceId0_, eventtypes0_.element as element0_ from EventTypes eventtypes0_ where eventtypes0_.InstanceId=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.l.collection.OneToManyLoader - Static select for one-to-many org.drools.persistence.processinstance.ProcessInstanceInfo.variables: select variables0_.processInstanceId as processI5_1_, variables0_.id as id1_, variables0_.name as formula17_1_, variables0_.id as id90_0_, variables0_.name as name90_0_, variables0_.persister as persister90_0_, variables0_.processInstanceId as processI5_90_0_, variables0_.workItemId as workItemId90_0_, variables0_.entityClass as entityCl7_90_0_, variables0_.entityId as entityId90_0_, variables0_.content as content90_0_, variables0_.TYPE as TYPE90_0_ from VariableInstanceInfo variables0_ where variables0_.processInstanceId=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.l.collection.OneToManyLoader - Static select for one-to-many org.drools.persistence.processinstance.WorkItemInfo.variables: select variables0_.workItemId as workItemId1_, variables0_.id as id1_, variables0_.name as formula16_1_, variables0_.id as id90_0_, variables0_.name as name90_0_, variables0_.persister as persister90_0_, variables0_.processInstanceId as processI5_90_0_, variables0_.workItemId as workItemId90_0_, variables0_.entityClass as entityCl7_90_0_, variables0_.entityId as entityId90_0_, variables0_.content as content90_0_, variables0_.TYPE as TYPE90_0_ from VariableInstanceInfo variables0_ where variables0_.workItemId=?
12:03:16.585 [pool-1-thread-1] DEBUG o.h.impl.SessionFactoryObjectFactory - registered: 8aa080de2f0d4c38012f0d4c53690008 (unnamed)
12:03:16.585 [pool-1-thread-1] INFO  o.h.impl.SessionFactoryObjectFactory - Not binding factory to JNDI, no JNDI name configured
12:03:16.585 [pool-1-thread-1] DEBUG o.hibernate.impl.SessionFactoryImpl - instantiated session factory
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Execute first pass mapping processing
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process hbm files
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process annotated classes
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - processing fk mappings (*ToOne and JoinedSubclass)
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing extends queue
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing association property references
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.WorkItemInfo
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Execute first pass mapping processing
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process hbm files
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - Process annotated classes
12:03:16.585 [pool-1-thread-1] DEBUG o.h.cfg.AnnotationConfiguration - processing fk mappings (*ToOne and JoinedSubclass)
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing extends queue
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing association property references
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.WorkItemInfo
12:03:16.585 [pool-1-thread-1] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: org.drools.persistence.processinstance.ProcessInstanceInfo
12:03:16.585 [pool-1-thread-1] INFO  o.h.tool.hbm2ddl.SchemaExport - Running hbm2ddl schema export
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - import file not found: /import.sql
12:03:16.585 [pool-1-thread-1] INFO  o.h.tool.hbm2ddl.SchemaExport - exporting generated schema to database
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - alter table EventTypes drop constraint FKB0E5621F82849DA
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - alter table VariableInstanceInfo drop constraint FK7BE49B9FF8EDED9
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - alter table VariableInstanceInfo drop constraint FK7BE49B9F85916989
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - drop table EventTypes if exists
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - drop table ProcessInstanceInfo if exists
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - drop table SessionInfo if exists
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - drop table VariableInstanceInfo if exists
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - drop table WorkItemInfo if exists
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - create table EventTypes (InstanceId bigint not null, element varchar(255))
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - create table ProcessInstanceInfo (InstanceId bigint generated by default as identity, externalVariables bit not null, lastModificationDate timestamp, lastReadDate timestamp, processId varchar(255), processInstanceByteArray blob, startDate timestamp, state integer not null, OPTLOCK integer, primary key (InstanceId))
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - create table SessionInfo (id integer generated by default as identity, lastModificationDate timestamp, rulesByteArray blob, startDate timestamp, OPTLOCK integer, primary key (id))
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - create table VariableInstanceInfo (TYPE varchar(50) not null, id bigint generated by default as identity, name varchar(255), persister varchar(255), processInstanceId bigint, workItemId bigint, entityClass varchar(255), entityId binary(255), content blob, primary key (id))
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - create table WorkItemInfo (workItemId bigint generated by default as identity, creationDate timestamp, externalVariables bit not null, name varchar(255), processInstanceId bigint not null, state bigint not null, OPTLOCK integer, workItemByteArray blob, primary key (workItemId))
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - alter table EventTypes add constraint FKB0E5621F82849DA foreign key (InstanceId) references ProcessInstanceInfo
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - alter table VariableInstanceInfo add constraint FK7BE49B9FF8EDED9 foreign key (workItemId) references WorkItemInfo
12:03:16.585 [pool-1-thread-1] DEBUG o.h.tool.hbm2ddl.SchemaExport - alter table VariableInstanceInfo add constraint FK7BE49B9F85916989 foreign key (processInstanceId) references ProcessInstanceInfo
12:03:16.585 [pool-1-thread-1] INFO  o.h.tool.hbm2ddl.SchemaExport - schema export complete
12:03:16.585 [pool-1-thread-1] DEBUG o.hibernate.impl.SessionFactoryImpl - Checking 1 named HQL queries
12:03:16.585 [pool-1-thread-1] DEBUG o.hibernate.impl.SessionFactoryImpl - Checking named query: ProcessInstancesWaitingForEvent
12:03:16.585 [pool-1-thread-1] DEBUG o.h.hql.ast.QueryTranslatorImpl - parse() - HQL: select processInstanceInfo.processInstanceId from org.drools.persistence.processinstance.ProcessInstanceInfo processInstanceInfo where :type in elements(processInstanceInfo.eventTypes)
12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.AST - --- HQL AST ---
 \-[QUERY] 'query'
    +-[SELECT_FROM] 'SELECT_FROM'
    |  +-[FROM] 'from'
    |  |  \-[RANGE] 'RANGE'
    |  |     +-[DOT] '.'
    |  |     |  +-[DOT] '.'
    |  |     |  |  +-[DOT] '.'
    |  |     |  |  |  +-[DOT] '.'
    |  |     |  |  |  |  +-[IDENT] 'org'
    |  |     |  |  |  |  \-[IDENT] 'drools'
    |  |     |  |  |  \-[IDENT] 'persistence'
    |  |     |  |  \-[IDENT] 'processinstance'
    |  |     |  \-[IDENT] 'ProcessInstanceInfo'
    |  |     \-[ALIAS] 'processInstanceInfo'
    |  \-[SELECT] 'select'
    |     \-[DOT] '.'
    |        +-[IDENT] 'processInstanceInfo'
    |        \-[IDENT] 'processInstanceId'
    \-[WHERE] 'where'
       \-[IN] 'in'
          +-[COLON] ':'
          |  \-[IDENT] 'type'
          \-[IN_LIST] 'inList'
             \-[ELEMENTS] 'elements'
                \-[DOT] '.'
                   +-[IDENT] 'processInstanceInfo'
                   \-[IDENT] 'eventTypes'

12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.ErrorCounter - throwQueryException() : no errors
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.antlr.HqlSqlBaseWalker - select << begin [level=1, statement=select]
12:03:16.601 [pool-1-thread-1] DEBUG o.hibernate.hql.ast.tree.FromElement - FromClause{level=1} :  org.drools.persistence.processinstance.ProcessInstanceInfo (processInstanceInfo) -> processins0_
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.ast.tree.FromReferenceNode - Resolved :  processInstanceInfo -> processins0_.InstanceId
12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.tree.DotNode - getDataType() : processInstanceId -> org.hibernate.type.LongType@1c04ec59
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.ast.tree.FromReferenceNode - Resolved :  processInstanceInfo.processInstanceId -> processins0_.InstanceId
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.ast.tree.FromReferenceNode - Resolved :  processInstanceInfo -> processins0_.InstanceId
12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.tree.DotNode - getDataType() : eventTypes -> org.hibernate.type.SetType(org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes)
12:03:16.601 [pool-1-thread-1] DEBUG o.hibernate.hql.ast.tree.FromElement - FromClause{level=1} :  null (no alias) -> eventtypes1_
12:03:16.601 [pool-1-thread-1] DEBUG o.hibernate.hql.ast.tree.FromClause - addCollectionJoinFromElementByPath() : processInstanceInfo.eventTypes -> EventTypes
12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.tree.DotNode - dereferenceCollection() : Created new FROM element for processInstanceInfo.eventTypes : EventTypes eventtypes1_
12:03:16.601 [pool-1-thread-1] DEBUG o.hibernate.hql.ast.tree.MethodNode - Creating elements for processInstanceInfo.eventTypes[].elements
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.ast.tree.FromElementType - toColumns(eventtypes1_,elements) : subquery = select eventtypes1_.element from EventTypes eventtypes1_ where processins0_.InstanceId=eventtypes1_.InstanceId
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.antlr.HqlSqlBaseWalker - select : finishing up [level=1, statement=select]
12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.HqlSqlWalker - processQuery() :  ( SELECT ( {select clause} ( processins0_.InstanceId processins0_.InstanceId processInstanceId ) ) ( FromClause{level=1}   ) ( where ( in ? ( inList ( select eventtypes1_.element from EventTypes eventtypes1_ where processins0_.InstanceId=eventtypes1_.InstanceId ( . processins0_.InstanceId eventTypes ) ) ) ) ) )
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.ast.util.JoinProcessor - Using FROM fragment [ProcessInstanceInfo processins0_]
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.antlr.HqlSqlBaseWalker - select >> end [level=1, statement=select]
12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.AST - --- SQL AST ---
 \-[SELECT] QueryNode: 'SELECT'  querySpaces (ProcessInstanceInfo,EventTypes)
    +-[SELECT_CLAUSE] SelectClause: '{select clause}'
    |  +-[DOT] DotNode: 'processins0_.InstanceId' {propertyName=processInstanceId,dereferenceType=4,propertyPath=processInstanceId,path=processInstanceInfo.processInstanceId,tableAlias=processins0_,className=org.drools.persistence.processinstance.ProcessInstanceInfo,classAlias=processInstanceInfo}
    |  |  +-[ALIAS_REF] IdentNode: 'processins0_.InstanceId' {alias=processInstanceInfo, className=org.drools.persistence.processinstance.ProcessInstanceInfo, tableAlias=processins0_}
    |  |  \-[IDENT] IdentNode: 'processInstanceId' {originalText=processInstanceId}
    |  \-[SELECT_COLUMNS] SqlNode: ' as col_0_0_'
    +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=2, fromElementByClassAlias=[processInstanceInfo], fromElementByTableAlias=[processins0_, eventtypes1_], fromElementsByPath=[], collectionJoinFromElementsByPath=[processInstanceInfo.eventTypes], impliedElements=[]}
    |  +-[FROM_FRAGMENT] FromElement: 'ProcessInstanceInfo processins0_' FromElement{explicit,collection join,not a fetch join,fetch non-lazy properties,classAlias=processInstanceInfo,role=null,tableName=ProcessInstanceInfo,tableAlias=processins0_,origin=null,colums={,className=org.drools.persistence.processinstance.ProcessInstanceInfo}}
    |  \-[FROM_FRAGMENT] ImpliedFromElement: '' ImpliedFromElement{implied,collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes,tableName={none},tableAlias=eventtypes1_,origin=ProcessInstanceInfo processins0_,colums={,className=null}}
    \-[WHERE] SqlNode: 'where'
       \-[IN] InLogicOperatorNode: 'in'
          +-[NAMED_PARAM] ParameterNode: '?' {name=type, expectedType=null}
          \-[IN_LIST] SqlNode: 'inList'
             \-[SQL_TOKEN] CollectionFunction: 'select eventtypes1_.element from EventTypes eventtypes1_ where processins0_.InstanceId=eventtypes1_.InstanceId' {method=elements,selectColumns=[select eventtypes1_.element from EventTypes eventtypes1_ where processins0_.InstanceId=eventtypes1_.InstanceId],fromElement=eventtypes1_}
                \-[DOT] DotNode: '.' {propertyName=eventTypes,dereferenceType=3,propertyPath=eventTypes,path=processInstanceInfo.eventTypes,tableAlias=eventtypes1_,className=null,classAlias=null}
                   +-[ALIAS_REF] IdentNode: 'processins0_.InstanceId' {alias=processInstanceInfo, className=org.drools.persistence.processinstance.ProcessInstanceInfo, tableAlias=processins0_}
                   \-[IDENT] IdentNode: 'eventTypes' {originalText=eventTypes}

12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.ErrorCounter - throwQueryException() : no errors
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.ast.QueryTranslatorImpl - HQL: select processInstanceInfo.processInstanceId from org.drools.persistence.processinstance.ProcessInstanceInfo processInstanceInfo where :type in elements(processInstanceInfo.eventTypes)
12:03:16.601 [pool-1-thread-1] DEBUG o.h.hql.ast.QueryTranslatorImpl - SQL: select processins0_.InstanceId as col_0_0_ from ProcessInstanceInfo processins0_ where ? in (select eventtypes1_.element from EventTypes eventtypes1_ where processins0_.InstanceId=eventtypes1_.InstanceId)
12:03:16.601 [pool-1-thread-1] DEBUG org.hibernate.hql.ast.ErrorCounter - throwQueryException() : no errors
START MY CODE
12:03:16.601 [pool-1-thread-1] DEBUG o.hibernate.impl.SessionFactoryImpl - Checking 0 named SQL queries
12:03:16.616 [pool-1-thread-1] DEBUG c.p.process.drools.ProxyBuilder - Approval constraint [StepApproval( approved == true, sliceValue == "NO_SLICE", approvalStepNodeId == "4e04c435-8f06-4bcc-b8a4-e91744575c2b" )]
12:03:16.616 [pool-1-thread-1] DEBUG c.p.process.drools.DroolsFlowAdapter - Created new StepNodeInstance [step-1 Step] with ID [06ea0b5c-6ad0-43a7-8d53-4a0304c094a0]
12:03:16.616 [pool-1-thread-1] DEBUG c.p.process.drools.DroolsFlowAdapter - Created new ImpliedStepNodeInstance [step-1 Approval] with ID [35fdffaf-ed0c-45dc-86ac-9a8a7cd851f5]
12:03:16.616 [pool-1-thread-1] DEBUG c.p.process.drools.DroolsFlowAdapter - Starting process flow [flow-1] instance [29de16c7-8803-4c57-bcc5-5cf9afeddb14]
12:03:16.694 [pool-1-thread-1] DEBUG o.d.p.s.SingleSessionCommandService - Instantiating  DroolsSpringTransactionManager
12:03:16.694 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981966
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@6ba22e1]
12:03:16.694 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.def.AbstractSaveEventListener - executing identity-insert immediately
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.SQL - insert into SessionInfo (id, lastModificationDate, rulesByteArray, startDate, OPTLOCK) values (null, ?, ?, ?, ?)
12:03:16.694 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding null to parameter: 1
12:03:16.694 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 3
12:03:16.694 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 4
12:03:16.694 [pool-1-thread-1] DEBUG o.h.id.IdentifierGeneratorFactory - Natively generated identity: 1
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7e6808080808080808080808080808080808080808080808080808080808080808080808d8084cdc1c9ce808081808d8084cdc1c9ce8081808180808080808081808180818081808a80808081808080808081808080818180818081808180808080808080808081, lastModificationDate=null, version=0}
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.694 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@1722fe15]
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981966
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.694 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@7a572090]
12:03:16.694 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.694 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.694 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
12:03:16.694 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7e6808080808080808080808080808080808080808080808080808080808080808080808d8084cdc1c9ce808081808d8084cdc1c9ce8081808180808080808081808180818081808a80808081808080808081808080818180818081808180808080808080808081, lastModificationDate=null, version=0}
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.694 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.694 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@6e1b0caf]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981967
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@31ddeda2]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7e6808080808080808080808080808080808080808080808080808080808080808080808d8084cdc1c9ce808081808d8084cdc1c9ce8081808180808080808081808180818081808a80808081808080808081808080818180818081808180808080808080808081, lastModificationDate=null, version=0}
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@611c4041]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981967
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@5be9d36]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7e6808080808080808080808080808080808080808080808080808080808080808080808d8084cdc1c9ce808081808d8084cdc1c9ce8081808180808080808081808180818081808a80808081808080808081808080818180818081808180808080808080808081, lastModificationDate=null, version=0}
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@2543472c]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981967
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@63f5acd0]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.def.AbstractSaveEventListener - executing identity-insert immediately
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - insert into ProcessInstanceInfo (InstanceId, externalVariables, lastModificationDate, lastReadDate, processId, processInstanceByteArray, startDate, state, OPTLOCK) values (null, ?, ?, ?, ?, ?, ?, ?, ?)
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - binding 'false' to parameter: 1
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding null to parameter: 2
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding null to parameter: 3
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.StringType - binding 'd9686dff_98a5_4670_bdfa_fd03f2c8ed42' to parameter: 4
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 6
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 7
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 8
12:03:16.710 [pool-1-thread-1] DEBUG o.h.id.IdentifierGeneratorFactory - Natively generated identity: 1
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Starting process [flow-1]...
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [flow-1 Start]...
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [flow-1 Start]...
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Reject Join]...
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Reject Join]...
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Step]...
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.def.AbstractSaveEventListener - executing identity-insert immediately
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - insert into WorkItemInfo (workItemId, creationDate, externalVariables, name, processInstanceId, state, OPTLOCK, workItemByteArray) values (null, ?, ?, ?, ?, ?, ?, ?)
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 1
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - binding 'false' to parameter: 2
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.StringType - binding 'Step' to parameter: 3
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 4
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '0' to parameter: 5
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 6
12:03:16.710 [pool-1-thread-1] DEBUG o.h.id.IdentifierGeneratorFactory - Natively generated identity: 1
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.StepWorkItemHandler - Executing Step with Drools work item ID [1] for Step with instance UUID [06ea0b5c-6ad0-43a7-8d53-4a0304c094a0] in slice [NO_SLICE]
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Step] triggered.
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Reject Join] left.
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Reject Join] triggered.
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Node [flow-1 Start] left.
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Node [flow-1 Start] triggered.
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Process [flow-1] started.
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7d8808080808080808080808080808080808080808080808080808080808080808082808d8084cdc1c9ce808081808d8084cdc1c9ce808180818080808080808180818081808180818180818081808180808080808080808081, lastModificationDate=2011-03-31 12:03:16, version=1}
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - update SessionInfo set lastModificationDate=?, rulesByteArray=?, startDate=?, OPTLOCK=? where id=? and OPTLOCK=?
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 1
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 3
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 4
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 5
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 6
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes#1], was: [<unreferenced>] (initialized)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.ProcessInstanceInfo.variables#1], was: [<unreferenced>] (initialized)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.WorkItemInfo.variables#1], was: [<unreferenced>] (initialized)
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 2 updates, 0 deletions to 2 objects
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 3 (re)creations, 0 updates, 0 removals to 3 collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.processinstance.WorkItemInfo{creationDate=2011-03-31 12:03:16, processInstanceId=1, name=Step, workItemByteArray=2c6d8085f7a4808080808080808180808080808080818084d3f4e5f080808080808080838084d5d5c9c4f3f2808eeae1f6e1aef5f4e9ecaed5d5c9c43c19837718ed05af828082ca808cece5e1f3f4d3e9e7c2e9f4f3ca808bedeff3f4d3e9e7c2e9f4f3f8f038246997c4d7dcabce8444b50f86cb4cf78c808ae9eef3f4e1eee3e5c9e4f3f180fe80800dd3ca8384401420866a8bdcea50c327f78c808af3ece9e3e5d6e1ecf5e5f48088cecfdfd3ccc9c3c5, state=0, externalVariables=false, workItemId=1, version=0, variables=[]}
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.processinstance.ProcessInstanceInfo{startDate=2011-03-31 12:03:16, processInstanceId=1, processId=d9686dff_98a5_4670_bdfa_fd03f2c8ed42, processInstanceByteArray=2c6d8085f7df8088d2f5ece5c6eceff7808080808080808180a4e4b9b6b8b6e4e6e6dfb9b8e1b5dfb4b6b7b0dfe2e4e6e1dfe6e4b0b3e6b2e3b8e5e4b4b2808080818080808080808083808080818095f0f2efe3e5f3f3c6eceff7c9eef3f4e1eee3e5c9e4f3f2808eeae1f6e1aef5f4e9ecaed5d5c9c43c19837718ed05af828082ca808cece5e1f3f4d3e9e7c2e9f4f3ca808bedeff3f4d3e9e7c2e9f4f3f8f03c45dc792f6d5b94a95e96470883ccd7f7aa808080808092808080808080808280808080808080838095808080808080808180808080808180808080, state=1, lastModificationDate=2011-03-31 12:03:16, lastReadDate=2011-03-31 12:03:16, externalVariables=false, eventTypes=[], version=1, variables=[]}
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - update ProcessInstanceInfo set externalVariables=?, lastModificationDate=?, lastReadDate=?, processId=?, processInstanceByteArray=?, startDate=?, state=?, OPTLOCK=? where InstanceId=? and OPTLOCK=?
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - binding 'false' to parameter: 1
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 2
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 3
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.StringType - binding 'd9686dff_98a5_4670_bdfa_fd03f2c8ed42' to parameter: 4
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 6
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 7
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 8
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 9
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 10
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - update WorkItemInfo set creationDate=?, externalVariables=?, name=?, processInstanceId=?, state=?, OPTLOCK=?, workItemByteArray=? where workItemId=? and OPTLOCK=?
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 1
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - binding 'false' to parameter: 2
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.StringType - binding 'Step' to parameter: 3
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 4
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '0' to parameter: 5
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 6
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 8
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 9
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - Inserting collection: [org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes#1]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - collection was empty
12:03:16.710 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - Inserting collection: [org.drools.persistence.processinstance.ProcessInstanceInfo.variables#1]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - collection was empty
12:03:16.710 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - Inserting collection: [org.drools.persistence.processinstance.WorkItemInfo.variables#1]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - collection was empty
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@4dbed348]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981967
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@2b2143d8]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7d8808080808080808080808080808080808080808080808080808080808080808082808d8084cdc1c9ce808081808d8084cdc1c9ce808180818080808080808180818081808180818180818081808180808080808080808081, lastModificationDate=2011-03-31 12:03:16, version=1}
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.710 [pool-1-thread-1] DEBUG c.p.process.drools.DroolsFlowAdapter - Completing step instance [step-1 Step] with workItemId [1]
12:03:16.710 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@14ed3007]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981967
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@5fec264c]
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - loading entity: [org.drools.persistence.processinstance.WorkItemInfo#1]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - select workitemin0_.workItemId as workItemId91_0_, workitemin0_.creationDate as creation2_91_0_, workitemin0_.externalVariables as external3_91_0_, workitemin0_.name as name91_0_, workitemin0_.processInstanceId as processI5_91_0_, workitemin0_.state as state91_0_, workitemin0_.OPTLOCK as OPTLOCK91_0_, workitemin0_.workItemByteArray as workItem8_91_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=?
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 1
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - result row: EntityKey[org.drools.persistence.processinstance.WorkItemInfo#1]
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: creation2_91_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - returning 'false' as column: external3_91_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.StringType - returning 'Step' as column: name91_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - returning '1' as column: processI5_91_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - returning '0' as column: state91_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - returning '1' as column: OPTLOCK91_0_
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [org.drools.persistence.processinstance.WorkItemInfo#1]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [org.drools.persistence.processinstance.WorkItemInfo#1]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - done entity load
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - loading entity: [org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - select processins0_.InstanceId as InstanceId89_0_, processins0_.externalVariables as external2_89_0_, processins0_.lastModificationDate as lastModi3_89_0_, processins0_.lastReadDate as lastRead4_89_0_, processins0_.processId as processId89_0_, processins0_.processInstanceByteArray as processI6_89_0_, processins0_.startDate as startDate89_0_, processins0_.state as state89_0_, processins0_.OPTLOCK as OPTLOCK89_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=?
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 1
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - result row: EntityKey[org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - returning 'false' as column: external2_89_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: lastModi3_89_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: lastRead4_89_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.StringType - returning 'd9686dff_98a5_4670_bdfa_fd03f2c8ed42' as column: processId89_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: startDate89_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - returning '1' as column: state89_0_
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - returning '1' as column: OPTLOCK89_0_
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - done entity load
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Step]...
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Approval]...
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.def.AbstractSaveEventListener - executing identity-insert immediately
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - insert into WorkItemInfo (workItemId, creationDate, externalVariables, name, processInstanceId, state, OPTLOCK, workItemByteArray) values (null, ?, ?, ?, ?, ?, ?, ?)
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 1
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - binding 'false' to parameter: 2
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.StringType - binding 'Step' to parameter: 3
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 4
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '0' to parameter: 5
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 6
12:03:16.710 [pool-1-thread-1] DEBUG o.h.id.IdentifierGeneratorFactory - Natively generated identity: 2
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.StepWorkItemHandler - Executing Step with Drools work item ID [2] for Step with instance UUID [35fdffaf-ed0c-45dc-86ac-9a8a7cd851f5] in slice [NO_SLICE]
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval] triggered.
12:03:16.710 [pool-1-thread-1] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Step] left.
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - loading collection: [org.drools.persistence.processinstance.WorkItemInfo.variables#1]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.SQL - select variables0_.workItemId as workItemId1_, variables0_.id as id1_, variables0_.name as formula16_1_, variables0_.id as id90_0_, variables0_.name as name90_0_, variables0_.persister as persister90_0_, variables0_.processInstanceId as processI5_90_0_, variables0_.workItemId as workItemId90_0_, variables0_.entityClass as entityCl7_90_0_, variables0_.entityId as entityId90_0_, variables0_.content as content90_0_, variables0_.TYPE as TYPE90_0_ from VariableInstanceInfo variables0_ where variables0_.workItemId=?
12:03:16.710 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 1
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - result set contains (possibly empty) collection: [org.drools.persistence.processinstance.WorkItemInfo.variables#1]
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.loading.CollectionLoadContext - 1 collections were found in result set for role: org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.loading.CollectionLoadContext - collection fully initialized: [org.drools.persistence.processinstance.WorkItemInfo.variables#1]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.loading.CollectionLoadContext - 1 collections initialized for role: org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - done loading collection
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.710 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7d8808080808080808080808080808080808080808080808080808080808080808082808d8084cdc1c9ce808081808d8084cdc1c9ce808180818080808080808180818081808180818180818081808180808080808080808081, lastModificationDate=2011-03-31 12:03:16, version=1}
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.710 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.710 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.710 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes#1], was: [org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes#1] (uninitialized)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.ProcessInstanceInfo.variables#1], was: [org.drools.persistence.processinstance.ProcessInstanceInfo.variables#1] (uninitialized)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.WorkItemInfo.variables#2], was: [<unreferenced>] (initialized)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection dereferenced: [org.drools.persistence.processinstance.WorkItemInfo.variables#1]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 1 deletions to 3 objects
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 1 (re)creations, 0 updates, 1 removals to 4 collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.processinstance.WorkItemInfo{creationDate=2011-03-31 12:03:16, processInstanceId=1, name=Step, workItemByteArray=2c6d8085f7a4808080808080808280808080808080818084d3f4e5f080808080808080838084d5d5c9c4f3f2808eeae1f6e1aef5f4e9ecaed5d5c9c43c19837718ed05af828082ca808cece5e1f3f4d3e9e7c2e9f4f3ca808bedeff3f4d3e9e7c2e9f4f3f8f038246997c4d7dcabce8444b50f86cb4cf78c808ae9eef3f4e1eee3e5c9e4f3f180fe8080062c1a0afc58d175b57d7f2f6d8cc55cf78c808af3ece9e3e5d6e1ecf5e5f48088cecfdfd3ccc9c3c5, state=0, externalVariables=false, workItemId=2, version=0, variables=[]}
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.processinstance.WorkItemInfo{creationDate=2011-03-31 12:03:16, processInstanceId=1, name=Step, workItemByteArray=2c6d8085f7a4808080808080808180808080808080818084d3f4e5f080808080808080838084d5d5c9c4f3f2808eeae1f6e1aef5f4e9ecaed5d5c9c43c19837718ed05af828082ca808cece5e1f3f4d3e9e7c2e9f4f3ca808bedeff3f4d3e9e7c2e9f4f3f8f038246997c4d7dcabce8444b50f86cb4cf78c808ae9eef3f4e1eee3e5c9e4f3f180fe80800dd3ca8384401420866a8bdcea50c327f78c808af3ece9e3e5d6e1ecf5e5f48088cecfdfd3ccc9c3c5, state=0, externalVariables=false, workItemId=1, version=1, variables=[]}
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.processinstance.ProcessInstanceInfo{startDate=2011-03-31 12:03:16, processInstanceId=1, processId=d9686dff_98a5_4670_bdfa_fd03f2c8ed42, processInstanceByteArray=2c6d8085f7df8088d2f5ece5c6eceff7808080808080808180a4e4b9b6b8b6e4e6e6dfb9b8e1b5dfb4b6b7b0dfe2e4e6e1dfe6e4b0b3e6b2e3b8e5e4b4b2808080818080808080808083808080818095f0f2efe3e5f3f3c6eceff7c9eef3f4e1eee3e5c9e4f3f2808eeae1f6e1aef5f4e9ecaed5d5c9c43c19837718ed05af828082ca808cece5e1f3f4d3e9e7c2e9f4f3ca808bedeff3f4d3e9e7c2e9f4f3f8f03c45dc792f6d5b94a95e96470883ccd7f7aa808080808092808080808080808280808080808080838095808080808080808180808080808180808080, state=1, lastModificationDate=2011-03-31 12:03:16, lastReadDate=2011-03-31 12:03:16, externalVariables=false, eventTypes=<uninitialized>, version=1, variables=<uninitialized>}
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - update WorkItemInfo set creationDate=?, externalVariables=?, name=?, processInstanceId=?, state=?, OPTLOCK=?, workItemByteArray=? where workItemId=? and OPTLOCK=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 1
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - binding 'false' to parameter: 2
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.StringType - binding 'Step' to parameter: 3
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 4
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '0' to parameter: 5
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 6
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '2' to parameter: 8
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '0' to parameter: 9
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - Inserting collection: [org.drools.persistence.processinstance.WorkItemInfo.variables#2]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.p.c.AbstractCollectionPersister - collection was empty
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - delete from WorkItemInfo where workItemId=? and OPTLOCK=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 1
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 2
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.725 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.725 [pool-1-thread-1] DEBUG c.p.process.drools.DroolsFlowAdapter - Completing step instance [step-1 Approval] with workItemId [2]
12:03:16.725 [pool-1-thread-1] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null
12:03:16.725 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2] for JPA transaction
12:03:16.725 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.725 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@53ddcd5f]
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13015981967
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - begin
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
12:03:16.725 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@6d642fd]
12:03:16.725 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.725 [pool-1-thread-1] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - loading entity: [org.drools.persistence.processinstance.WorkItemInfo#2]
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - select workitemin0_.workItemId as workItemId91_0_, workitemin0_.creationDate as creation2_91_0_, workitemin0_.externalVariables as external3_91_0_, workitemin0_.name as name91_0_, workitemin0_.processInstanceId as processI5_91_0_, workitemin0_.state as state91_0_, workitemin0_.OPTLOCK as OPTLOCK91_0_, workitemin0_.workItemByteArray as workItem8_91_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '2' to parameter: 1
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - result row: EntityKey[org.drools.persistence.processinstance.WorkItemInfo#2]
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: creation2_91_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - returning 'false' as column: external3_91_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.StringType - returning 'Step' as column: name91_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - returning '1' as column: processI5_91_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - returning '0' as column: state91_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - returning '1' as column: OPTLOCK91_0_
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [org.drools.persistence.processinstance.WorkItemInfo#2]
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [org.drools.persistence.processinstance.WorkItemInfo#2]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - done entity load
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - loading entity: [org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - select processins0_.InstanceId as InstanceId89_0_, processins0_.externalVariables as external2_89_0_, processins0_.lastModificationDate as lastModi3_89_0_, processins0_.lastReadDate as lastRead4_89_0_, processins0_.processId as processId89_0_, processins0_.processInstanceByteArray as processI6_89_0_, processins0_.startDate as startDate89_0_, processins0_.state as state89_0_, processins0_.OPTLOCK as OPTLOCK89_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 1
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - result row: EntityKey[org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - returning 'false' as column: external2_89_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: lastModi3_89_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: lastRead4_89_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.StringType - returning 'd9686dff_98a5_4670_bdfa_fd03f2c8ed42' as column: processId89_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - returning '2011-03-31 12:03:16' as column: startDate89_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - returning '1' as column: state89_0_
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - returning '1' as column: OPTLOCK89_0_
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [org.drools.persistence.processinstance.ProcessInstanceInfo#1]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - done entity load
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - loading collection: [org.drools.persistence.processinstance.WorkItemInfo.variables#2]
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - select variables0_.workItemId as workItemId1_, variables0_.id as id1_, variables0_.name as formula16_1_, variables0_.id as id90_0_, variables0_.name as name90_0_, variables0_.persister as persister90_0_, variables0_.processInstanceId as processI5_90_0_, variables0_.workItemId as workItemId90_0_, variables0_.entityClass as entityCl7_90_0_, variables0_.entityId as entityId90_0_, variables0_.content as content90_0_, variables0_.TYPE as TYPE90_0_ from VariableInstanceInfo variables0_ where variables0_.workItemId=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '2' to parameter: 1
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - result set contains (possibly empty) collection: [org.drools.persistence.processinstance.WorkItemInfo.variables#2]
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.loading.CollectionLoadContext - 1 collections were found in result set for role: org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.loading.CollectionLoadContext - collection fully initialized: [org.drools.persistence.processinstance.WorkItemInfo.variables#2]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.loading.CollectionLoadContext - 1 collections initialized for role: org.drools.persistence.processinstance.WorkItemInfo.variables
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.loader.Loader - done loading collection
12:03:16.725 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit
12:03:16.725 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@3851ddd2]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.session.SessionInfo{id=1, startDate=2011-03-31 12:03:16, rulesByteArray=2c6d8085f7d8808080808080808080808080808080808080808080808080808080808080808082808d8084cdc1c9ce808081808d8084cdc1c9ce808180818080808080808180818081808180818180818081808180808080808080808081, lastModificationDate=2011-03-31 12:03:16, version=1}
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - update SessionInfo set lastModificationDate=?, rulesByteArray=?, startDate=?, OPTLOCK=? where id=? and OPTLOCK=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 1
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 3
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '2' to parameter: 4
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 5
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 6
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes#1], was: [org.drools.persistence.processinstance.ProcessInstanceInfo.eventTypes#1] (uninitialized)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection found: [org.drools.persistence.processinstance.ProcessInstanceInfo.variables#1], was: [org.drools.persistence.processinstance.ProcessInstanceInfo.variables#1] (uninitialized)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.engine.Collections - Collection dereferenced: [org.drools.persistence.processinstance.WorkItemInfo.variables#2]
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 1 deletions to 2 objects
12:03:16.725 [pool-1-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 1 removals to 3 collections
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.processinstance.WorkItemInfo{creationDate=2011-03-31 12:03:16, processInstanceId=1, name=Step, workItemByteArray=2c6d8085f7a4808080808080808280808080808080818084d3f4e5f080808080808080838084d5d5c9c4f3f2808eeae1f6e1aef5f4e9ecaed5d5c9c43c19837718ed05af828082ca808cece5e1f3f4d3e9e7c2e9f4f3ca808bedeff3f4d3e9e7c2e9f4f3f8f038246997c4d7dcabce8444b50f86cb4cf78c808ae9eef3f4e1eee3e5c9e4f3f180fe8080062c1a0afc58d175b57d7f2f6d8cc55cf78c808af3ece9e3e5d6e1ecf5e5f48088cecfdfd3ccc9c3c5, state=0, externalVariables=false, workItemId=2, version=1, variables=[]}
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.pretty.Printer - org.drools.persistence.processinstance.ProcessInstanceInfo{startDate=2011-03-31 12:03:16, processInstanceId=1, processId=d9686dff_98a5_4670_bdfa_fd03f2c8ed42, processInstanceByteArray=2c6d8085f7df8088d2f5ece5c6eceff7808080808080808180a4e4b9b6b8b6e4e6e6dfb9b8e1b5dfb4b6b7b0dfe2e4e6e1dfe6e4b0b3e6b2e3b8e5e4b4b2808080818080808080808083808080818095f0f2efe3e5f3f3c6eceff7c9eef3f4e1eee3e5c9e4f3f2808eeae1f6e1aef5f4e9ecaed5d5c9c43c19837718ed05af828082ca808cece5e1f3f4d3e9e7c2e9f4f3ca808bedeff3f4d3e9e7c2e9f4f3f8f03c45dc792f6d5b94a95e96470883ccd7f7aa808080808092808080808080808280808080808080838095808080808080808180808080808180808080, state=1, lastModificationDate=2011-03-31 12:03:16, lastReadDate=2011-03-31 12:03:16, externalVariables=false, eventTypes=<uninitialized>, version=1, variables=<uninitialized>}
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - update ProcessInstanceInfo set externalVariables=?, lastModificationDate=?, lastReadDate=?, processId=?, processInstanceByteArray=?, startDate=?, state=?, OPTLOCK=? where InstanceId=? and OPTLOCK=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.BooleanType - binding 'false' to parameter: 1
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 2
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 3
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.StringType - binding 'd9686dff_98a5_4670_bdfa_fd03f2c8ed42' to parameter: 4
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.TimestampType - binding '2011-03-31 12:03:16' to parameter: 6
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 7
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '2' to parameter: 8
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '1' to parameter: 9
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 10
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.SQL - delete from WorkItemInfo where workItemId=? and OPTLOCK=?
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.LongType - binding '2' to parameter: 1
12:03:16.725 [pool-1-thread-1] TRACE org.hibernate.type.IntegerType - binding '1' to parameter: 2
12:03:16.725 [pool-1-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:16.757 [pool-1-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
12:03:16.772 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
12:03:16.772 [pool-1-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:03:16.772 [pool-1-thread-1] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction
12:03:16.772 [pool-1-thread-1] INFO  o.s.c.s.ClassPathXmlApplicationContext - Closing org.springframework.context.support.ClassPathXmlApplicationContext@7d6bb63e: startup date [Thu Mar 31 12:03:16 PDT 2011]; root of context hierarchy
12:03:16.772 [pool-1-thread-1] INFO  o.s.c.s.DefaultLifecycleProcessor - Stopping beans in phase 0
12:03:16.772 [pool-1-thread-1] INFO  o.s.b.f.s.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@1c944d4a: defining beans [processFlowManager,stepWorkItemHandler,stepActivationCallbackHandler,processEventListener,modelCache,modelFactory,droolsFlowAdapter,memberSetResolver,instanceCache,processFlowService,startProcessFlowHandler,getProcessFlowStatusHandler,stepCompletedServiceHandler,approvalCompletedServiceHandler,connectionFactory,protobufJmsListener,protobufConverter,messageHandler,cachedConnectionFactory,jmsTemplate,messageProducer,dataSource,transactionManager,entityManagerFactory,jpaAdapter,entityManager,org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0,testOutJmsTemplate,testInJmsTemplate,testInConverter,outListener,inSender,embeddedJmsBroker]; root of factory hierarchy
12:03:16.772 [pool-1-thread-1] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'org.drools.persistence.jpa'
12:03:16.772 [pool-1-thread-1] INFO  o.hibernate.impl.SessionFactoryImpl - closing