XA 模式一个分支超时，会把IDLE 连接放回连接池，导致其他业务执行异常

[tanyaofei]

• I have searched the issues of this repository and believe that this is not a duplicate.

Ⅰ. Issue Description

开启 XA 全局事务后，如果其中一条 SQL 执行超时，会导致该分支回滚失败，并且以 IDLE 的状态放回连接池，后续再执行 SQL 会报错。

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

1. 开启全局事务
2. 执行分支事务 A，对记录 a 修改
3. 执行分支事务 B，同样对记录 a 进行修改，但是由于 A 事务未完成，死锁导致阻塞。
4. TC 检测到全局事务超时，让各分支事务回滚：事务 A 回滚成功，事务 B 由于还在执行中，回滚失败（不断刷回滚失败日志: NO_TA 错误，因为 B 事务还没 XA prepare）
5. 由于事务 A 已回滚，事务 B 继续执行，然后尝试 commit，先 XA end 再向 TC 查询状态，由于分布式事务已经没了，报错
6. 报错之后尝试 rollback，rollback 时再次执行 XA end，mysql 返回错误 XAER_RMFAIL: The command cannot be executed when global transaction is in the IDLE state，回滚失败
7. 至此，当前连接处于 IDLE 状态，没有 XA rollback 成功

根本问题时因为 commit 的时候已经 XA end 过一次了，rollback 的时候又想 XA end 一次，中断了 rollback 过程。

Ⅴ. Anything else we need to know?

建议方案:

1. 执行完 sql 后，commit 之前先向 TC 确认一次事务状态，如果事务已经过期了，直接执行 rollback
2. rollback 时执行 XA end 之后如果 sql 报错是 IDLE 错误，忽略该错误继续 XA rollback

如果认定这是一个 bug，我可以尝试提交修改的 PR 😀

Ⅵ. Environment:

• JDK version(e.g. java -version): 11
• Seata client/server version: 1.8.0
• Database version: 8.0.29

[tanyaofei]

通过 MySQL 控制台测试语句可以看出来不能多次执行 XA end

[funky-eyes]

commit时会end+prepare ,如果遇到超时是end+rollback,二阶段下发时不会进行end,而是直接rollback.
你是否看见了这行代码的输出?
Commit will end + prepare, if the timeout is end + rollback, the two-phase delivery will not end, but directly rollback.
Did you see the output of this line of code?

throw new SQLException("failed xa branch " + xid
                    + " the global transaction has finish, branch status: " + branchStatus.getCode());

[tanyaofei]

commit时会end+prepare ,如果遇到超时是end+rollback,二阶段下发时不会进行end,而是直接rollback. 你是否看见了这行代码的输出? Commit will end + prepare, if the timeout is end + rollback, the two-phase delivery will not end, but directly rollback. Did you see the output of this line of code?

throw new SQLException("failed xa branch " + xid
                    + " the global transaction has finish, branch status: " + branchStatus.getCode());

没有的，因为当前死锁的事务B由于别的事务回滚了释放了写锁，因此继续正常执行，自己本身并没有超时

[tanyaofei]

2024-04-22T22:28:39.808590224+08:00 2024-04-22 22:28:39.808  INFO 7 --- [llel-thread-694] io.seata.rm.AbstractResourceManager      : branch register success, xid:172.18.186.7:32002:3990701588026468048, branchId:3990701588026468050, lockKeys:null

2024-04-22T22:28:39.851178251+08:00 2024-04-22 22:28:39.851  INFO 7 --- [llel-thread-694] io.seata.rm.AbstractResourceManager      : branch register success, xid:172.18.186.7:32002:3990701588026468048, branchId:3990701588026468052, lockKeys:null

2024-04-22T22:28:39.854974554+08:00 2024-04-22 22:28:39.854  INFO 7 --- [llel-thread-694] io.seata.rm.AbstractResourceManager      : branch register success, xid:172.18.186.7:32002:3990701588026468048, branchId:3990701588026468054, lockKeys:null

