search

google-code-export / mybatis

Automatically exported from code.google.com/p/mybatis
0 stars 0 forks source link

spring-mybatis transaction rollback failed #490

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
What version of the MyBatis are you using?
Spring 3.0.6.RELEASE
mybatis 3.0.6
mybatis-spring 1.0.2

Please describe the problem.  Unit tests are best!
[Logic code]
@Service(value = "userErrBLogic")
public class UserErrBLogic  {

    @Resource(name = "updateDAO", type = UpdateDAO.class)
    protected UpdateDAO updateDAO;

    @Transactional
    public Integer execute(User param) {

        int ret = updateDAO.execute("user.insertUser", param);

        Log log = new Log();
        log.setLog(null); // This would cause "Column 'log' cannot be null" exception
        updateDAO.execute("log.insertLog", log);

        return ret;
    }
}

public class UpdateDAOMyBatisImpl extends SqlSessionDaoSupport implements 
UpdateDAO {

    @Override
    public int execute(String sqlID, Object bindParams) {
        int row = getSqlSession().update(sqlID, bindParams);

        return row;
    }
}

[Unit Test]
@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration(locations={"/applicationContext-dao.xml", 
"/applicationContext-blogic.xml"})
public class JdbcTransactionTest extends TestCase {

    @Resource(name="userErrBLogic", type = BLogic.class)
    private BLogic<User, Integer> userErrBLogic;

    @Test
    public void testJdbcTransactionRollback() throws SQLException {

        // Prepare data
        UTUtil.deleteAll(new String[] { "users", "log" });
        User user = new User();
        user.setName("tom");
        user.setLastLoginTime(1234567890L);

        try {
            // Run test
            userErrBLogic.execute(user);
            fail();
        } catch (Exception e) {
            Map<String, String>[] users = UTUtil.select("users");
            assertNotNull(users);
            assertEquals(0, users.length); // <-- Failed, insert user succeed.
        }
    }
}

