search

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.28k stars 8.78k forks source link

seata 1.6.1事务提交时seata服务器报错 #6934

Open yangyangyfm opened 2 days ago

yangyangyfm commented 2 days ago

客户端的错误：

8 16:58:15 | Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a8b0405] from current transaction |   -- | -- | --   |   | 2024-10-18 16:58:15 | ... 89 common frames omitted |     |   | 2024-10-18 16:58:15 | at io.seata.rm.AbstractResourceManager.branchRegister(AbstractResourceManager.java:67) |     |   | 2024-10-18 16:58:15 | at io.seata.core.rpc.netty.AbstractNettyRemotingClient.sendSyncRequest(AbstractNettyRemotingClient.java:174) |     |   | 2024-10-18 16:58:15 | at io.seata.core.protocol.MessageFuture.get(MessageFuture.java:65) |     |   | 2024-10-18 16:58:15 | Caused by: java.util.concurrent.TimeoutException: null ,cost: 15001 ms |     |   | 2024-10-18 16:58:15 | ... 86 common frames omitted |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy.processGlobalTransactionCommit(ConnectionProxy.java:250) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy.register(ConnectionProxy.java:273) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.DefaultResourceManager.branchRegister(DefaultResourceManager.java:96) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.AbstractResourceManager.branchRegister(AbstractResourceManager.java:73) |     |   | 2024-10-18 16:58:15 | Caused by: io.seata.core.exception.RmTransactionException: RPC Timeout |     |   | 2024-10-18 16:58:15 | ... 34 common frames omitted |     |   | 2024-10-18 16:58:15 | at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:425) |     |   | 2024-10-18 16:58:15 | at java.lang.reflect.Method.invoke(Method.java:498) |     |   | 2024-10-18 16:58:15 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |     |   | 2024-10-18 16:58:15 | at sun.reflect.GeneratedMethodAccessor218.invoke(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:194) |     |   | 2024-10-18 16:58:15 | at com.sun.proxy.$Proxy323.update(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:62) |     |   | 2024-10-18 16:58:15 | at com.baomidou.mybatisplus.extension.plugins.MybatisPlusInterceptor.intercept(MybatisPlusInterceptor.java:106) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.plugin.Invocation.proceed(Invocation.java:49) |     |   | 2024-10-18 16:58:15 | at java.lang.reflect.Method.invoke(Method.java:498) |     |   | 2024-10-18 16:58:15 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |     |   | 2024-10-18 16:58:15 | at sun.reflect.GeneratedMethodAccessor219.invoke(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:50) |     |   | 2024-10-18 16:58:15 | at com.sun.proxy.$Proxy324.update(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:64) |     |   | 2024-10-18 16:58:15 | at java.lang.reflect.Method.invoke(Method.java:498) |     |   | 2024-10-18 16:58:15 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |     |   | 2024-10-18 16:58:15 | at sun.reflect.GeneratedMethodAccessor230.invoke(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:74) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:47) |     |   | 2024-10-18 16:58:15 | at com.sun.proxy.$Proxy325.execute(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:59) |     |   | 2024-10-18 16:58:15 | at java.lang.reflect.Method.invoke(Method.java:498) |     |   | 2024-10-18 16:58:15 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |     |   | 2024-10-18 16:58:15 | at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.driver.jdbc.core.statement.ShardingSpherePreparedStatement.execute(ShardingSpherePreparedStatement.java:403) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.driver.executor.DriverJDBCExecutor.execute(DriverJDBCExecutor.java:145) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.driver.executor.DriverJDBCExecutor.doExecute(DriverJDBCExecutor.java:156) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.infra.executor.sql.execute.engine.driver.jdbc.JDBCExecutor.execute(JDBCExecutor.java:49) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.infra.executor.sql.execute.engine.driver.jdbc.JDBCExecutor.execute(JDBCExecutor.java:65) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.infra.executor.kernel.ExecutorEngine.execute(ExecutorEngine.java:116) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.infra.executor.kernel.ExecutorEngine.parallelExecute(ExecutorEngine.java:131) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.infra.executor.kernel.ExecutorEngine.syncExecute(ExecutorEngine.java:135) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.infra.executor.sql.execute.engine.driver.jdbc.JDBCExecutorCallback.execute(JDBCExecutorCallback.java:75) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.infra.executor.sql.execute.engine.driver.jdbc.JDBCExecutorCallback.execute(JDBCExecutorCallback.java:95) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.driver.jdbc.core.statement.ShardingSpherePreparedStatement$2.executeSQL(ShardingSpherePreparedStatement.java:438) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.driver.jdbc.core.statement.ShardingSpherePreparedStatement$2.executeSQL(ShardingSpherePreparedStatement.java:442) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.PreparedStatementProxy.execute(PreparedStatementProxy.java:55) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.exec.ExecuteTemplate.execute(ExecuteTemplate.java:56) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.exec.ExecuteTemplate.execute(ExecuteTemplate.java:137) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.exec.BaseTransactionalExecutor.execute(BaseTransactionalExecutor.java:125) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor.doExecute(AbstractDMLBaseExecutor.java:82) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor.executeAutoCommitTrue(AbstractDMLBaseExecutor.java:136) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor$LockRetryPolicy.execute(AbstractDMLBaseExecutor.java:180) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy$LockRetryPolicy.doRetryOnLockConflict(ConnectionProxy.java:356) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor.lambda$executeAutoCommitTrue$2(AbstractDMLBaseExecutor.java:138) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy.commit(ConnectionProxy.java:187) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy$LockRetryPolicy.execute(ConnectionProxy.java:344) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy.lambda$commit$0(ConnectionProxy.java:188) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy.doCommit(ConnectionProxy.java:230) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy.processGlobalTransactionCommit(ConnectionProxy.java:252) |     |   | 2024-10-18 16:58:15 | at io.seata.rm.datasource.ConnectionProxy.recognizeLockKeyConflictException(ConnectionProxy.java:161) |     |   | 2024-10-18 16:58:15 | Caused by: java.sql.SQLException: io.seata.core.exception.RmTransactionException: RPC Timeout |     |   | 2024-10-18 16:58:15 | at java.lang.Thread.run(Thread.java:750) |     |   | 2024-10-18 16:58:15 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) |     |   | 2024-10-18 16:58:15 | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.schedule.BroadcastPlanSchedule.lambda$null$0(BroadcastPlanSchedule.java:44) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.BroadcastPlanService$$EnhancerBySpringCGLIB$$8b4a02ee.runPlan() |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708) |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) |     |   | 2024-10-18 16:58:15 | at org.apache.shardingsphere.spring.transaction.TransactionTypeInterceptor.invoke(TransactionTypeInterceptor.java:44) |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) |     |   | 2024-10-18 16:58:15 | at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) |     |   | 2024-10-18 16:58:15 | at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) |     |   | 2024-10-18 16:58:15 | at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) |     |   | 2024-10-18 16:58:15 | at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793) |     |   | 2024-10-18 16:58:15 | at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.BroadcastPlanService$$FastClassBySpringCGLIB$$9a38fc98.invoke() |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.BroadcastPlanService.runPlan(BroadcastPlanService.java:228) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.BroadcastPlanService.runPlan(BroadcastPlanService.java:248) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.utils.BroadcastUtils.applyExecutableNode(BroadcastUtils.java:242) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.BroadcastPlanService.lambda$runPlan$5(BroadcastPlanService.java:249) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.BroadcastPlanService.executeNode(BroadcastPlanService.java:374) |     |   | 2024-10-18 16:58:15 | at com.citc.nce.im.broadcast.node.AbstractNode.syncDb(AbstractNode.java:123) |     |   | 2024-10-18 16:58:15 | at com.baomidou.mybatisplus.extension.conditions.update.ChainUpdate.update(ChainUpdate.java:45) |     |   | 2024-10-18 16:58:15 | at com.baomidou.mybatisplus.extension.conditions.ChainWrapper.execute(ChainWrapper.java:63) |     |   | 2024-10-18 16:58:15 | at com.baomidou.mybatisplus.extension.conditions.update.ChainUpdate.lambda$update$eb4b7d7c$1(ChainUpdate.java:45) |     |   | 2024-10-18 16:58:15 | at com.sun.proxy.$Proxy229.update(Unknown Source) |     |   | 2024-10-18 16:58:15 | at com.baomidou.mybatisplus.core.override.MybatisMapperProxy.invoke(MybatisMapperProxy.java:89) |     |   | 2024-10-18 16:58:15 | at com.baomidou.mybatisplus.core.override.MybatisMapperProxy$PlainMethodInvoker.invoke(MybatisMapperProxy.java:148) |     |   | 2024-10-18 16:58:15 | at com.baomidou.mybatisplus.core.override.MybatisMapperMethod.execute(MybatisMapperMethod.java:64) |     |   | 2024-10-18 16:58:15 | at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:288) |     |   | 2024-10-18 16:58:15 | at com.sun.proxy.$Proxy181.update(Unknown Source) |     |   | 2024-10-18 16:58:15 | at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:439) |     |   | 2024-10-18 16:58:15 | at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:93) |     |   | 2024-10-18 16:58:15 | ; uncategorized SQLException; SQL state [null]; error code [0]; io.seata.core.exception.RmTransactionException: RPC Timeout; nested exception is java.sql.SQLException: io.seata.core.exception.RmTransactionException: RPC Timeout |     |   | 2024-10-18 16:58:15 | ### Cause: java.sql.SQLException: io.seata.core.exception.RmTransactionException: RPC Timeout |     |   | 2024-10-18 16:58:15 | ### SQL: UPDATE robot_group_plan_detail SET update_time=?, updater=?, plan_status=?,send_time=? WHERE deleted=0 AND (id = ?) |     |   | 2024-10-18 16:58:15 | ### The error occurred while setting parameters |     |   | 2024-10-18 16:58:15 | ### The error may involve com.citc.nce.im.mapper.RobotGroupSendPlansDetailDao.update-Inline |     |   | 2024-10-18 16:58:15 | ### The error may exist in com/citc/nce/im/mapper/RobotGroupSendPlansDetailDao.java (best guess) |     |   | 2024-10-18 16:58:15 | ### Error updating database. Cause: java.sql.SQLException: io.seata.core.exception.RmTransactionException: RPC Timeout |     |   | 2024-10-18 16:58:15 | org.springframework.jdbc.UncategorizedSQLException: |     |   | 2024-10-18 16:58:15 | ; uncategorized SQLException; SQL state [null]; error code [0]; io.seata.core.exception.RmTransactionException: RPC Timeout; nested exception is java.sql.SQLException: io.seata.core.exception.RmTransactionException: RPC Timeout |     |   | 2024-10-18 16:58:15 | ### Cause: java.sql.SQLException: io.seata.core.exception.RmTransactionException: RPC Timeout |     |   | 2024-10-18 16:58:15 | ### SQL: UPDATE robot_group_plan_detail SET update_time=?, updater=?, plan_status=?,send_time=? WHERE deleted=0 AND (id = ?) |     |   | 2024-10-18 16:58:15 | ### The error occurred while setting parameters |     |   | 2024-10-18 16:58:15 | ### The error may involve com.citc.nce.im.mapper.RobotGroupSendPlansDetailDao.update-Inline |     |   | 2024-10-18 16:58:15 | ### The error may exist in com/citc/nce/im/mapper/RobotGroupSendPlansDetailDao.java (best guess) |     |   | 2024-10-18 16:58:15 | ### Error updating database. Cause: java.sql.SQLException: io.seata.core.exception.RmTransactionException: RPC Timeout