2024-04-22T22:28:39.858038741+08:00 2024-04-22 22:28:39.857  INFO 7 --- [llel-thread-694] io.seata.rm.AbstractResourceManager      : branch register success, xid:172.18.186.7:32002:3990701588026468048, branchId:3990701588026468056, lockKeys:null

2024-04-22T22:28:39.861093429+08:00 2024-04-22 22:28:39.861  INFO 7 --- [llel-thread-694] io.seata.rm.AbstractResourceManager      : branch register success, xid:172.18.186.7:32002:3990701588026468048, branchId:3990701588026468058, lockKeys:null

2024-04-22T22:28:39.873874543+08:00 2024-04-22 22:28:39.873  INFO 7 --- [llel-thread-694] io.seata.rm.AbstractResourceManager      : branch register success, xid:172.18.186.7:32002:3990701588026468048, branchId:3990701588026468062, lockKeys:null

# 这一条会阻塞
2024-04-22T22:28:39.879148524+08:00 2024-04-22 22:28:39.879  INFO 7 --- [llel-thread-694] io.seata.rm.AbstractResourceManager      : branch register success, xid:172.18.186.7:32002:3990701588026468048, branchId:3990701588026468064, lockKeys:null

由于最后一个分支事务发生死锁，开始回滚，但由于还处于执行状态，没有 xa end 因此回滚失败，会刷日志

2024-04-22T22:30:25.543523306+08:00 2024-04-22 22:30:25.543  INFO 7 --- [ch_RMROLE_1_4_4] io.seata.rm.AbstractRMHandler            : Branch Rollbacking: 172.18.186.7:32002:3990701588026468048 3990701588026468064 jdbc:mysql://xxx:3306/xxx

2024-04-22T22:30:25.544294970+08:00 2024-04-22 22:30:25.544  INFO 7 --- [ch_RMROLE_1_4_4] io.seata.rm.AbstractRMHandler            : Branch Rollbacked result: PhaseTwo_RollbackFailed_XAER_NOTA_Retryable

2024-04-22T22:30:26.543319405+08:00 2024-04-22 22:30:26.543  INFO 7 --- [ch_RMROLE_1_1_4] i.s.c.r.p.c.RmBranchRollbackProcessor    : rm handle branch rollback process:BranchRollbackRequest{xid='172.18.186.7:32002:3990701588026468048', branchId=3990701588026468064, branchType=XA, resourceId='jdbc:mysql://xxx:3306/xxx', applicationData='null'}

之后其他分支会回滚成功释放了写锁，上述所说的阻塞的分支就会继续执行下去了，能看到提交日志

Failed to commit xa branch of 172.18.186.7:32002:3990701588026468048) since failed xa branch 172.18.186.7:32002:3990701588026468048 the global transaction has finish, branch status: 8

提交失败后，尝试回滚