What is the expected output? What do you see instead?
[DEBUG]log
[2012/01/09 16:13:51][INFO][TestContextManager] @TestExecutionListeners is not 
present for class [class ext.JdbcTransactionTest]: using defaults.
[2012/01/09 16:13:51][INFO][XmlBeanDefinitionReader] Loading XML bean 
definitions from class path resource [applicationContext-dao.xml]
[2012/01/09 16:13:51][INFO][XmlBeanDefinitionReader] Loading XML bean 
definitions from class path resource [applicationContext-blogic.xml]
[2012/01/09 16:13:51][INFO][GenericApplicationContext] Refreshing 
org.springframework.context.support.GenericApplicationContext@c980c9: startup 
date [Mon Jan 09 16:13:51 CST 2012]; root of context hierarchy
[2012/01/09 16:13:51][INFO][DefaultListableBeanFactory] Pre-instantiating 
singletons in 
org.springframework.beans.factory.support.DefaultListableBeanFactory@2b9406: 
defining beans 
[dataSource,transactionManager,org.springframework.aop.config.internalAutoProxyC
reator,org.springframework.transaction.annotation.AnnotationTransactionAttribute
Source#0,org.springframework.transaction.interceptor.TransactionInterceptor#0,or
g.springframework.transaction.config.internalTransactionAdvisor,sqlSessionFactor
y,queryDAO,updateDAO,userBLogic,userErrBLogic,org.springframework.context.annota
tion.internalConfigurationAnnotationProcessor,org.springframework.context.annota
tion.internalAutowiredAnnotationProcessor,org.springframework.context.annotation
.internalRequiredAnnotationProcessor,org.springframework.context.annotation.inte
rnalCommonAnnotationProcessor]; root of factory hierarchy
[2012/01/09 16:13:51][INFO][DriverManagerDataSource] Loaded JDBC driver: 
com.mysql.jdbc.Driver
[2012/01/09 16:13:51][DEBUG][LogFactory] Logging initialized using 
'org.apache.ibatis.logging.commons.JakartaCommonsLoggingImpl' adapter.
[2012/01/09 16:13:52][DEBUG][SqlSessionFactoryBean] Parsed configuration file: 
'class path resource [mybatis-config.xml]'
[2012/01/09 16:13:52][DEBUG][SqlSessionFactoryBean] Property 'mapperLocations' 
was not specified or no matching resources found
[2012/01/09 16:13:52][DEBUG][UpdateDAOMyBatisImpl] execute Start.
[2012/01/09 16:13:52][DEBUG][SqlSessionUtils] Creating SqlSession with JDBC 
Connection [com.mysql.jdbc.JDBC4Connection@1024994]
[2012/01/09 16:13:52][DEBUG][Connection] ooo Connection Opened
[2012/01/09 16:13:52][DEBUG][SpringManagedTransaction] JDBC Connection 
[com.mysql.jdbc.JDBC4Connection@1024994] will be managed by Spring
[2012/01/09 16:13:52][DEBUG][SqlSessionUtils] Registering transaction 
synchronization for SqlSession 
[org.apache.ibatis.session.defaults.DefaultSqlSession@5d855f]
[2012/01/09 16:13:52][DEBUG][PreparedStatement] ==>  Executing: insert into 
users ( name, last_login_time ) values ( ?, ?) 
[2012/01/09 16:13:52][DEBUG][PreparedStatement] ==> Parameters: tom(String), 
1234567890(Long)
[2012/01/09 16:13:52][DEBUG][SqlSessionUtils] Releasing transactional 
SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5d855f]
[2012/01/09 16:13:52][DEBUG][UpdateDAOMyBatisImpl] execute End. success count:1
[2012/01/09 16:13:52][DEBUG][UpdateDAOMyBatisImpl] execute Start.
[2012/01/09 16:13:52][DEBUG][SqlSessionUtils] Fetched SqlSession 
[org.apache.ibatis.session.defaults.DefaultSqlSession@5d855f] from current 
transaction
[2012/01/09 16:13:52][DEBUG][PreparedStatement] ==>  Executing: insert into log 
( log ) values ( ? ) 
[2012/01/09 16:13:52][DEBUG][PreparedStatement] ==> Parameters: null
[2012/01/09 16:13:52][INFO][XmlBeanDefinitionReader] Loading XML bean 
definitions from class path resource 
[org/springframework/jdbc/support/sql-error-codes.xml]
[2012/01/09 16:13:52][INFO][SQLErrorCodesFactory] SQLErrorCodes loaded: [DB2, 
Derby, H2, HSQL, Informix, MS-SQL, MySQL, Oracle, PostgreSQL, Sybase]
[2012/01/09 16:13:52][DEBUG][SqlSessionUtils] Releasing transactional 
SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5d855f]
[2012/01/09 16:13:52][DEBUG][SqlSessionUtils] Transaction synchronization 
closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5d855f]
org.springframework.dao.DataIntegrityViolationException: 
### Error updating database.  Cause: 
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: 
Column 'log' cannot be null
### The error may involve log.insertLog-Inline
### The error occurred while setting parameters
### Cause: 
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: 
Column 'log' cannot be null
; SQL []; Column 'log' cannot be null; nested exception is 
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: 
Column 'log' cannot be null
    at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:85)
    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:71)
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:358)
    at $Proxy13.update(Unknown Source)
    at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:246)
    at com.qunar.base.meerkat.orm.mybatis.UpdateDAOMyBatisImpl.execute(UpdateDAOMyBatisImpl.java:107)
    at com.qunar.base.meerkat.sample.blogic.UserErrBLogic.execute(UserErrBLogic.java:29)
    at com.qunar.base.meerkat.sample.blogic.UserErrBLogic.execute(UserErrBLogic.java:1)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
    at $Proxy15.execute(Unknown Source)
    at ext.JdbcTransactionTest.testJdbcTransactionRollback(JdbcTransactionTest.java:106)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
    at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:74)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
    at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:82)
    at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:72)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:231)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
    at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
    at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:174)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
