spring3+mybatis3+atomikos3事务无效403.10 禁止访问：配置无效 

今天整合基于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]