Failed to rollback xa branch of 172.18.186.7:32002:3990701588026468048(caused by commit failure(failed xa branch 172.18.186.7:32002:3990701588026468048 the global transaction has finish, branch status: 8) since should NOT rollback on an inactive session

补充一下，并不是两次 xa end 导致的，而是第一个 commit() 的 finally 里执行了 cleanXABranchContext，导致 rollback 的时候抛出异常，但连接仍处于 IDLE 状态

    // ConnectionProxyXA.java
    @Override
    public synchronized void commit() throws SQLException {
        if (currentAutoCommitStatus) {
            // Ignore the committing on an autocommit session.
            return;
        }
        if (!xaActive || this.xaBranchXid == null) {
            throw new SQLException("should NOT commit on an inactive session", SQLSTATE_XA_NOT_END);
        }
        try {
            // XA End: Success
            end(XAResource.TMSUCCESS);                     // 这里会去向 TC 查询状态，抛出异常
            long now = System.currentTimeMillis();
            checkTimeout(now);
            setPrepareTime(now);
            xaResource.prepare(xaBranchXid);
        } catch (XAException xe) {
            // Branch Report to TC: Failed
            reportStatusToTC(BranchStatus.PhaseOne_Failed);
            throw new SQLException(
                "Failed to end(TMSUCCESS)/prepare xa branch on " + xid + "-" + xaBranchXid.getBranchId() + " since " + xe
                    .getMessage(), xe);
        } finally {
            cleanXABranchContext();                             // 清理了上下文，无法执行后续的 rollback
        }
    }

    @Override
    public void rollback() throws SQLException {
        if (currentAutoCommitStatus) {
            // Ignore the committing on an autocommit session.
            return;
        }
        if (!xaActive || this.xaBranchXid == null) {
            throw new SQLException("should NOT rollback on an inactive session");        // 上下文没了，无法 rollback
        }
        try {
            if (!rollBacked) {
                // XA End: Fail
                xaResource.end(this.xaBranchXid, XAResource.TMFAIL);
                xaRollback(xaBranchXid);
            }
            // Branch Report to TC
            reportStatusToTC(BranchStatus.PhaseOne_Failed);
            LOGGER.info("{} was rollbacked", xaBranchXid);
        } catch (XAException xe) {
            throw new SQLException("Failed to end(TMFAIL) xa branch on " + xid + "-" + xaBranchXid.getBranchId()
                + " since " + xe.getMessage(), xe);
        } finally {
            cleanXABranchContext();
        }
    }

[funky-eyes]

end不会去检查tc状态，而是直接end。针对还在运行中的事务，seata目前依靠无限重试来保证他走到end后被回滚。
清理上下文不会影响rollback，看我说的xarollback的方法，里面会重新build一个xid，然后进行rollback。
End does not check the tc state, but directly ends. For transactions that are still running, seata currently relies on infinite retries to ensure that they are rolled back when they reach end.
Cleaning up the context will not affect the rollback. Look at the method of xarollback I mentioned, which will rebuild a xid and then perform rollback.

[tanyaofei]

end不会去检查tc状态，而是直接end。针对还在运行中的事务，seata目前依靠无限重试来保证他走到end后被回滚。 清理上下文不会影响rollback，看我说的xarollback的方法，里面会重新build一个xid，然后进行rollback。 End does not check the tc state, but directly ends. For transactions that are still running, seata currently relies on infinite retries to ensure that they are rolled back when they reach end. Cleaning up the context will not affect the rollback. Look at the method of xarollback I mentioned, which will rebuild a xid and then perform rollback.

不会走到 xaRollback() 方法，会在 if 判断的时候抛出异常

if (!xaActive || this.xaBranchXid == null) {
    throw new SQLException("should NOT rollback on an inactive session");        // 上下文没了，无法 rollback
}

[funky-eyes]

所以在commit的时候为什么会走到rollback？

[tanyaofei]

所以在commit的时候为什么会走到rollback？

commit() -> end() -> termination() -> SQLException

private void termination(String xaBranchXid) throws SQLException {
        // if it is not empty, the resource will hang and need to be terminated early
        BranchStatus branchStatus = BaseDataSourceResource.getBranchStatus(xaBranchXid);
        if (branchStatus != null) {
            releaseIfNecessary();
            throw new SQLException("failed xa branch " + xid
                    + " the global transaction has finish, branch status: " + branchStatus.getCode());
        }
    }

我创建了一个复现的 项目

1. 数据库地址 127.0.0.1:3306, 账号 root, 密码 123456，表初始化 sql 位于 resources/database.sql。
2. 程序启动后访问 http://127.0.0.1:8080/user。

访问后控制台会不断地刷回滚报错日志，请耐心等待直至抛出异常

以下是控制台报错日志

org.springframework.transaction.TransactionSystemException: JDBC commit failed; nested exception is java.sql.SQLException: failed xa branch 192.168.6.132:8091:5161638839849824278 the global transaction has finish, branch status: 8
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.translateException(DataSourceTransactionManager.java:435)
	at org.springframework.jdbc.support.JdbcTransactionManager.translateException(JdbcTransactionManager.java:188)
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:336)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:743)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711)
	at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:152)
	at com.example.UserServiceImpl.updateUser(UserServiceImpl.java:40)
	at com.example.UserServiceImpl$$FastClassBySpringCGLIB$$4998c799.invoke(<generated>)
	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
	at io.seata.spring.annotation.GlobalTransactionalInterceptor$2.execute(GlobalTransactionalInterceptor.java:208)
	at io.seata.tm.api.TransactionalTemplate.execute(TransactionalTemplate.java:128)
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.handleGlobalTransaction(GlobalTransactionalInterceptor.java:205)
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.invoke(GlobalTransactionalInterceptor.java:175)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708)
	at com.example.UserServiceImpl$$EnhancerBySpringCGLIB$$cae137cc.updateUser(<generated>)
	at com.example.UserController.getUsers(UserController.java:24)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1070)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.sql.SQLException: failed xa branch 192.168.6.132:8091:5161638839849824278 the global transaction has finish, branch status: 8
	at io.seata.rm.datasource.xa.ConnectionProxyXA.termination(ConnectionProxyXA.java:349)
	at io.seata.rm.datasource.xa.ConnectionProxyXA.termination(ConnectionProxyXA.java:340)
	at io.seata.rm.datasource.xa.ConnectionProxyXA.end(ConnectionProxyXA.java:273)
	at io.seata.rm.datasource.xa.ConnectionProxyXA.commit(ConnectionProxyXA.java:209)
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:333)
	... 68 more