Caused by: 
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: 
Column 'log' cannot be null
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)
    at com.mysql.jdbc.Util.getInstance(Util.java:384)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1041)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3566)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3498)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1959)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2113)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2568)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2113)
    at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1364)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:45)
    at $Proxy21.execute(Unknown Source)
    at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:22)
    at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:51)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:44)
    at $Proxy20.update(Unknown Source)
    at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:29)
    at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:88)
    at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:43)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:122)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:350)
    ... 47 more
[2012/01/09 16:13:52][INFO][GenericApplicationContext] Closing 
org.springframework.context.support.GenericApplicationContext@c980c9: startup 
date [Mon Jan 09 16:13:51 CST 2012]; root of context hierarchy
[2012/01/09 16:13:52][INFO][DefaultListableBeanFactory] Destroying singletons 
in org.springframework.beans.factory.support.DefaultListableBeanFactory@2b9406: 
defining beans 
[dataSource,transactionManager,org.springframework.aop.config.internalAutoProxyC
reator,org.springframework.transaction.annotation.AnnotationTransactionAttribute
Source#0,org.springframework.transaction.interceptor.TransactionInterceptor#0,or
g.springframework.transaction.config.internalTransactionAdvisor,sqlSessionFactor
y,queryDAO,updateDAO,userBLogic,userErrBLogic,org.springframework.context.annota
tion.internalConfigurationAnnotationProcessor,org.springframework.context.annota
tion.internalAutowiredAnnotationProcessor,org.springframework.context.annotation
.internalRequiredAnnotationProcessor,org.springframework.context.annotation.inte
rnalCommonAnnotationProcessor]; root of factory hierarchy

Please provide any additional information below.
[applicationContext-dao.xml]
    <bean id="dataSource" class="org.springframework.jdbc.datasource.DriverManagerDataSource">
        <property name="driverClassName" value="com.mysql.jdbc.Driver" />
        <property name="url" value="jdbc:mysql://localhost:3306/default" />
        <property name="username" value="root" />
        <property name="password" value="root" />
    </bean>

    <bean id="transactionManager"
        class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
        <property name="dataSource" ref="dataSource" />
    </bean>
    <tx:annotation-driven/>

    <bean id="sqlSessionFactory" class="org.mybatis.spring.SqlSessionFactoryBean">
        <property name="dataSource" ref="dataSource" />
        <property name="configLocation" value="classpath:mybatis-config.xml" />
    </bean>

    <bean id="updateDAO" class="xxx.xxx.sample.UpdateDAOMyBatisImpl">
        <property name="sqlSessionFactory" ref="sqlSessionFactory" />
    </bean>
</beans>

[applicationContext-blogic.xml]
<beans xmlns="http://www.springframework.org/schema/beans"
     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
     xmlns:context="http://www.springframework.org/schema/context"
     xsi:schemaLocation="
         http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.0.xsd
         http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.0.xsd">

    <context:component-scan base-package="com.qunar.base.meerkat.sample.blogic" />
</beans>

Original issue reported on code.google.com by zzy....@gmail.com on 9 Jan 2012 at 9:24

GoogleCodeExporter commented 9 years ago 
Everything looks fine. I cannot see the text "Transaction synchronization 
committing SqlSession" so it seems that the transaction finishes with rollback.

Could you post the Spring trace at debug level?

Original comment by eduardo.macarron on 15 Jan 2012 at 12:48

GoogleCodeExporter commented 9 years ago 
Sorry, I'd make a mistake. The tables were created using MyISAM engine. After I 
recreate them using InnoDB, It works.  = =!

Original comment by zzy....@gmail.com on 17 Jan 2012 at 11:12

GoogleCodeExporter commented 9 years ago 
Thanks for the update!

Original comment by eduardo.macarron on 17 Jan 2012 at 3:17