data inserted into db after spring transaction rollback -

i'm testing declartive transaction configuration following testcase:

i try insert 2 record table 4 columns(id, content, position, time) while position unique index. use mysql 5.5 innodb engine, , develop test spring 3.2.2, mybatis 3.2.2, mybatis-spring 1.2.0. below sql create database , table 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 `test` (`id`, `content`, `position`, `time`) values (1, 'test', 0, 1368164281),(2, '测试内容', 1, 1368164364),(44, 'bbb', 2, 1368431459),(45, 'ccc', 3, 1368431459), 

here 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 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 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 {            (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();         (record item : recordlist) {             logger.info(item.getid() + ":" + item.getcontent() + ":"                     + new date((long) item.gettime() * 1000) + ":"                     + item.getposition());         }      }  } 

i run application, , here log:

debug: org.springframework.transaction.interceptor.namematchtransactionattributesource - adding transactional method [get*] attribute [propagation_required,isolation_default,readonly] debug: org.springframework.transaction.interceptor.namematchtransactionattributesource - adding transactional method [add*] attribute [propagation_required,isolation_default] debug: org.springframework.transaction.interceptor.namematchtransactionattributesource - adding transactional method [get*] attribute [propagation_required,isolation_default,readonly] debug: org.springframework.transaction.interceptor.namematchtransactionattributesource - adding transactional method [add*] attribute [propagation_required,isolation_default] debug: org.springframework.jdbc.datasource.datasourcetransactionmanager - creating new transaction 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] jdbc transaction debug: org.springframework.jdbc.datasource.datasourcetransactionmanager - switching jdbc connection [org.apache.commons.dbcp.poolableconnection@6650af3b] 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 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' key 'primary' ### error may involve com.ssports.test.mapper.recordmapper.insert-inline ### error occurred while setting parameters ### sql: insert test (id, content, position,        time)     values (?, ?, ?,        ?) ### cause: com.mysql.jdbc.exceptions.jdbc4.mysqlintegrityconstraintviolationexception: duplicate entry '1' key 'primary' ; sql []; duplicate entry '1' key 'primary'; nested exception com.mysql.jdbc.exceptions.jdbc4.mysqlintegrityconstraintviolationexception: duplicate entry '1' 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 while exception throw, transaction manager roll database back, record still insert it.

is there can tell wrong here, or bug?

updated

i tried programatic transaction code below, of course comment lines in service.xml disable aop , 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 {         (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 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 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] jdbc transaction 2013-05-16 11:23:18 747 debug: org.springframework.jdbc.datasource.datasourcetransactionmanager - switching jdbc connection [org.apache.commons.dbcp.poolableconnection@6188024d] manual commit 2013-05-16 11:23:18 748 debug: com.ssports.db.transtest - 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 new sqlsession 2013-05-16 11:23:18 757 debug: org.mybatis.spring.sqlsessionutils - registering transaction synchronization 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] managed 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 test 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] 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 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] 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 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' key 'position' ### error may involve com.ssports.test.mapper.recordmapper.insert-inline ### error occurred while setting parameters ### sql: insert test (id, content, position,        time)     values (?, ?, ?,        ?) ### cause: com.mysql.jdbc.exceptions.jdbc4.mysqlintegrityconstraintviolationexception: duplicate entry '0' key 'position' ; sql []; duplicate entry '0' key 'position'; nested exception com.mysql.jdbc.exceptions.jdbc4.mysqlintegrityconstraintviolationexception: duplicate entry '0' 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 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 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' key 'position' ### error may involve com.ssports.test.mapper.recordmapper.insert-inline ### error occurred while setting parameters ### sql: insert test (id, content, position,        time)     values (?, ?, ?,        ?) ### cause: com.mysql.jdbc.exceptions.jdbc4.mysqlintegrityconstraintviolationexception: duplicate entry '0' key 'position' ; sql []; duplicate entry '0' key 'position'; nested exception com.mysql.jdbc.exceptions.jdbc4.mysqlintegrityconstraintviolationexception: duplicate entry '0' 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 new sqlsession 2013-05-16 11:23:18 909 debug: org.mybatis.spring.sqlsessionutils - sqlsession [org.apache.ibatis.session.defaults.defaultsqlsession@2c8446f7] not registered synchronization because synchronization not active 2013-05-16 11:23:18 929 debug: org.mybatis.spring.transaction.springmanagedtransaction - jdbc connection [org.apache.commons.dbcp.poolableconnection@6188024d] not managed 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 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 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 object");         }     }      public synchronized static void init(string[] paths){          if(cx == null){           cx = new classpathxmlapplicationcontext(paths);           logger.info("spring config success!,applicationcontext set object");         }      }      public synchronized static void init(string path){          init(new string[]{path});     }  } 

updated i‘ve made little change on testserviceimpl, , it's solved, below:

private static recordmapper mapper;  public void init() {     if (null == mapper) {         mapper = (recordmapper) springhelper.getbean("recordmapper");     } } 

the problem:

i problem in springhelper class implementation , how using (namely static reference in testserviceimpl). you might have 2 spring contexts initialized (symptoms contained within first 4 lines of log file).

why not work:

transaction+rollback in 1 context not have effect on db connection made other context (both have own testdatasource , txmanager beans).

how solve it:

spring dependency injection framework, don't see point implementing own dependency lookup strategy. might want check autowired annotation getting depdendencies (such testserviceimpl.mapper) in place.

check spring documentation , demo projects (e.g. https://github.com/springsource/greenhouse) see how best out of spring. try use spring in standard way.

additional aop issue:

btw. pointcut definition not correct read-only advice not covered that.