PreparedStatementCallback; uncategorized SQLException; SQL state [XAE07]; error code [1399]; XAER_RMFAIL: The command cannot be executed when global transaction is in the  IDLE state; nested exception is java.sql.SQLException: XAER_RMFAIL: The command cannot be executed when global transaction is in the  IDLE state
PreparedStatementCallback; uncategorized SQLException; SQL state [XAE07]; error code [1399]; XAER_RMFAIL: The command cannot be executed when global transaction is in the  IDLE state; nested exception is java.sql.SQLException: XAER_RMFAIL: The command cannot be executed when global transaction is in the  IDLE state
PreparedStatementCallback; uncategorized SQLException; SQL state [XAE07]; error code [1399]; XAER_RMFAIL: The command cannot be executed when global transaction is in the  IDLE state; nested exception is java.sql.SQLException: XAER_RMFAIL: The command cannot be executed when global transaction is in the  IDLE state

[funky-eyes]

你不是跟我说没有吗？

throw new SQLException("failed xa branch " + xid
                    + " the global transaction has finish, branch status: " + branchStatus.getCode());

如果抛出了这个异常，那么end是完成了，二阶段下发回滚时会找到这个connection进行rollback，此时不需要end，直接会走xarollback。
如果找不到这个connection，只可能因为这个connection被close了，并且没有进行hold connection。你是mysql8.0.29及以上版本？

[tanyaofei]

你不是跟我说没有吗？

throw new SQLException("failed xa branch " + xid
                    + " the global transaction has finish, branch status: " + branchStatus.getCode());

如果抛出了这个异常，那么end是完成了，二阶段下发回滚时会找到这个connection进行rollback，此时不需要end，直接会走xarollback。 如果找不到这个connection，只可能因为这个connection被close了，并且没有进行hold connection。你是mysql8.0.29及以上版本？

用的是 8.0.30

[funky-eyes]

我重新理解下，由于8.0.29及以上不会进行hold，所以这个连接commit发现此时已经二阶段时，会进行防悬挂操作抛出异常，此时orm或者用户持有的connection选择走向了rollback时，由于没有xid信息无法rollback这个xa事务。即便二阶段下发采用了其他的connection时，由于该xid也没有进行prepare，所以无法直接回滚成功是吗？
欢迎提一个bugfix的pr来修复该问题

[tanyaofei]

我重新理解下，由于8.0.29及以上不会进行hold，所以这个连接commit发现此时已经二阶段时，会进行防悬挂操作抛出异常，此时orm或者用户持有的connection选择走向了rollback时，由于没有xid信息无法rollback这个xa事务。即便二阶段下发采用了其他的connection时，由于该xid也没有进行prepare，所以无法直接回滚成功是吗？ 欢迎提一个bugfix的pr来修复该问题

对的，是这个意思。我来提一个 pr 来修复吧～