服务端的错误： 6:58:00.227 INFO --- [ Thread-184049] i.seata.server.coordinator.AbstractCore : Register branch successfully, xid = 10.244.2.126:8091:5269764498780407050, branchId = 5269764498780407054, resourceId = jdbc:mysql://10.201.6.52:3306/robot ,lockKeys = robot_group_plan_detail:1847199069562269697 16:58:00.229 ERROR --- [verHandlerThread_1_43_500] i.s.c.r.p.s.ServerOnRequestProcessor : handle request error: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 ==> java.util.concurrent.ExecutionException: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357) at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1908) at io.seata.core.rpc.processor.server.ServerOnRequestProcessor.onRequestMessage(ServerOnRequestProcessor.java:201) at io.seata.core.rpc.processor.server.ServerOnRequestProcessor.process(ServerOnRequestProcessor.java:123) at io.seata.core.rpc.netty.AbstractNettyRemoting.lambda$processMessage$2(AbstractNettyRemoting.java:281) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.lang.Thread.run(Thread.java:750) Caused by: java.lang.IndexOutOfBoundsException: Index: 1, Size: 0 at java.util.concurrent.CopyOnWriteArrayList.add(CopyOnWriteArrayList.java:463) at io.seata.core.rpc.processor.server.ServerOnRequestProcessor.lambda$onRequestMessage$1(ServerOnRequestProcessor.java:191) at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1640) ... 1 common frames omitted <==

16:58:00.260 INFO --- [ batchLoggerPrint_1_1] i.s.c.r.p.server.BatchLogHandler : SeataMergeMessage xid=10.244.2.126:8091:5269764498780407050,branchType=AT,resourceId=jdbc:mysql://10.201.6.52:3306/robot,lockKey=robot_group_plan_send:1847198822794588161

funky-eyes commented 2 days ago

服务端统一升级到1.7或以上 Server level upgrade to 1.7 or above