09:16:06.453 [main] INFO o.s.c.s.ClassPathXmlApplicationContext - Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@1fbbdd48: startup date [Fri Apr 01 09:16:06 PDT 2011]; root of context hierarchy 09:16:06.606 [main] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/proferi-component.xml] 09:16:06.987 [main] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/proferi-component-test.xml] 09:16:07.088 [main] 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]] 09:16:07.142 [main] 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]] 09:16:07.556 [main] INFO o.s.b.f.c.PropertyPlaceholderConfigurer - Loading properties file from class path resource [proferi-component.properties] 09:16:07.600 [main] INFO o.s.b.f.s.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@30b48b11: 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 09:16:08.196 [main] DEBUG org.springframework.beans.BeanUtils - No property editor [org.hornetq.api.core.client.ClientSessionFactoryEditor] found for type org.hornetq.api.core.client.ClientSessionFactory according to 'Editor' suffix convention 09:16:08.199 [main] DEBUG org.springframework.beans.BeanUtils - No property editor [org.hornetq.api.core.PairEditor] found for type org.hornetq.api.core.Pair according to 'Editor' suffix convention 09:16:08.719 [main] DEBUG c.p.core.message.ProtobufJmsListener - invoking handleMessage on ProcessFlowMessageConsumer for a StepCompletedRequest 09:16:08.720 [main] DEBUG c.p.core.message.ProtobufJmsListener - invoking handleMessage on ProcessFlowMessageConsumer for a ApprovalCompletedRequest 09:16:08.866 [main] DEBUG org.springframework.beans.BeanUtils - No property editor [org.springframework.orm.jpa.vendor.DatabaseEditor] found for type org.springframework.orm.jpa.vendor.Database according to 'Editor' suffix convention 09:16:08.907 [main] INFO o.s.o.j.LocalContainerEntityManagerFactoryBean - Building JPA container EntityManagerFactory for persistence unit 'org.drools.persistence.jpa' 09:16:12.232 [main] DEBUG c.p.process.drools.ProxyBuilder - Approval constraint [StepApproval( approved == true, sliceValue == "NO_SLICE", approvalStepNodeId == "1a8a5a64-1e32-46a9-8b04-806c1706a97a" )] 09:16:12.268 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Created new StepNodeInstance [step-1 Step] with ID [48305f48-1ea6-47c2-a74b-254e48247285] 09:16:12.277 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Created new ImpliedStepNodeInstance [step-1 Approval] with ID [6204a045-9c95-4392-8927-aa88333e38ce] 10:51:21.672 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Starting process flow [flow-1] instance [71d27a30-4db9-4133-b461-86318f48cd24] 10:51:25.643 [main] DEBUG o.d.p.s.SingleSessionCommandService - Instantiating DroolsSpringTransactionManager 10:51:25.804 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:25.807 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:25.808 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:25.878 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@7a9eb4a1] 10:51:25.882 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:25.997 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:25.998 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.006 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.009 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.010 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.020 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.021 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@43e3556a] 10:51:26.023 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@1fcc4f8] 10:51:26.027 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.028 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.033 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.034 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.040 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.078 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.079 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.080 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.081 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@733e4c83] 10:51:26.130 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@7f116790] 10:51:26.131 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.132 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.133 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.181 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.182 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.186 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.187 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.188 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.234 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@4e2120fa] 10:51:26.235 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@60fc2528] 10:51:26.237 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.238 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.239 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.239 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.241 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.244 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.245 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.246 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.247 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@7792a63a] 10:51:26.295 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@3cdf672a] 10:51:26.296 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.297 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.359 [main] DEBUG c.p.p.drools.ProcessEventListener - Starting process [flow-1]... 10:51:26.387 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [flow-1 Start]... 10:51:26.389 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [flow-1 Start]... 10:51:26.390 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Reject Join]... 10:51:26.391 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Reject Join]... 10:51:26.395 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Step]... 10:51:26.416 [main] DEBUG c.p.p.drools.StepWorkItemHandler - Executing Step with Drools work item ID [1] for Step with instance UUID [48305f48-1ea6-47c2-a74b-254e48247285] in slice [NO_SLICE] 10:51:26.417 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Step] triggered. 10:51:26.417 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Reject Join] left. 10:51:26.417 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Reject Join] triggered. 10:51:26.418 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [flow-1 Start] left. 10:51:26.453 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [flow-1 Start] triggered. 10:51:26.454 [main] DEBUG c.p.p.drools.ProcessEventListener - Process [flow-1] started. 10:51:26.455 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.455 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.494 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.495 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.496 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.496 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.508 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@47fb4a7b] 10:51:26.510 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@42d6f628] 10:51:26.510 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.511 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.512 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.512 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.513 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.514 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Completing step instance [step-1 Step] with workItemId [1] 10:51:26.516 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.517 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.517 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.518 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@3eb2aa1c] 10:51:26.567 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@7c63c132] 10:51:26.568 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.568 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.610 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Step]... 10:51:26.611 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Approval]... 10:51:26.613 [main] DEBUG c.p.p.drools.StepWorkItemHandler - Executing Step with Drools work item ID [2] for Step with instance UUID [6204a045-9c95-4392-8927-aa88333e38ce] in slice [NO_SLICE] 10:51:26.614 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval] triggered. 10:51:26.614 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Step] left. 10:51:26.638 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.639 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.652 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.653 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Completing step instance [step-1 Approval] with workItemId [2] 10:51:26.653 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.672 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.673 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.675 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@566dc8f0] 10:51:26.676 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@41a330e4] 10:51:26.677 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.678 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.686 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Approval]... 10:51:26.687 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Approval Split]... 10:51:26.694 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Approval Split]... 10:51:26.695 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Reject Join]... 10:51:26.695 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Reject Join]... 10:51:26.696 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Step]... 10:51:26.732 [main] DEBUG c.p.p.drools.StepWorkItemHandler - Executing Step with Drools work item ID [3] for Step with instance UUID [48305f48-1ea6-47c2-a74b-254e48247285] in slice [NO_SLICE] 10:51:26.733 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Step] triggered. 10:51:26.733 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Reject Join] left. 10:51:26.734 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Reject Join] triggered. 10:51:26.734 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval Split] left. 10:51:26.782 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval Split] triggered. 10:51:26.783 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval] left. 10:51:26.787 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.788 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.797 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.798 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Completing step instance [step-1 Step] with workItemId [3] 10:51:26.798 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.836 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.837 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.837 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@4bdb0f40] 10:51:26.839 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@1ac659a8] 10:51:26.839 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.840 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.846 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Step]... 10:51:26.889 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Approval]... 10:51:26.892 [main] DEBUG c.p.p.drools.StepWorkItemHandler - Executing Step with Drools work item ID [4] for Step with instance UUID [6204a045-9c95-4392-8927-aa88333e38ce] in slice [NO_SLICE] 10:51:26.892 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval] triggered. 10:51:26.893 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Step] left. 10:51:26.895 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:26.896 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:26.952 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:26.953 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Approving step instance [step-1 Approval] 10:51:26.956 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:26.956 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:26.994 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:26.995 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@192eb04e] 10:51:26.997 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@4838ddcc] 10:51:26.998 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:26.998 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:27.014 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:27.015 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:27.021 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:27.022 [main] DEBUG c.p.process.drools.DroolsFlowAdapter - Completing step instance [step-1 Approval] with workItemId [4] 10:51:27.022 [main] DEBUG o.d.c.s.b.p.DroolsSpringTransactionManager - Current TX name (According to TransactionSynchronizationManager) : null 10:51:27.051 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] for JPA transaction 10:51:27.052 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 10:51:27.052 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@6c4f7b4c] 10:51:27.054 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Starting resource local transaction on application-managed EntityManager [org.hibernate.ejb.EntityManagerImpl@5627f221] 10:51:27.054 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:27.055 [main] DEBUG o.s.o.j.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler - Joined local transaction 10:51:27.062 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Approval]... 10:51:27.063 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [step-1 Approval Split]... 10:51:27.063 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [step-1 Approval Split]... 10:51:27.066 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [null Wait]... 10:51:27.067 [main] DEBUG c.proferi.process.manager.Terminator - Active nodes: 1 10:51:27.067 [main] DEBUG c.proferi.process.manager.Terminator - Terminating Flow 10:51:27.133 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [null Wait]... 10:51:27.134 [main] DEBUG c.p.p.drools.ProcessEventListener - Triggering node [null End]... 10:51:27.134 [main] DEBUG c.p.p.drools.ProcessEventListener - Leaving node [null End]... 10:51:27.136 [main] DEBUG c.p.p.drools.ProcessEventListener - Completing process [flow-1]... 10:51:27.140 [main] DEBUG c.p.p.drools.ProcessEventListener - Process [flow-1] Complete. 10:51:27.143 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [null End] left. 10:51:27.159 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [null End] triggered. 10:51:27.160 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [null Wait] left. 10:51:27.160 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [null Wait] triggered. 10:51:27.161 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval Split] left. 10:51:27.161 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval Split] triggered. 10:51:27.162 [main] DEBUG c.p.p.drools.ProcessEventListener - Node [step-1 Approval] left. 10:51:27.165 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Initiating transaction commit 10:51:27.165 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@a70ad76] 10:51:27.172 [main] DEBUG o.s.orm.jpa.JpaTransactionManager - Not closing pre-bound JPA EntityManager after transaction 10:51:27.174 [main] INFO o.s.c.s.ClassPathXmlApplicationContext - Closing org.springframework.context.support.ClassPathXmlApplicationContext@1fbbdd48: startup date [Fri Apr 01 09:16:06 PDT 2011]; root of context hierarchy 10:51:27.221 [main] INFO o.s.c.s.DefaultLifecycleProcessor - Stopping beans in phase 0 10:51:27.222 [main] INFO o.s.b.f.s.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@30b48b11: 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 Disconnected from the target VM, address: 'javadebug', transport: 'shared memory' 10:51:27.269 [main] INFO o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'org.drools.persistence.jpa' Process finished with exit code 0