apache / incubator-seata

:fire: Seata is an easy-to-use, high-performance, open source distributed transaction solution.
https://seata.apache.org/
Apache License 2.0
25.33k stars 8.78k forks source link

TransactionSystemException: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException #1003

Open heshengyahuai opened 5 years ago

heshengyahuai commented 5 years ago

Ⅰ. Issue Description

seata 0.5.1 版本。 出现异常: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException

sql 语句涉及四张表: 有三个表update 一个表 Insert

Ⅱ. Describe what happened

2019-05-09 10:36:15.478 DEBUG io.seata.core.context.RootContext Line:57  - bind 172.26.177.17:8901:2011125712

Preparing: UPDATE shar_rental_demand SET grab_status=?,grab_id=?,grab_tenant_id=? WHERE is_delete=0 AND id = ? AND grab_status = ? 
Parameters: 2(Integer), c0fe227c79f94afd5f7259c2ce935e80(String), 02700001(String), ca64e443dc3f45f6d852ec98a1b96795(String), 1(Integer)
<==    Updates: 1

Preparing: update shar_score_balance bal set bal.available_balance = bal.available_balance - ?, bal.total_revenue = bal.total_revenue - ?, bal.grab_count = bal.grab_count + 1, bal.update_time=now() where bal.emp_id = ? 
Parameters: 10(Integer), 10(Integer), c0fe227c79f94afd5f7259c2ce935e80(String)
<==    Updates: 1

Preparing: INSERT INTO shar_score_record ( id, score, direction, description, biz_type, biz_id, emp_id, create_time, update_time, is_delete ) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ? ) 
Parameters: 9dbfd33e169ff9526212d57ef68ebac1(String), 10(Integer), 2(Integer), 抢单: Seata9[](String), 2(Integer), ca64e443dc3f45f6d852ec98a1b96795(String), c0fe227c79f94afd5f7259c2ce935e80(String), 2019-05-09 10:36:15.557(Timestamp), 2019-05-09 10:36:15.557(Timestamp), 0(Integer)
<==    Updates: 1

Preparing: UPDATE shar_rental_demand_record SET grab_tenant_id=?,grab_id=? WHERE is_delete=0 AND id = ? 
Parameters: 02700001(String), c0fe227c79f94afd5f7259c2ce935e80(String), ca64e443dc3f45f6d852ec98a1b96795(String)
<==    Updates: 1

2019-05-09 10:36:15.579 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:239 - offer message: xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
2019-05-09 10:36:15.580 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:297 - write message:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
, channel:[id: 0x1a909cda, L:/172.22.0.24:58218 - R:/172.26.177.17:8901],active?true,writable?true,isopen?true
2019-05-09 10:36:15.580 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:116 - Send:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795

2019-05-09 10:36:15.584 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:206 - Receive:MergeResultMessage BranchRegisterResponse: branchId=0,result code =Failed,getMsg =TransactionException[null]
,messageId:636
2019-05-09 10:36:15.586 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:297 - write message:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
, channel:[id: 0x1a909cda, L:/172.22.0.24:58218 - R:/172.26.177.17:8901],active?true,writable?true,isopen?true
2019-05-09 10:36:15.586 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:239 - offer message: xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
2019-05-09 10:36:15.587 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:116 - Send:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795

2019-05-09 10:36:15.588 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:206 - Receive:MergeResultMessage BranchRegisterResponse: branchId=0,result code =Failed,getMsg =TransactionException[null]
,messageId:638
org.springframework.transaction.TransactionSystemException: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:332)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:533)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:304)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
    at xxx.modules.sharedpool.demand.service.impl.RentalDemandServiceImpl$$EnhancerBySpringCGLIB$$f2b7fd67.grabDemand(<generated>)
    at xxx.modules.sharedpool.demand.controller.RentalDemandController.grab(RentalDemandController.java:97)

Caused by: io.seata.rm.datasource.exec.LockConflictException: null
    at io.seata.rm.datasource.ConnectionProxy.recognizeLockKeyConflictException(ConnectionProxy.java:131)
    at io.seata.rm.datasource.ConnectionProxy.processGlobalTransactionCommit(ConnectionProxy.java:182)
    at io.seata.rm.datasource.ConnectionProxy.commit(ConnectionProxy.java:159)
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:329)
    ... 126 common frames omitted
