data inserted into db after spring transaction rollback

Question

I'm testing my declartive transaction configuration with following testcase:

I try to insert 2 record into a table with 4 columns(id, content, position, time) while position is a UNIQUE index. I use mysql 5.5 with innoDB engine, and develop the test with Spring 3.2.2, Mybatis 3.2.2, Mybatis-Spring 1.2.0. below is the sql to create the database and table with experimental data inserted.

    CREATE DATABASE `development` DEFAULT CHARACTER SET utf8 COLLATE utf8_general_ci;
    USE `development`;

    CREATE TABLE IF NOT EXISTS `test` (
      `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
      `content` varchar(256) DEFAULT NULL,
      `position` int(10) unsigned NOT NULL,
      `time` int(10) unsigned NOT NULL DEFAULT '0',
      PRIMARY KEY (`id`),
      UNIQUE KEY `position` (`position`)
    ) ENGINE=InnoDB  DEFAULT CHARSET=utf8 AUTO_INCREMENT=97 ;

    INSERT INTO `test` (`id`, `content`, `position`, `time`) VALUES (1, 'test', 0, 1368164281),(2, '测试内容', 1, 1368164364),(44, 'bbb', 2, 1368431459),(45, 'ccc', 3, 1368431459),

Here is the configuration xml service.xml:

<beans xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:aop="http://www.springframework.org/schema/aop"
    xmlns:tx="http://www.springframework.org/schema/tx"
    xsi:schemaLocation="
    http://www.springframework.org/schema/beans
    http://www.springframework.org/schema/beans/spring-beans.xsd
    http://www.springframework.org/schema/tx
    http://www.springframework.org/schema/tx/spring-tx.xsd
    http://www.springframework.org/schema/aop
    http://www.springframework.org/schema/aop/spring-aop.xsd">
    <bean id="testDataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource" destroy-method="close">
        <property name="driverClassName" value="${test.driverClass}" />
        <property name="url" value="${test.jdbcUrl}" />
        <property name="username" value="${test.user}" />
        <property name="password" value="${test.password}" />
        <property name="minPoolSize" value="${test.miniPoolSize}" />
        <property name="maxPoolSize" value="${test.maxPoolSize}" />
        <property name="initialPoolSize" value="${test.initialPoolSize}" />
        <property name="maxIdleTime" value="${test.maxIdleTime}" />
        <property name="acquireIncrement" value="${test.acquireIncrement}" />
        <property name="acquireRetryAttempts" value="${test.acquireRetryAttempts}" />
        <property name="acquireRetryDelay" value="${test.acquireRetryDelay}" />
        <property name="testConnectionOnCheckin" value="${test.testConnectionOnCheckin}" />
        <property name="automaticTestTable" value="${test.automaticTestTable}" />
        <property name="idleConnectionTestPeriod" value="${test.idleConnectionTestPeriod}" />
        <property name="checkoutTimeout" value="${test.checkoutTimeout}" />
    </bean>

    <bean id="txManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager">  
        <property name="dataSource" ref="testDataSource" />
    </bean>

    <tx:advice id="txAdvice" transaction-manager="txManager">
        <tx:attributes>
            <tx:method name="get*" read-only="true" />
            <tx:method name="add*" />
        </tx:attributes>
    </tx:advice>
    <aop:config>
        <aop:pointcut id="testServiceOperation" expression="execution(* com.ssports.test.service.TestServiceImpl.addRecords(..))" />
        <aop:advisor advice-ref="txAdvice" pointcut-ref="testServiceOperation" />
    </aop:config>

    <bean id="TestService" class="com.ssports.test.service.TestServiceImpl" />
</beans>

Below is the test-mapper-config.xml:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:mybatis-spring="http://mybatis.org/schema/mybatis-spring"
    xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd
http://mybatis.org/schema/mybatis-spring http://mybatis.org/schema/mybatis-spring-1.2.xsd">

    <bean id="recordMapper" class="org.mybatis.spring.mapper.MapperFactoryBean">
    <property name="sqlSessionFactory" ref="testSqlSessionFactory" />
    <property name="mapperInterface" value="com.ssports.test.mapper.RecordMapper" />
    </bean>
</beans>

Here is the serviceImpl class:

package com.ssports.test.service;

import java.util.List;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.jdbc.datasource.DataSourceTransactionManager;

import com.ssports.test.mapper.RecordMapper;
import com.ssports.test.model.Record;
import com.ssports.test.model.RecordExample;
import com.ssports.util.SpringHelper;

public class TestServiceImpl implements TestService {
    Logger logger = LoggerFactory.getLogger(TestServiceImpl.class);
    private static RecordMapper mapper = SpringHelper.getBean("recordMapper");

    public List<Record> getAll() {
        return mapper.selectByExample(new RecordExample());
    }

    public Record getRecordbyId(int id) {
        return mapper.selectByPrimaryKey(id);
    }

    public void addRecords(List<Record> recordList) throws Exception {
           for (Record record : recordList) {
                logger.info(record.getPosition() + ":" + record.getTime());
                    mapper.insert(record);
        }
    }

}

the test code is: package com.ssports.db;

import java.util.ArrayList;
import java.util.Date;
import java.util.List;


import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.jdbc.datasource.DataSourceTransactionManager;

import com.ssports.test.model.Record;
import com.ssports.test.service.TestService;
import com.ssports.util.SpringHelper;

public class TransTest {
    /**
     * @param args
     * @throws Exception
     */
    public static void main(String[] args) throws Exception {
        Logger logger = LoggerFactory.getLogger(TransTest.class);

        TestService service = SpringHelper.getBean("TestService");
        List<Record> records = new ArrayList<Record>();

        Record record1 = service.getRecordbyId(1);
        Record record4 = new Record();
        record4.setContent("ddd");
        record4.setPosition(4);
        record4.setTime((int) (new Long(System.currentTimeMillis()) / 1000));

        records.add(record4);
        records.add(record1);

        DataSourceTransactionManager txManager = SpringHelper.getBean("txManager");
        try {
            service.addRecords(records);
        } catch (UnsupportedOperationException ex) {            
            logger.info(ex.getMessage());
        }

        List<Record> recordlist = service.getAll();
        for (Record item : recordlist) {
            logger.info(item.getId() + ":" + item.getContent() + ":"
                    + new Date((long) item.getTime() * 1000) + ":"
                    + item.getPosition());
        }

    }

}

I run the application, and here is the log:

DEBUG: org.springframework.transaction.interceptor.NameMatchTransactionAttributeSource - Adding transactional method [get*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly]
DEBUG: org.springframework.transaction.interceptor.NameMatchTransactionAttributeSource - Adding transactional method [add*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT]
DEBUG: org.springframework.transaction.interceptor.NameMatchTransactionAttributeSource - Adding transactional method [get*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly]
DEBUG: org.springframework.transaction.interceptor.NameMatchTransactionAttributeSource - Adding transactional method [add*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT]
DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [com.ssports.test.service.TestServiceImpl.addRecords]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [org.apache.commons.dbcp.PoolableConnection@6650af3b] for JDBC transaction
DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [org.apache.commons.dbcp.PoolableConnection@6650af3b] to manual commit
INFO : com.ssports.test.service.TestServiceImpl - 4:1368602606
INFO : com.ssports.test.service.TestServiceImpl - 0:1368164281
DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction rollback
DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Rolling back JDBC transaction on Connection [org.apache.commons.dbcp.PoolableConnection@6650af3b]
DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [org.apache.commons.dbcp.PoolableConnection@6650af3b] after transaction
INFO : com.ssports.db.TransTest - 
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1' for key 'PRIMARY'
### The error may involve com.ssports.test.mapper.RecordMapper.insert-Inline
### The error occurred while setting parameters
### SQL: insert into test (id, content, position,        time)     values (?, ?, ?,        ?)
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1' for key 'PRIMARY'
; SQL []; Duplicate entry '1' for key 'PRIMARY'; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1' for key 'PRIMARY'
INFO : com.ssports.db.TransTest - 1:test:Fri May 10 13:38:01 CST 2013:0
INFO : com.ssports.db.TransTest - 2:测试内容:Fri May 10 13:39:24 CST 2013:1
INFO : com.ssports.db.TransTest - 44:bbb:Mon May 13 15:50:59 CST 2013:2
INFO : com.ssports.db.TransTest - 45:ccc:Mon May 13 15:50:59 CST 2013:3
INFO : com.ssports.db.TransTest - 98:ddd:Wed May 15 15:23:26 CST 2013:4

you can see that while the exception throw, the transaction manager roll the database back, but a record still insert into it.

Is there anyone can tell what wrong here, or is it a bug?

updated

I tried programatic transaction with code below, of course comment the lines in service.xml to disable the aop and txAdvice. after that,it works:

package com.ssports.test.service;

import java.util.List;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.jdbc.datasource.DataSourceTransactionManager;
import org.springframework.transaction.TransactionDefinition;
import org.springframework.transaction.TransactionStatus;
import org.springframework.transaction.support.DefaultTransactionDefinition;

import com.ssports.test.mapper.RecordMapper;
import com.ssports.test.model.Record;
import com.ssports.test.model.RecordExample;
import com.ssports.util.SpringHelper;

public class TestServiceImpl implements TestService {
    Logger logger = LoggerFactory.getLogger(TestServiceImpl.class);
    private static RecordMapper mapper = SpringHelper.getBean("recordMapper");
    private static DataSourceTransactionManager txManager = SpringHelper.getBean("txManager");
    private static TransactionDefinition def = new DefaultTransactionDefinition();
    private static TransactionStatus status = txManager.getTransaction(def);

    public List<Record> getAll() {
        return mapper.selectByExample(new RecordExample());
    }

    public Record getRecordbyId(int id) {
        Thread t = Thread.currentThread();
        logger.debug("Thread Name: "+t.getName());
        logger.debug("Thread id: "+t.getId());
        return mapper.selectByPrimaryKey(id);
    }

    public void addRecords(List<Record> recordList) throws Exception {


        try {
        for (Record record : recordList) {
            Thread t = Thread.currentThread();
            logger.debug("Thread Name: "+t.getName());
            logger.debug("Thread id: "+t.getId());
            logger.info(record.getPosition() + ":" + record.getTime());
            mapper.insert(record);
        }
        } catch (Exception ex) {
            logger.debug("Exception throw");
            logger.debug(ex.getMessage());
            txManager.rollback(status);
            throw ex;
        }

        txManager.commit(status);
    }

}

Here is the log:

2013-05-16 11:23:17 625 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed configuration file: 'class path resource [config/mybatis-config.xml]'
2013-05-16 11:23:17 929 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed mapper file: 'file [/home/zhangzhi/workspace-STS/MultiDb/target/classes/com/ssports/uc/mybatis/mappers/UcMemberMapper.xml]'
2013-05-16 11:23:17 948 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed configuration file: 'class path resource [config/mybatis-config.xml]'
2013-05-16 11:23:18 247 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed mapper file: 'file [/home/zhangzhi/workspace-STS/MultiDb/target/classes/com/ssports/site/mybatis/mappers/adMapper.xml]'
2013-05-16 11:23:18 264 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed configuration file: 'class path resource [config/mybatis-config.xml]'
2013-05-16 11:23:18 316 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed mapper file: 'file [/home/zhangzhi/workspace-STS/MultiDb/target/classes/com/ssports/test/mybatis/mappers/RecordMapper.xml]'
2013-05-16 11:23:18 476 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed configuration file: 'class path resource [config/mybatis-config.xml]'
2013-05-16 11:23:18 546 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed mapper file: 'file [/home/zhangzhi/workspace-STS/MultiDb/target/classes/com/ssports/uc/mybatis/mappers/UcMemberMapper.xml]'
2013-05-16 11:23:18 556 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed configuration file: 'class path resource [config/mybatis-config.xml]'
2013-05-16 11:23:18 680 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed mapper file: 'file [/home/zhangzhi/workspace-STS/MultiDb/target/classes/com/ssports/site/mybatis/mappers/adMapper.xml]'
2013-05-16 11:23:18 690 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed configuration file: 'class path resource [config/mybatis-config.xml]'
2013-05-16 11:23:18 728 DEBUG: org.mybatis.spring.SqlSessionFactoryBean - Parsed mapper file: 'file [/home/zhangzhi/workspace-STS/MultiDb/target/classes/com/ssports/test/mybatis/mappers/RecordMapper.xml]'
2013-05-16 11:23:18 739 DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2013-05-16 11:23:18 740 DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [org.apache.commons.dbcp.PoolableConnection@6188024d] for JDBC transaction
2013-05-16 11:23:18 747 DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [org.apache.commons.dbcp.PoolableConnection@6188024d] to manual commit
2013-05-16 11:23:18 748 DEBUG: com.ssports.db.TransTest - Get record1.
2013-05-16 11:23:18 749 DEBUG: com.ssports.db.TransTest - Thread Name: main
2013-05-16 11:23:18 749 DEBUG: com.ssports.db.TransTest - Thread id: 1
2013-05-16 11:23:18 749 DEBUG: com.ssports.test.service.TestServiceImpl - Thread Name: main
2013-05-16 11:23:18 749 DEBUG: com.ssports.test.service.TestServiceImpl - Thread id: 1
2013-05-16 11:23:18 754 DEBUG: org.mybatis.spring.SqlSessionUtils - Creating a new SqlSession
2013-05-16 11:23:18 757 DEBUG: org.mybatis.spring.SqlSessionUtils - Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810]
2013-05-16 11:23:18 776 DEBUG: org.mybatis.spring.transaction.SpringManagedTransaction - JDBC Connection [org.apache.commons.dbcp.PoolableConnection@6188024d] will be managed by Spring
2013-05-16 11:23:18 777 DEBUG: com.ssports.test.mapper.RecordMapper.selectByPrimaryKey - ooo Using Connection [org.apache.commons.dbcp.PoolableConnection@6188024d]
2013-05-16 11:23:18 783 DEBUG: com.ssports.test.mapper.RecordMapper.selectByPrimaryKey - ==>  Preparing: select id, content, position, time from test where id = ? 
2013-05-16 11:23:18 807 DEBUG: com.ssports.test.mapper.RecordMapper.selectByPrimaryKey - ==> Parameters: 1(Integer)
2013-05-16 11:23:18 824 DEBUG: org.mybatis.spring.SqlSessionUtils - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810]
2013-05-16 11:23:18 824 DEBUG: com.ssports.db.TransTest - Invoking service method[addRecords]
2013-05-16 11:23:18 824 DEBUG: com.ssports.db.TransTest - Thread Name: main
2013-05-16 11:23:18 824 DEBUG: com.ssports.db.TransTest - Thread id: 1
2013-05-16 11:23:18 824 DEBUG: com.ssports.test.service.TestServiceImpl - Thread Name: main
2013-05-16 11:23:18 824 DEBUG: com.ssports.test.service.TestServiceImpl - Thread id: 1
2013-05-16 11:23:18 824 INFO : com.ssports.test.service.TestServiceImpl - 4:1368674598
2013-05-16 11:23:18 824 DEBUG: org.mybatis.spring.SqlSessionUtils - Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810] from current transaction
2013-05-16 11:23:18 825 DEBUG: com.ssports.test.mapper.RecordMapper.insert - ooo Using Connection [org.apache.commons.dbcp.PoolableConnection@6188024d]
2013-05-16 11:23:18 825 DEBUG: com.ssports.test.mapper.RecordMapper.insert - ==>  Preparing: insert into test (id, content, position, time) values (?, ?, ?, ?) 
2013-05-16 11:23:18 825 DEBUG: com.ssports.test.mapper.RecordMapper.insert - ==> Parameters: null, ddd(String), 4(Integer), 1368674598(Integer)
2013-05-16 11:23:18 826 DEBUG: org.mybatis.spring.SqlSessionUtils - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810]
2013-05-16 11:23:18 826 DEBUG: com.ssports.test.service.TestServiceImpl - Thread Name: main
2013-05-16 11:23:18 826 DEBUG: com.ssports.test.service.TestServiceImpl - Thread id: 1
2013-05-16 11:23:18 826 INFO : com.ssports.test.service.TestServiceImpl - 0:1368164281
2013-05-16 11:23:18 826 DEBUG: org.mybatis.spring.SqlSessionUtils - Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810] from current transaction
2013-05-16 11:23:18 826 DEBUG: com.ssports.test.mapper.RecordMapper.insert - ooo Using Connection [org.apache.commons.dbcp.PoolableConnection@6188024d]
2013-05-16 11:23:18 826 DEBUG: com.ssports.test.mapper.RecordMapper.insert - ==>  Preparing: insert into test (id, content, position, time) values (?, ?, ?, ?) 
2013-05-16 11:23:18 826 DEBUG: com.ssports.test.mapper.RecordMapper.insert - ==> Parameters: null, test(String), 0(Integer), 1368164281(Integer)
2013-05-16 11:23:18 871 DEBUG: org.mybatis.spring.SqlSessionUtils - Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810]
2013-05-16 11:23:18 871 DEBUG: com.ssports.test.service.TestServiceImpl - Exception throw
2013-05-16 11:23:18 871 DEBUG: com.ssports.test.service.TestServiceImpl - 
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '0' for key 'position'
### The error may involve com.ssports.test.mapper.RecordMapper.insert-Inline
### The error occurred while setting parameters
### SQL: insert into test (id, content, position,        time)     values (?, ?, ?,        ?)
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '0' for key 'position'
; SQL []; Duplicate entry '0' for key 'position'; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '0' for key 'position'
2013-05-16 11:23:18 871 DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction rollback
2013-05-16 11:23:18 871 DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Rolling back JDBC transaction on Connection [org.apache.commons.dbcp.PoolableConnection@6188024d]
2013-05-16 11:23:18 907 DEBUG: org.mybatis.spring.SqlSessionUtils - Transaction synchronization rolling back SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810]
2013-05-16 11:23:18 907 DEBUG: org.mybatis.spring.SqlSessionUtils - Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@158b6810]
2013-05-16 11:23:18 908 DEBUG: org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [org.apache.commons.dbcp.PoolableConnection@6188024d] after transaction
2013-05-16 11:23:18 909 DEBUG: com.ssports.db.TransTest - Exception throw
2013-05-16 11:23:18 909 DEBUG: com.ssports.db.TransTest - 
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '0' for key 'position'
### The error may involve com.ssports.test.mapper.RecordMapper.insert-Inline
### The error occurred while setting parameters
### SQL: insert into test (id, content, position,        time)     values (?, ?, ?,        ?)
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '0' for key 'position'
; SQL []; Duplicate entry '0' for key 'position'; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '0' for key 'position'
2013-05-16 11:23:18 909 DEBUG: com.ssports.db.TransTest - Checking Result
2013-05-16 11:23:18 909 DEBUG: org.mybatis.spring.SqlSessionUtils - Creating a new SqlSession
2013-05-16 11:23:18 909 DEBUG: org.mybatis.spring.SqlSessionUtils - SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2c8446f7] was not registered for synchronization because synchronization is not active
2013-05-16 11:23:18 929 DEBUG: org.mybatis.spring.transaction.SpringManagedTransaction - JDBC Connection [org.apache.commons.dbcp.PoolableConnection@6188024d] will not be managed by Spring
2013-05-16 11:23:18 929 DEBUG: com.ssports.test.mapper.RecordMapper.selectByExample - ooo Using Connection [org.apache.commons.dbcp.PoolableConnection@6188024d]
2013-05-16 11:23:18 929 DEBUG: com.ssports.test.mapper.RecordMapper.selectByExample - ==>  Preparing: select id, content, position, time from test 
2013-05-16 11:23:18 930 DEBUG: com.ssports.test.mapper.RecordMapper.selectByExample - ==> Parameters: 
2013-05-16 11:23:18 931 DEBUG: org.mybatis.spring.SqlSessionUtils - Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2c8446f7]
2013-05-16 11:23:18 932 INFO : com.ssports.db.TransTest - 1:test:Fri May 10 13:38:01 CST 2013:0
2013-05-16 11:23:18 932 INFO : com.ssports.db.TransTest - 2:测试内容:Fri May 10 13:39:24 CST 2013:1
2013-05-16 11:23:18 932 INFO : com.ssports.db.TransTest - 44:bbb:Mon May 13 15:50:59 CST 2013:2
2013-05-16 11:23:18 932 INFO : com.ssports.db.TransTest - 45:ccc:Mon May 13 15:50:59 CST 2013:3

and here is the SpringHelper Class:

package com.ssports.util;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.context.ApplicationContext;
import org.springframework.context.support.ClassPathXmlApplicationContext;

public class SpringHelper {

    private static Log logger = LogFactory.getLog(SpringHelper.class);

    private static ApplicationContext cx = null;

    @SuppressWarnings("unchecked")
    public static <T> T getBean(String beanId){
        if(cx == null){
          cx = new ClassPathXmlApplicationContext("classpath:spring/application-context.xml");
        }
        return (T)cx.getBean(beanId);
    }

    public synchronized static void init(){
        if(cx == null){
          cx = new ClassPathXmlApplicationContext("classpath:spring/application-context.xml");
          logger.info("Spring config success!,ApplicationContext set a object");
        }
    }

    public synchronized static void init(String[] paths){

        if(cx == null){
          cx = new ClassPathXmlApplicationContext(paths);
          logger.info("Spring config success!,ApplicationContext set a object");
        }

    }

    public synchronized static void init(String path){

        init(new String[]{path});
    }

}

updated I‘ve made a little change on TestServiceImpl, and it's solved, as below:

private static RecordMapper mapper;

public void init() {
    if (null == mapper) {
        mapper = (RecordMapper) SpringHelper.getBean("recordMapper");
    }
}

Answer 1

The problem:

I would say that the problem is in your SpringHelper class implementation and how you are using it (namely the static reference in TestServiceImpl). You might have two Spring contexts initialized (symptoms for this are contained within the first 4 lines of your log file).

Why it does not work:

Transaction+rollback in one context does not have any effect on the DB connection made by the other context (both have their own testDataSource and txManager beans).

How to solve it:

Spring is a dependency injection framework, so I don't see a point for implementing your own dependency lookup strategy. You might want to check Autowired annotation for getting depdendencies (such as your TestServiceImpl.mapper) in place.

Check Spring documentation and demo projects (e.g. https://github.com/SpringSource/greenhouse) to see how to get the best out of Spring. Try to use Spring in a standard way.

Additional AOP issue:

Btw. your pointcut definition is not correct as the read-only advice is not covered by that.