spring3.2.4+mybatis3.2.8+atomikos3.9事务无效

Alex.Wong 发布于 2015/02/05 21:29
阅读 3K+
收藏 0

今天整合基于spring3.2.4+mybatis3.2.8+atomikos3.9的分布式事务,事务却老是不起作用,查了好久也不知道哪里有问题,有接触的朋友请指点指点,谢谢。

TEST 2015-02-05 21:39:37,161 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'userTokenService'
TEST 2015-02-05 21:39:37,161 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'userTokenService'
TEST 2015-02-05 21:39:37,161 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0'
TEST 2015-02-05 21:39:37,161 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
TEST 2015-02-05 21:39:37,161 DEBUG [][main] org.springframework.beans.factory.annotation.InjectionMetadata [InjectionMetadata.java:71] - Registered injected element on class [org.lottery.common.service.user.UserTokenService]: AutowiredFieldElement for org.lottery.common.dao.user.UserTokenDaoImpl org.lottery.common.service.user.UserTokenService.tokenDao
TEST 2015-02-05 21:39:37,161 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'userTokenService' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,163 DEBUG [][main] org.springframework.beans.factory.annotation.InjectionMetadata [InjectionMetadata.java:85] - Processing injected method of bean 'userTokenService': AutowiredFieldElement for org.lottery.common.dao.user.UserTokenDaoImpl org.lottery.common.service.user.UserTokenService.tokenDao
TEST 2015-02-05 21:39:37,163 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'userTokenDaoImpl'
TEST 2015-02-05 21:39:37,163 DEBUG [][main] org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor [AutowiredAnnotationBeanPostProcessor.java:433] - Autowiring by type from bean name 'userTokenService' to bean named 'userTokenDaoImpl'
TEST 2015-02-05 21:39:37,163 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0'
TEST 2015-02-05 21:39:37,164 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
TEST 2015-02-05 21:39:37,164 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0'
TEST 2015-02-05 21:39:37,181 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
TEST 2015-02-05 21:39:37,182 DEBUG [][main] org.springframework.aop.aspectj.annotation.AnnotationAwareAspectJAutoProxyCreator [AbstractAutoProxyCreator.java:538] - Creating implicit proxy for bean 'userTokenService' with 0 common interceptors and 2 specific interceptors
TEST 2015-02-05 21:39:37,182 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:155] - Creating CGLIB proxy: target source is SingletonTargetSource for target object [org.lottery.common.service.user.UserTokenService@6ce807b0]
TEST 2015-02-05 21:39:37,182 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:808] - Unable to apply any optimisations to advised method: public int org.lottery.common.service.user.UserTokenService.longin(java.lang.Long,java.lang.Short,java.lang.String)
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:759] - Found finalize() method - using NO_OVERRIDE
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:771] - Found 'equals' method: public boolean java.lang.Object.equals(java.lang.Object)
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:808] - Unable to apply any optimisations to advised method: public java.lang.String java.lang.Object.toString()
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:776] - Found 'hashCode' method: public native int java.lang.Object.hashCode()
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:808] - Unable to apply any optimisations to advised method: protected native java.lang.Object java.lang.Object.clone() throws java.lang.CloneNotSupportedException
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract int org.springframework.aop.framework.Advised.indexOf(org.springframework.aop.Advisor)
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract int org.springframework.aop.framework.Advised.indexOf(org.aopalliance.aop.Advice)
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.isFrozen()
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract java.lang.Class[] org.springframework.aop.framework.Advised.getProxiedInterfaces()
TEST 2015-02-05 21:39:37,183 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.isInterfaceProxied(java.lang.Class)
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.replaceAdvisor(org.springframework.aop.Advisor,org.springframework.aop.Advisor) throws org.springframework.aop.framework.AopConfigException
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract java.lang.String org.springframework.aop.framework.Advised.toProxyConfigString()
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.addAdvisor(org.springframework.aop.Advisor) throws org.springframework.aop.framework.AopConfigException
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.addAdvisor(int,org.springframework.aop.Advisor) throws org.springframework.aop.framework.AopConfigException
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.isExposeProxy()
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract org.springframework.aop.TargetSource org.springframework.aop.framework.Advised.getTargetSource()
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.setPreFiltered(boolean)
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.setTargetSource(org.springframework.aop.TargetSource)
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.isProxyTargetClass()
TEST 2015-02-05 21:39:37,184 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.setExposeProxy(boolean)
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract org.springframework.aop.Advisor[] org.springframework.aop.framework.Advised.getAdvisors()
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.isPreFiltered()
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.removeAdvice(org.aopalliance.aop.Advice)
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.removeAdvisor(int) throws org.springframework.aop.framework.AopConfigException
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract boolean org.springframework.aop.framework.Advised.removeAdvisor(org.springframework.aop.Advisor)
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.addAdvice(int,org.aopalliance.aop.Advice) throws org.springframework.aop.framework.AopConfigException
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract void org.springframework.aop.framework.Advised.addAdvice(org.aopalliance.aop.Advice) throws org.springframework.aop.framework.AopConfigException
TEST 2015-02-05 21:39:37,185 DEBUG [][main] org.springframework.aop.framework.CglibAopProxy [CglibAopProxy.java:765] - Method is declared on Advised interface: public abstract java.lang.Class org.springframework.aop.TargetClassAware.getTargetClass()
TEST 2015-02-05 21:39:37,191 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'userTokenService'
TEST 2015-02-05 21:39:37,191 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.context.annotation.internalRequiredAnnotationProcessor'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.context.annotation.internalCommonAnnotationProcessor'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'org.springframework.context.annotation.ConfigurationClassPostProcessor.importAwareProcessor'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbBonusDetailMapper'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbGameIssueCheckMapper'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbGameIssueMapper'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbGameMapper'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbPlayCodeMapper'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbPlusBonusMapper'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbSupplierMapper'
TEST 2015-02-05 21:39:37,192 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbUserBankcardMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbUserBillMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbUserMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbUserPointsBillMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbUserRechargeMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbUserTokenMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbOrderMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbOrderOriginalMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbOrderSplitMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbTeamOrderFollowMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbTeamOrderMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbTeamOrderOriginalMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbTraceOrderMapper'
TEST 2015-02-05 21:39:37,193 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'tbMatchMapper'
TEST 2015-02-05 21:39:37,195 DEBUG [][main] org.springframework.context.support.FileSystemXmlApplicationContext [AbstractApplicationContext.java:858] - Unable to locate LifecycleProcessor with name 'lifecycleProcessor': using default [org.springframework.context.support.DefaultLifecycleProcessor@17080026]
TEST 2015-02-05 21:39:37,196 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'lifecycleProcessor'
TEST 2015-02-05 21:39:37,197 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'sqlSessionFactory'
TEST 2015-02-05 21:39:37,197 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'sqlSessionFactory_user'
TEST 2015-02-05 21:39:37,197 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'sqlSessionFactory_order'
TEST 2015-02-05 21:39:37,197 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'sqlSessionFactory_sporttery'
TEST 2015-02-05 21:39:37,198 DEBUG [][main] org.springframework.core.env.PropertySourcesPropertyResolver [PropertySourcesPropertyResolver.java:81] - Searching for key 'spring.liveBeansView.mbeanDomain' in [systemProperties]
TEST 2015-02-05 21:39:37,198 DEBUG [][main] org.springframework.core.env.PropertySourcesPropertyResolver [PropertySourcesPropertyResolver.java:81] - Searching for key 'spring.liveBeansView.mbeanDomain' in [systemEnvironment]
TEST 2015-02-05 21:39:37,199 DEBUG [][main] org.springframework.core.env.PropertySourcesPropertyResolver [PropertySourcesPropertyResolver.java:103] - Could not find key 'spring.liveBeansView.mbeanDomain' in any property source. Returning [null]
TEST 2015-02-05 21:39:37,200 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'userService'
TEST 2015-02-05 21:39:37,201 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'orderService'
TEST 2015-02-05 21:39:37,205 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction() returning NULL!
TEST 2015-02-05 21:39:37,206 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:366] - Creating new transaction with name [org.lottery.common.service.user.UserService.login]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,-Exception
TEST 2015-02-05 21:39:37,207 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction() returning NULL!
TEST 2015-02-05 21:39:37,207 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000100031 entering state: ACTIVE
TEST 2015-02-05 21:39:37,208 DEBUG [][main] com.atomikos.icatch.imp.thread.TaskManager [Slf4jLogger.java:20] - TaskManager: initializing...
TEST 2015-02-05 21:39:37,208 INFO  [][main] com.atomikos.icatch.imp.thread.TaskManager [Slf4jLogger.java:16] - THREADS: using JDK thread pooling...
TEST 2015-02-05 21:39:37,211 DEBUG [][main] com.atomikos.icatch.imp.thread.TaskManager [Slf4jLogger.java:20] - THREADS: using executor class com.atomikos.icatch.imp.thread.Java15ExecutorFactory$Executor
TEST 2015-02-05 21:39:37,211 DEBUG [][main] com.atomikos.icatch.imp.thread.Java15ExecutorFactory [Slf4jLogger.java:20] - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@3cdc3901
TEST 2015-02-05 21:39:37,212 DEBUG [][main] com.atomikos.icatch.imp.thread.ThreadFactory [Slf4jLogger.java:20] - ThreadFactory: creating new thread: Atomikos:0
TEST 2015-02-05 21:39:37,213 DEBUG [][main] com.atomikos.icatch.imp.TransactionServiceImp [Slf4jLogger.java:20] - Creating composite transaction: 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,217 INFO  [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:16] - createCompositeTransaction ( 300000 ): created new ROOT transaction with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,382 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:104] - Creating a new SqlSession
TEST 2015-02-05 21:39:37,385 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:120] - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@407305a3]
TEST 2015-02-05 21:39:37,418 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:110] - Fetching JDBC Connection from DataSource
TEST 2015-02-05 21:39:37,419 DEBUG [][main] com.atomikos.jdbc.ConnectionPool [Slf4jLogger.java:20] - JDBC ConnectionPool: using connection: ExternalXAPooledConnectionImp1423143565971com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@47a82a6a
TEST 2015-02-05 21:39:37,466 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:114] - Registering transaction synchronization for JDBC Connection
TEST 2015-02-05 21:39:37,468 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,469 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000100031 entering state: ACTIVE
TEST 2015-02-05 21:39:37,470 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - addParticipant ( XAResourceTransaction: 3139322E3136382E312E33332E746D30303030313030303331:3139322E3136382E312E33332E746D31 ) for transaction 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,470 DEBUG [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:20] - XAResourceTransaction: 3139322E3136382E312E33332E746D30303030313030303331:3139322E3136382E312E33332E746D31: about to switch to XAResource com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@75e207f
TEST 2015-02-05 21:39:37,470 DEBUG [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:20] - XAResourceTransaction 192.168.1.33.tm0000100031192.168.1.33.tm1: switched to XAResource com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@75e207f
TEST 2015-02-05 21:39:37,470 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,470 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - registerSynchronization ( ExternalXAPooledConnectionImp1423143565971com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@47a82a6a ) for transaction 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,470 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.start ( 3139322E3136382E312E33332E746D30303030313030303331:3139322E3136382E312E33332E746D31 , XAResource.TMNOFLAGS ) on resource mysql/user represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@75e207f
TEST 2015-02-05 21:39:37,471 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: using resource transaction: 192.168.1.33.tm0000100031192.168.1.33.tm1
TEST 2015-02-05 21:39:37,471 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating getAutoCommit to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@5e1b7661
TEST 2015-02-05 21:39:37,471 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - Calling non-transactional method 'toString' on connection proxy, bypassing enlistment
TEST 2015-02-05 21:39:37,471 DEBUG [][main] org.mybatis.spring.transaction.SpringManagedTransaction [SpringManagedTransaction.java:86] - JDBC Connection [com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@5e1b7661] will be managed by Spring
TEST 2015-02-05 21:39:37,476 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.selectBySelective [BaseJdbcLogger.java:139] - ==>  Preparing: select user_id, phone, password, idcard, user_name, reg_date, account, freeze_account, last_up_time, status, alias, points, freeze_points, client_id, client_ty, reg_type from tb_user where 1=1 and phone = ? and password = ? 
TEST 2015-02-05 21:39:37,476 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,476 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating prepareStatement to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@5e1b7661
TEST 2015-02-05 21:39:37,498 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.selectBySelective [BaseJdbcLogger.java:139] - ==> Parameters: lrTEs/8KsmCIuCI2rVCqZw==(String), 47b91fcc95ca45619de2720fdb437bb1(String)
TEST 2015-02-05 21:39:37,517 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.selectBySelective [BaseJdbcLogger.java:139] - <==      Total: 1
TEST 2015-02-05 21:39:37,518 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:163] - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@407305a3]
TEST 2015-02-05 21:39:37,518 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:261] - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@407305a3]
TEST 2015-02-05 21:39:37,518 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:287] - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@407305a3]
TEST 2015-02-05 21:39:37,518 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:292] - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@407305a3]
TEST 2015-02-05 21:39:37,518 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:327] - Returning JDBC Connection to DataSource
TEST 2015-02-05 21:39:37,519 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,519 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating close to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@5e1b7661
TEST 2015-02-05 21:39:37,519 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.end ( 3139322E3136382E312E33332E746D30303030313030303331:3139322E3136382E312E33332E746D31 , XAResource.TMSUCCESS ) on resource mysql/user represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@75e207f
TEST 2015-02-05 21:39:37,520 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,520 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:753] - Initiating transaction commit
TEST 2015-02-05 21:39:37,520 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,520 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,521 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - commit() done (by application) of transaction 192.168.1.33.tm0000100031
TEST 2015-02-05 21:39:37,522 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000100031 entering state: COMMITTING
TEST 2015-02-05 21:39:37,545 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.commit ( 3139322E3136382E312E33332E746D30303030313030303331:3139322E3136382E312E33332E746D31 , true ) on resource mysql/user represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@75e207f
TEST 2015-02-05 21:39:37,546 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000100031 entering state: TERMINATED
TEST 2015-02-05 21:39:37,546 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000100031 : stopping timer...
TEST 2015-02-05 21:39:37,546 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000100031 : disposing statehandler TERMINATED...
TEST 2015-02-05 21:39:37,547 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000100031 : disposed.
TEST 2015-02-05 21:39:37,547 DEBUG [][main] com.atomikos.jdbc.ConnectionPool [Slf4jLogger.java:20] - Putting connection back in pool: ExternalXAPooledConnectionImp1423143565971com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@47a82a6a
TEST 2015-02-05 21:39:37,547 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction() returning NULL!
TEST 2015-02-05 21:39:37,547 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:366] - Creating new transaction with name [org.lottery.common.service.user.UserService.freezeAccount]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,-Exception
TEST 2015-02-05 21:39:37,547 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction() returning NULL!
TEST 2015-02-05 21:39:37,547 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000200031 entering state: ACTIVE
TEST 2015-02-05 21:39:37,547 DEBUG [][main] com.atomikos.icatch.imp.thread.Java15ExecutorFactory [Slf4jLogger.java:20] - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@37143859
TEST 2015-02-05 21:39:37,548 DEBUG [][main] com.atomikos.icatch.imp.TransactionServiceImp [Slf4jLogger.java:20] - Creating composite transaction: 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,548 INFO  [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:16] - createCompositeTransaction ( 300000 ): created new ROOT transaction with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,548 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'springTransactionManager'
TEST 2015-02-05 21:39:37,548 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,548 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:471] - Participating in existing transaction
TEST 2015-02-05 21:39:37,548 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:104] - Creating a new SqlSession
TEST 2015-02-05 21:39:37,548 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:120] - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@107f774f]
TEST 2015-02-05 21:39:37,548 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:110] - Fetching JDBC Connection from DataSource
TEST 2015-02-05 21:39:37,549 DEBUG [][main] com.atomikos.jdbc.ConnectionPool [Slf4jLogger.java:20] - JDBC ConnectionPool: using connection: ExternalXAPooledConnectionImp1423143565976com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@45637b37
TEST 2015-02-05 21:39:37,549 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:114] - Registering transaction synchronization for JDBC Connection
TEST 2015-02-05 21:39:37,549 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,549 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000200031 entering state: ACTIVE
TEST 2015-02-05 21:39:37,549 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - addParticipant ( XAResourceTransaction: 3139322E3136382E312E33332E746D30303030323030303331:3139322E3136382E312E33332E746D32 ) for transaction 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,549 DEBUG [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:20] - XAResourceTransaction: 3139322E3136382E312E33332E746D30303030323030303331:3139322E3136382E312E33332E746D32: about to switch to XAResource com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@16257bf6
TEST 2015-02-05 21:39:37,549 DEBUG [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:20] - XAResourceTransaction 192.168.1.33.tm0000200031192.168.1.33.tm2: switched to XAResource com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@16257bf6
TEST 2015-02-05 21:39:37,549 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,549 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - registerSynchronization ( ExternalXAPooledConnectionImp1423143565976com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@45637b37 ) for transaction 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,550 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.start ( 3139322E3136382E312E33332E746D30303030323030303331:3139322E3136382E312E33332E746D32 , XAResource.TMNOFLAGS ) on resource mysql/user represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@16257bf6
TEST 2015-02-05 21:39:37,550 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: using resource transaction: 192.168.1.33.tm0000200031192.168.1.33.tm2
TEST 2015-02-05 21:39:37,550 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating getAutoCommit to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@59ed2ef2
TEST 2015-02-05 21:39:37,550 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - Calling non-transactional method 'toString' on connection proxy, bypassing enlistment
TEST 2015-02-05 21:39:37,550 DEBUG [][main] org.mybatis.spring.transaction.SpringManagedTransaction [SpringManagedTransaction.java:86] - JDBC Connection [com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@59ed2ef2] will be managed by Spring
TEST 2015-02-05 21:39:37,550 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.selectByPrimaryKey [BaseJdbcLogger.java:139] - ==>  Preparing: select user_id, phone, password, idcard, user_name, reg_date, account, freeze_account, last_up_time, status, alias, points, freeze_points, client_id, client_ty, reg_type from tb_user where user_id = ? 
TEST 2015-02-05 21:39:37,550 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,551 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating prepareStatement to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@59ed2ef2
TEST 2015-02-05 21:39:37,551 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.selectByPrimaryKey [BaseJdbcLogger.java:139] - ==> Parameters: 91(Long)
TEST 2015-02-05 21:39:37,553 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.selectByPrimaryKey [BaseJdbcLogger.java:139] - <==      Total: 1
TEST 2015-02-05 21:39:37,553 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:163] - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@107f774f]
TEST 2015-02-05 21:39:37,553 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:97] - Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@107f774f] from current transaction
TEST 2015-02-05 21:39:37,554 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.updateByPrimaryKeySelective [BaseJdbcLogger.java:139] - ==>  Preparing: update tb_user SET phone = ?, password = ?, idcard = ?, user_name = ?, reg_date = ?, account = ?, freeze_account = ?, last_up_time = ?, status = ?, alias = ?, points = ?, freeze_points = ?, client_id = ?, client_ty = ?, reg_type = ? where user_id = ? 
TEST 2015-02-05 21:39:37,554 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,554 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating prepareStatement to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@59ed2ef2
TEST 2015-02-05 21:39:37,555 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.updateByPrimaryKeySelective [BaseJdbcLogger.java:139] - ==> Parameters: lrTEs/8KsmCIuCI2rVCqZw==(String), 47b91fcc95ca45619de2720fdb437bb1(String), (String), (String), 1423120098(Integer), 0.00(BigDecimal), 160.00(BigDecimal), 1423120098(Integer), 0(Byte), (String), 0(Integer), 0(Integer), 1(Integer), 1(Short), 1(Byte), 91(Long)
TEST 2015-02-05 21:39:37,556 DEBUG [][main] org.lottery.common.mapper.user.TbUserMapper.updateByPrimaryKeySelective [BaseJdbcLogger.java:139] - <==    Updates: 1
TEST 2015-02-05 21:39:37,557 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:163] - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@107f774f]
TEST 2015-02-05 21:39:37,557 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:261] - Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@107f774f]
TEST 2015-02-05 21:39:37,557 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:287] - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@107f774f]
TEST 2015-02-05 21:39:37,557 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:292] - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@107f774f]
TEST 2015-02-05 21:39:37,557 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:327] - Returning JDBC Connection to DataSource
TEST 2015-02-05 21:39:37,557 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,557 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating close to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@59ed2ef2
TEST 2015-02-05 21:39:37,557 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.end ( 3139322E3136382E312E33332E746D30303030323030303331:3139322E3136382E312E33332E746D32 , XAResource.TMSUCCESS ) on resource mysql/user represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@16257bf6
TEST 2015-02-05 21:39:37,558 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,558 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:753] - Initiating transaction commit
TEST 2015-02-05 21:39:37,558 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,558 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,558 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - commit() done (by application) of transaction 192.168.1.33.tm0000200031
TEST 2015-02-05 21:39:37,558 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000200031 entering state: COMMITTING
TEST 2015-02-05 21:39:37,576 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.commit ( 3139322E3136382E312E33332E746D30303030323030303331:3139322E3136382E312E33332E746D32 , true ) on resource mysql/user represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@16257bf6
TEST 2015-02-05 21:39:37,642 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000200031 entering state: TERMINATED
TEST 2015-02-05 21:39:37,642 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000200031 : stopping timer...
TEST 2015-02-05 21:39:37,642 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000200031 : disposing statehandler TERMINATED...
TEST 2015-02-05 21:39:37,642 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000200031 : disposed.
TEST 2015-02-05 21:39:37,642 DEBUG [][main] com.atomikos.jdbc.ConnectionPool [Slf4jLogger.java:20] - Putting connection back in pool: ExternalXAPooledConnectionImp1423143565976com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@45637b37
TEST 2015-02-05 21:39:37,643 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction() returning NULL!
TEST 2015-02-05 21:39:37,643 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:366] - Creating new transaction with name [org.lottery.common.service.order.OrderService.add]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,-Exception
TEST 2015-02-05 21:39:37,643 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction() returning NULL!
TEST 2015-02-05 21:39:37,643 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 entering state: ACTIVE
TEST 2015-02-05 21:39:37,643 DEBUG [][main] com.atomikos.icatch.imp.thread.Java15ExecutorFactory [Slf4jLogger.java:20] - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@211fc71
TEST 2015-02-05 21:39:37,643 DEBUG [][main] com.atomikos.icatch.imp.TransactionServiceImp [Slf4jLogger.java:20] - Creating composite transaction: 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,643 INFO  [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:16] - createCompositeTransaction ( 300000 ): created new ROOT transaction with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,643 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractBeanFactory.java:246] - Returning cached instance of singleton bean 'springTransactionManager'
TEST 2015-02-05 21:39:37,643 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,643 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:471] - Participating in existing transaction
TEST 2015-02-05 21:39:37,652 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:104] - Creating a new SqlSession
TEST 2015-02-05 21:39:37,652 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:120] - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3c123b4a]
TEST 2015-02-05 21:39:37,652 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:110] - Fetching JDBC Connection from DataSource
TEST 2015-02-05 21:39:37,652 DEBUG [][main] com.atomikos.jdbc.ConnectionPool [Slf4jLogger.java:20] - JDBC ConnectionPool: using connection: ExternalXAPooledConnectionImp1423143566343com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@5ccaed61
TEST 2015-02-05 21:39:37,652 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:114] - Registering transaction synchronization for JDBC Connection
TEST 2015-02-05 21:39:37,653 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,653 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 entering state: ACTIVE
TEST 2015-02-05 21:39:37,653 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - addParticipant ( XAResourceTransaction: 3139322E3136382E312E33332E746D30303030333030303331:3139322E3136382E312E33332E746D33 ) for transaction 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,653 DEBUG [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:20] - XAResourceTransaction: 3139322E3136382E312E33332E746D30303030333030303331:3139322E3136382E312E33332E746D33: about to switch to XAResource com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@2acf062d
TEST 2015-02-05 21:39:37,653 DEBUG [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:20] - XAResourceTransaction 192.168.1.33.tm0000300031192.168.1.33.tm3: switched to XAResource com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@2acf062d
TEST 2015-02-05 21:39:37,653 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,653 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - registerSynchronization ( ExternalXAPooledConnectionImp1423143566343com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@5ccaed61 ) for transaction 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,653 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.start ( 3139322E3136382E312E33332E746D30303030333030303331:3139322E3136382E312E33332E746D33 , XAResource.TMNOFLAGS ) on resource mysql/order represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@2acf062d
TEST 2015-02-05 21:39:37,654 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: using resource transaction: 192.168.1.33.tm0000300031192.168.1.33.tm3
TEST 2015-02-05 21:39:37,654 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating getAutoCommit to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@338a88f7
TEST 2015-02-05 21:39:37,654 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - Calling non-transactional method 'toString' on connection proxy, bypassing enlistment
TEST 2015-02-05 21:39:37,654 DEBUG [][main] org.mybatis.spring.transaction.SpringManagedTransaction [SpringManagedTransaction.java:86] - JDBC Connection [com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@338a88f7] will be managed by Spring
TEST 2015-02-05 21:39:37,654 DEBUG [][main] org.lottery.common.mapper.order.TbOrderMapper.insert [BaseJdbcLogger.java:139] - ==>  Preparing: insert into tb_order (order_id, user_id, game_id, issue_number, bets, prices, status, bonus, awards, create_time, client_id, client_ty ) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? ) 
TEST 2015-02-05 21:39:37,654 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,654 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating prepareStatement to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@338a88f7
TEST 2015-02-05 21:39:37,655 DEBUG [][main] org.lottery.common.mapper.order.TbOrderMapper.insert [BaseJdbcLogger.java:139] - ==> Parameters: null, null, null, null, null, null, null, null, null, null, null, null
TEST 2015-02-05 21:39:37,658 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:163] - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3c123b4a]
TEST 2015-02-05 21:39:37,666 DEBUG [][main] org.springframework.core.env.StandardEnvironment [AbstractEnvironment.java:112] - Initializing new StandardEnvironment
TEST 2015-02-05 21:39:37,667 DEBUG [][main] org.springframework.core.env.StandardEnvironment [MutablePropertySources.java:107] - Adding [systemProperties] PropertySource with lowest search precedence
TEST 2015-02-05 21:39:37,667 DEBUG [][main] org.springframework.core.env.StandardEnvironment [MutablePropertySources.java:107] - Adding [systemEnvironment] PropertySource with lowest search precedence
TEST 2015-02-05 21:39:37,667 DEBUG [][main] org.springframework.core.env.StandardEnvironment [AbstractEnvironment.java:116] - Initialized StandardEnvironment with PropertySources [systemProperties,systemEnvironment]
TEST 2015-02-05 21:39:37,667 INFO  [][main] org.springframework.beans.factory.xml.XmlBeanDefinitionReader [XmlBeanDefinitionReader.java:315] - Loading XML bean definitions from class path resource [org/springframework/jdbc/support/sql-error-codes.xml]
TEST 2015-02-05 21:39:37,669 DEBUG [][main] org.springframework.beans.factory.xml.DefaultDocumentLoader [DefaultDocumentLoader.java:72] - Using JAXP provider [com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderFactoryImpl]
TEST 2015-02-05 21:39:37,670 DEBUG [][main] org.springframework.beans.factory.xml.BeansDtdResolver [BeansDtdResolver.java:73] - Found beans DTD [http://www.springframework.org/dtd/spring-beans-2.0.dtd] in classpath: spring-beans-2.0.dtd
TEST 2015-02-05 21:39:37,676 DEBUG [][main] org.springframework.beans.factory.xml.DefaultBeanDefinitionDocumentReader [DefaultBeanDefinitionDocumentReader.java:106] - Loading bean definitions
TEST 2015-02-05 21:39:37,686 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'DB2'
TEST 2015-02-05 21:39:37,686 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'DB2'
TEST 2015-02-05 21:39:37,686 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'DB2' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,691 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'DB2'
TEST 2015-02-05 21:39:37,691 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'Derby'
TEST 2015-02-05 21:39:37,691 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'Derby'
TEST 2015-02-05 21:39:37,691 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'Derby' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,692 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'Derby'
TEST 2015-02-05 21:39:37,693 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'H2'
TEST 2015-02-05 21:39:37,694 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'H2'
TEST 2015-02-05 21:39:37,694 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'H2' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,694 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'H2'
TEST 2015-02-05 21:39:37,695 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'HSQL'
TEST 2015-02-05 21:39:37,695 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'HSQL'
TEST 2015-02-05 21:39:37,695 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'HSQL' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,696 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'HSQL'
TEST 2015-02-05 21:39:37,696 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'Informix'
TEST 2015-02-05 21:39:37,696 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'Informix'
TEST 2015-02-05 21:39:37,697 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'Informix' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,697 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'Informix'
TEST 2015-02-05 21:39:37,697 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'MS-SQL'
TEST 2015-02-05 21:39:37,697 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'MS-SQL'
TEST 2015-02-05 21:39:37,697 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'MS-SQL' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,698 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'MS-SQL'
TEST 2015-02-05 21:39:37,699 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'MySQL'
TEST 2015-02-05 21:39:37,699 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'MySQL'
TEST 2015-02-05 21:39:37,699 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'MySQL' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,699 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'MySQL'
TEST 2015-02-05 21:39:37,700 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'Oracle'
TEST 2015-02-05 21:39:37,700 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'Oracle'
TEST 2015-02-05 21:39:37,700 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'Oracle' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,701 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'Oracle'
TEST 2015-02-05 21:39:37,701 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'PostgreSQL'
TEST 2015-02-05 21:39:37,702 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'PostgreSQL'
TEST 2015-02-05 21:39:37,702 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'PostgreSQL' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,702 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'PostgreSQL'
TEST 2015-02-05 21:39:37,703 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [DefaultSingletonBeanRegistry.java:215] - Creating shared instance of singleton bean 'Sybase'
TEST 2015-02-05 21:39:37,703 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:432] - Creating instance of bean 'Sybase'
TEST 2015-02-05 21:39:37,703 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:506] - Eagerly caching bean 'Sybase' to allow for resolving potential circular references
TEST 2015-02-05 21:39:37,704 DEBUG [][main] org.springframework.beans.factory.support.DefaultListableBeanFactory [AbstractAutowireCapableBeanFactory.java:460] - Finished creating instance of bean 'Sybase'
TEST 2015-02-05 21:39:37,704 INFO  [][main] org.springframework.jdbc.support.SQLErrorCodesFactory [SQLErrorCodesFactory.java:126] - SQLErrorCodes loaded: [DB2, Derby, H2, HSQL, Informix, MS-SQL, MySQL, Oracle, PostgreSQL, Sybase]
TEST 2015-02-05 21:39:37,704 DEBUG [][main] org.springframework.jdbc.support.SQLErrorCodesFactory [SQLErrorCodesFactory.java:199] - Looking up default SQLErrorCodes for DataSource [com.atomikos.jdbc.SimpleDataSourceBean@7a93d960]
TEST 2015-02-05 21:39:37,706 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,706 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating getMetaData to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@338a88f7
TEST 2015-02-05 21:39:37,707 DEBUG [][main] org.springframework.jdbc.support.SQLErrorCodesFactory [SQLErrorCodesFactory.java:217] - Database product name cached for DataSource [com.atomikos.jdbc.SimpleDataSourceBean@7a93d960]: name is 'MySQL'
TEST 2015-02-05 21:39:37,707 DEBUG [][main] org.springframework.jdbc.support.SQLErrorCodesFactory [SQLErrorCodesFactory.java:175] - SQL error codes for 'MySQL' found
TEST 2015-02-05 21:39:37,707 DEBUG [][main] org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator [SQLErrorCodeSQLExceptionTranslator.java:287] - Unable to translate SQLException with Error code '1048', will now try the fallback translator
TEST 2015-02-05 21:39:37,708 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:851] - Participating transaction failed - marking existing transaction as rollback-only
TEST 2015-02-05 21:39:37,708 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [JtaTransactionManager.java:1062] - Setting JTA transaction rollback-only
TEST 2015-02-05 21:39:37,708 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,708 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,709 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 entering state: ACTIVE
TEST 2015-02-05 21:39:37,709 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - setRollbackOnly() called for transaction 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,709 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:287] - Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3c123b4a]
TEST 2015-02-05 21:39:37,709 DEBUG [][main] org.mybatis.spring.SqlSessionUtils [SqlSessionUtils.java:292] - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3c123b4a]
TEST 2015-02-05 21:39:37,710 DEBUG [][main] org.springframework.jdbc.datasource.DataSourceUtils [DataSourceUtils.java:327] - Returning JDBC Connection to DataSource
TEST 2015-02-05 21:39:37,710 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,710 DEBUG [][main] com.atomikos.jdbc.ConnectionProxy [Slf4jLogger.java:20] - JDBC ConnectionProxy: delegating close to connection com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@338a88f7
TEST 2015-02-05 21:39:37,710 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.end ( 3139322E3136382E312E33332E746D30303030333030303331:3139322E3136382E312E33332E746D33 , XAResource.TMSUCCESS ) on resource mysql/order represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@2acf062d
TEST 2015-02-05 21:39:37,710 DEBUG [][main] org.springframework.transaction.jta.JtaTransactionManager [AbstractPlatformTransactionManager.java:844] - Initiating transaction rollback
TEST 2015-02-05 21:39:37,710 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,710 DEBUG [][main] com.atomikos.icatch.imp.BaseTransactionManager [Slf4jLogger.java:20] - getCompositeTransaction()  returning instance with id 192.168.1.33.tm0000300031
TEST 2015-02-05 21:39:37,711 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 entering state: ABORTING
TEST 2015-02-05 21:39:37,711 INFO  [][main] com.atomikos.datasource.xa.XAResourceTransaction [Slf4jLogger.java:16] - XAResource.rollback ( 3139322E3136382E312E33332E746D30303030333030303331:3139322E3136382E312E33332E746D33 ) on resource mysql/order represented by XAResource instance com.mysql.jdbc.jdbc2.optional.JDBC4MysqlXAConnection@2acf062d
TEST 2015-02-05 21:39:37,712 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 entering state: TERMINATED
TEST 2015-02-05 21:39:37,712 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 : stopping timer...
TEST 2015-02-05 21:39:37,712 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 : disposing statehandler TERMINATED...
TEST 2015-02-05 21:39:37,712 DEBUG [][main] com.atomikos.icatch.imp.CoordinatorImp [Slf4jLogger.java:20] - Coordinator 192.168.1.33.tm0000300031 : disposed.
TEST 2015-02-05 21:39:37,715 DEBUG [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:33] - Ignoring error during event callback
java.lang.IllegalStateException: Transaction no longer active
at com.atomikos.icatch.imp.TxTerminatedStateHandler.rollbackWithStateCheck(TxTerminatedStateHandler.java:106) ~[transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CompositeTransactionImp.doRollback(CompositeTransactionImp.java:237) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CompositeTerminatorImp.rollback(CompositeTerminatorImp.java:123) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CompositeTransactionImp.rollback(CompositeTransactionImp.java:346) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CompositeTransactionImp.entered(CompositeTransactionImp.java:373) [transactions-3.9.3.jar:na]
at com.atomikos.finitestates.FSMImp.notifyListeners(FSMImp.java:188) [atomikos-util-3.9.3.jar:na]
at com.atomikos.finitestates.FSMImp.setState(FSMImp.java:279) [atomikos-util-3.9.3.jar:na]
at com.atomikos.icatch.imp.CoordinatorImp.setState(CoordinatorImp.java:416) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CoordinatorImp.setStateHandler(CoordinatorImp.java:273) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CoordinatorStateHandler.rollbackFromWithinCallback(CoordinatorStateHandler.java:769) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.ActiveStateHandler$7.doRollback(ActiveStateHandler.java:319) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CoordinatorStateHandler.rollbackWithAfterCompletionNotification(CoordinatorStateHandler.java:832) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.ActiveStateHandler.rollbackWithAfterCompletionNotification(ActiveStateHandler.java:49) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.ActiveStateHandler.rollback(ActiveStateHandler.java:314) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CoordinatorImp.rollback(CoordinatorImp.java:741) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.TransactionStateHandler.rollback(TransactionStateHandler.java:185) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.TransactionStateHandler.rollbackWithStateCheck(TransactionStateHandler.java:203) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CompositeTransactionImp.doRollback(CompositeTransactionImp.java:237) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CompositeTerminatorImp.rollback(CompositeTerminatorImp.java:123) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.imp.CompositeTransactionImp.rollback(CompositeTransactionImp.java:346) [transactions-3.9.3.jar:na]
at com.atomikos.icatch.jta.TransactionImp.rollback(TransactionImp.java:217) [transactions-jta-3.9.3.jar:na]
at com.atomikos.icatch.jta.TransactionManagerImp.rollback(TransactionManagerImp.java:448) [transactions-jta-3.9.3.jar:na]
at com.atomikos.icatch.jta.UserTransactionImp.rollback(UserTransactionImp.java:118) [transactions-jta-3.9.3.jar:na]
at org.springframework.transaction.jta.JtaTransactionManager.doRollback(JtaTransactionManager.java:1038) [org.springframework.transaction-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:846) [org.springframework.transaction-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:823) [org.springframework.transaction-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:493) [org.springframework.transaction-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:264) [org.springframework.transaction-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94) [org.springframework.transaction-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) [spring-aop-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:631) [spring-aop-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.lottery.common.service.order.OrderService$$EnhancerByCGLIB$$682962a3.add(<generated>) [spring-core-3.2.4.RELEASE.jar:na]
at org.lottery.common.service.user.UserService.main(UserService.java:106) [classes/:na]
TEST 2015-02-05 21:39:37,716 DEBUG [][main] com.atomikos.jdbc.ConnectionPool [Slf4jLogger.java:20] - Putting connection back in pool: ExternalXAPooledConnectionImp1423143566343com.atomikos.jdbc.ExclusiveExternalXAPooledConnectionImp@5ccaed61
TEST 2015-02-05 21:39:37,716 INFO  [][main] com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - rollback() done of transaction 192.168.1.33.tm0000300031
Exception in thread "main" org.springframework.dao.DataIntegrityViolationException: 
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Column 'user_id' cannot be null
### The error may involve org.lottery.common.mapper.order.TbOrderMapper.insert-Inline
### The error occurred while setting parameters
### SQL: insert into tb_order (order_id, user_id, game_id,   issue_number, bets, prices,   status, bonus, awards,   create_time, client_id, client_ty   )   values (?, ?,   ?,   ?, ?, ?,   ?, ?,   ?,   ?, ?, ?   )
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Column 'user_id' cannot be null
; SQL []; Column 'user_id' cannot be null; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Column 'user_id' cannot be null
at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:86)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80)
at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:73)
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:371)
at com.sun.proxy.$Proxy11.insert(Unknown Source)
at org.mybatis.spring.SqlSessionTemplate.insert(SqlSessionTemplate.java:240)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:51)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:52)
at com.sun.proxy.$Proxy21.insert(Unknown Source)
at org.lottery.common.service.order.OrderService.add(OrderService.java:50)
at org.lottery.common.service.order.OrderService$$FastClassByCGLIB$$f036414.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:698)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:631)
at org.lottery.common.service.order.OrderService$$EnhancerByCGLIB$$682962a3.add(<generated>)
at org.lottery.common.service.user.UserService.main(UserService.java:106)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Column 'user_id' cannot be null
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:408)
at com.mysql.jdbc.Util.getInstance(Util.java:383)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1049)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4226)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4158)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2776)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2840)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2082)
at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1302)
at com.mysql.jdbc.jdbc2.optional.PreparedStatementWrapper.execute(PreparedStatementWrapper.java:820)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:62)
at com.sun.proxy.$Proxy28.execute(Unknown Source)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:44)
at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:69)
at org.apache.ibatis.executor.ReuseExecutor.doUpdate(ReuseExecutor.java:50)
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:105)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:152)
at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:141)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:358)
... 23 more
TEST 2015-02-05 21:39:37,738 DEBUG [][Thread-8] com.atomikos.icatch.system.Configuration [Slf4jLogger.java:20] - Configuration: removed resource mysql/sporttery
TEST 2015-02-05 21:39:37,739 DEBUG [][Thread-6] com.atomikos.icatch.system.Configuration [Slf4jLogger.java:20] - Configuration: removed resource mysql/order
TEST 2015-02-05 21:39:37,740 DEBUG [][Thread-2] com.atomikos.icatch.system.Configuration [Slf4jLogger.java:20] - Configuration: removed resource mysql/game
TEST 2015-02-05 21:39:37,740 DEBUG [][Thread-4] com.atomikos.icatch.system.Configuration [Slf4jLogger.java:20] - Configuration: removed resource mysql/user






加载中
0
Alex.Wong
Alex.Wong
分片事务,基本概念没了解
0
bboss
bboss

整得这么高大上,如果只是想多个数据库事务,可以参考和采用bboss持久层的事务框架来管理多数据库事务:


bboss持久层多数据源配置及多数据库事务控制使用方法 

补充一下,bboss的全局事务管理框架还可以托管spring jdbc,ibatis/mybatis,hibernate等第三方持久层框架的事务呢


0
萧萧刀
萧萧刀
找到原因了吗?
Alex.Wong
Alex.Wong
回复 @王柏宇 : 2年前的项目了,给忘了。可以的话,贴上你的代码给大家看看~~
王柏宇
王柏宇
@Alex.Wong 同样遇到了这个问题,请问你是怎么解决的 ?
zdp2014
zdp2014
回复 @Alex.Wong : 哪块事物没加啊,日志里面都有rollback com.atomikos.icatch.imp.CompositeTransactionImp [Slf4jLogger.java:16] - rollback() done of transaction 192.168.1.33.tm0000300031
Alex.Wong
Alex.Wong
找到了,没加事务
返回顶部
顶部