2019-05-09 10:36:15.597 DEBUG io.seata.core.context.RootContext Line:83  - unbind 172.26.177.17:8901:2011125712
2019-05-09 10:36:17.621 DEBUG io.seata.core.rpc.netty.TmRpcClient Line:207 - will send ping msg,channel[id: 0x182b4850, L:/172.22.0.24:58216 - R:/172.26.177.17:8901]
2019-05-09 10:36:17.622 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:297 - write message:services ping, channel:[id: 0x182b4850, L:/172.22.0.24:58216 - R:/172.26.177.17:8901],active?true,writable?true,isopen?true
2019-05-09 10:36:17.622 DEBUG io.seata.core.rpc.netty.AbstractRpcRemotingClient Line:272 - received PONG from /172.26.177.17:8901

Ⅳ. How to reproduce it (as minimally and precisely as possible)

业务描述: 有 A、B、C 三个服务,A无DB连接。Seata-Server 一同注册到 Eureka。

  1. A先调用B,再调用C
  2. B 和 C 有一张相同结构的表
  3. 需要将 B 服务的一行数据copy到 C服务

Ⅵ. Environment:

fescar-robot commented 5 years ago

Hi @heshengyahuai, we detect non-English characters in the issue. This comment is an auto translation from @fescar-robot to help other users to understand this issue. We encourage you to describe your issue in English which is more friendly to other users.

LockConflictException: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException

Ⅰ. Issue Description

Seata version 0.5.1. 出现异常: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException

The sql statement involves four tables: There are three table updates a table Insert

Ⅱ. Describe what happened

2019-05-09 10:36:15.478 DEBUG io.seata.core.context.RootContext Line:57  - bind 172.26.177.17:8901:2011125712

Preparing: UPDATE shar_rental_demand SET grab_status=?,grab_id=?,grab_tenant_id=? WHERE is_delete=0 AND id = ? AND grab_status = ? 
Parameters: 2(Integer), c0fe227c79f94afd5f7259c2ce935e80(String), 02700001(String), ca64e443dc3f45f6d852ec98a1b96795(String), 1(Integer)
<==    Updates: 1

Preparing: update shar_score_balance bal set bal.available_balance = bal.available_balance - ?, bal.total_revenue = bal.total_revenue - ?, bal.grab_count = bal.grab_count + 1, bal.update_time=now() where bal.emp_id = ? 
Parameters: 10(Integer), 10(Integer), c0fe227c79f94afd5f7259c2ce935e80(String)
<==    Updates: 1

Preparing: INSERT INTO shar_score_record ( id, score, direction, description, biz_type, biz_id, emp_id, create_time, update_time, is_delete ) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ? ) 
Parameters: 9dbfd33e169ff9526212d57ef68ebac1(String), 10(Integer), 2(Integer), 抢单: Seata9[](String), 2(Integer), ca64e443dc3f45f6d852ec98a1b96795(String), c0fe227c79f94afd5f7259c2ce935e80(String), 2019-05-09 10:36:15.557(Timestamp), 2019-05-09 10:36:15.557(Timestamp), 0(Integer)
<==    Updates: 1

Preparing: UPDATE shar_rental_demand_record SET grab_tenant_id=?,grab_id=? WHERE is_delete=0 AND id = ? 
Parameters: 02700001(String), c0fe227c79f94afd5f7259c2ce935e80(String), ca64e443dc3f45f6d852ec98a1b96795(String)
<==    Updates: 1

2019-05-09 10:36:15.579 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:239 - offer message: xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
2019-05-09 10:36:15.580 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:297 - write message:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
, channel:[id: 0x1a909cda, L:/172.22.0.24:58218 - R:/172.26.177.17:8901],active?true,writable?true,isopen?true
2019-05-09 10:36:15.580 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:116 - Send:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795

2019-05-09 10:36:15.584 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:206 - Receive:MergeResultMessage BranchRegisterResponse: branchId=0,result code =Failed,getMsg =TransactionException[null]
,messageId:636
2019-05-09 10:36:15.586 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:297 - write message:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
, channel:[id: 0x1a909cda, L:/172.22.0.24:58218 - R:/172.26.177.17:8901],active?true,writable?true,isopen?true
2019-05-09 10:36:15.586 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:239 - offer message: xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795
2019-05-09 10:36:15.587 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:116 - Send:SeataMergeMessage xid=172.26.177.17:8901:2011125712,branchType=AT,resourceId=jdbc:mysql://172.17.0.1:3306/ltfox_sharedpool?allowMultiQueries=true&serverTimezone=PRC&useUnicode=true&characterEncoding=UTF-8&useSSL=false,lockKey=shar_rental_demand:ca64e443dc3f45f6d852ec98a1b96795;shar_score_balance:1110897170782883841;shar_score_record:9dbfd33e169ff9526212d57ef68ebac1;shar_rental_demand_record:ca64e443dc3f45f6d852ec98a1b96795

2019-05-09 10:36:15.588 DEBUG io.seata.core.rpc.netty.MessageCodecHandler Line:206 - Receive:MergeResultMessage BranchRegisterResponse: branchId=0,result code =Failed,getMsg =TransactionException[null]
,messageId:638
org.springframework.transaction.TransactionSystemException: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:332)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:533)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:304)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
    at xxx.modules.sharedpool.demand.service.impl.RentalDemandServiceImpl$EnhancerBySpringCGLIB$f2b7fd67.grabDemand(<generated>)
    at xxx.modules.sharedpool.demand.controller.RentalDemandController.grab(RentalDemandController.java:97)

Caused by: io.seata.rm.datasource.exec.LockConflictException: null
    at io.seata.rm.datasource.ConnectionProxy.recognizeLockKeyConflictException(ConnectionProxy.java:131)
    at io.seata.rm.datasource.ConnectionProxy.processGlobalTransactionCommit(ConnectionProxy.java:182)
    at io.seata.rm.datasource.ConnectionProxy.commit(ConnectionProxy.java:159)
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:329)
    ... 126 common frames omitted
2019-05-09 10:36:15.597 DEBUG io.seata.core.context.RootContext Line:83  - unbind 172.26.177.17:8901:2011125712
2019-05-09 10:36:17.621 DEBUG io.seata.core.rpc.netty.TmRpcClient Line:207 - will send ping msg,channel[id: 0x182b4850, L:/172.22.0.24:58216 - R:/172.26.177.17:8901]
2019-05-09 10:36:17.622 DEBUG io.seata.core.rpc.netty.AbstractRpcRemoting Line:297 - write message:services ping, channel:[id: 0x182b4850, L:/172.22.0.24:58216 - R:/172.26.177.17:8901],active?true,writable?true,isopen?true
2019-05-09 10:36:17.622 DEBUG io.seata.core.rpc.netty.AbstractRpcRemotingClient Line:272 - received PONG from /172.26.177.17:8901

Ⅳ. How to reproduce it (as minimally and precisely as possible)

Business Description: There are three services A, B, and C, and A has no DB connection. Seata-Server is registered with Eureka.

  1. A calls B first, then C
  2. B and C have a table of the same structure
  3. Need to copy a row of data from the B service to the C service

Ⅵ. Environment:

heshengyahuai commented 5 years ago

续:

出现上面异常后,重启 Seata Server 后,B服务不再报异常,但C又出了问题, 且B服务没有回滚事务:

`

Error flushing statements. Cause: io.seata.common.exception.NotSupportYetException

Cause: io.seata.common.exception.NotSupportYetException

org.apache.ibatis.exceptions.PersistenceException:

Error flushing statements. Cause: io.seata.common.exception.NotSupportYetException

Cause: io.seata.common.exception.NotSupportYetException

at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
at org.apache.ibatis.session.defaults.DefaultSqlSession.flushStatements(DefaultSqlSession.java:254)
at com.baomidou.mybatisplus.extension.service.impl.ServiceImpl.saveBatch(ServiceImpl.java:132)
at com.baomidou.mybatisplus.extension.service.IService.saveBatch(IService.java:58)
at com.baomidou.mybatisplus.extension.service.IService$$FastClassBySpringCGLIB$$f8525d18.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)

Caused by: io.seata.common.exception.NotSupportYetException: null at io.seata.rm.datasource.AbstractStatementProxy.executeBatch(AbstractStatementProxy.java:234) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

`

slievrly commented 5 years ago

currently, not support executeBatch

heshengyahuai commented 5 years ago

currently, not support executeBatch

@slievrly 不支持executeBatch,是指:本地事务内不能有多条 update/insert 语句?

如果是,那大概什么时间可以支持这一功能? 我们很期待!!!

poolye commented 5 years ago

currently, not support executeBatch

同问。还有个办法可以复现,两个线程(其中一个加个sleep),都在Seata事务下。然后都更新同一行数据。也会报这个错。

slievrly commented 5 years ago

currently, not support executeBatch

@slievrly 不支持executeBatch,是指:本地事务内不能有多条 update/insert 语句?

如果是,那大概什么时间可以支持这一功能? 我们很期待!!! 是不支持jdbc的executeBatch,可以在本地事务中多条语句,这个是支持的。