文章目录
- 前言
- 参考目录
- 版本说明
- 测试 Demo
- 0、Demo XA / AT 模式切换
- 1、模块说明
- 2、调用逻辑说明
- 3、分析流程说明
- 4、注意事项
- Seata AT 模式 Commit 调用流程分析
- 1、调用流程图
- 2、全局事务开启 Global Begin
- 3、分支注册
- 4、UndoLog
- 5、全局事务提交 Commit
- 6、分支提交处理
- Seata AT 模式 Rollback 调用流程分析
- 1、调用流程图
- 2、全局事务回滚 Rollback
- 3、分支回滚处理
- 附录
- Commit 调用流程 Client 端控制台输出
- 业务模块（business-xa）
- 库存模块（stock-xa）
- 订单模块（order-xa）
- 账户模块（account-xa）
- Commit 调用流程 Server 端控制台输出
- 按时序整理的完整流程输出（包含Client 端、Server 端）
- Rollback 调用流程 Client 端控制台输出
- 业务模块（business-xa）
- 库存模块（stock-xa）
- 订单模块（order-xa）
- 账户模块（account-xa）
- Rollback 调用流程 Server 端控制台输出
- 按时序整理的完整流程输出（包含Client 端、Server 端）
前言
之前的文章介绍了 XA 模式的调用流程。但是 XA 模式也存在着一些问题：
（截图自微信读书《阿里云云原生架构实践》）
而为了能够解决 XA 模式存在的问题， Seata 演化出了 AT 模式，本文来介绍一下 AT 模式的底层调用流程。
参考目录
- Seata 官方文档
- Seata 官方 Demo ：seata-xa
- Seata AT 模式
- 《阿里云云原生架构实践》
书本章节 3.5 介绍了分布式事务模式的相关内容。
版本说明
由于官方 Demo 版本较低，本文使用的版本如下：
Seata：V1.7.0druid-spring-boot-starter：V1.2.16
测试 Demo
这一部分和 XA 模式的内容大致相同，所以大部分内容就直接 copy 之前文章的。
0、Demo XA / AT 模式切换
两种模式业务代码相同，只是修改数据源配置即可进行模式切换。
（截图自 GitHub README.md）
建表 undo_log：
CREATE TABLE IF NOT EXISTS undo_log
(
branch_id BIGINT(20) NOT NULL COMMENT 'branch transaction id',
xid VARCHAR(100) NOT NULL COMMENT 'global transaction id',
context VARCHAR(128) NOT NULL COMMENT 'undo_log context,such as serialization',
rollback_info LONGBLOB NOT NULL COMMENT 'rollback info',
log_status INT(11) NOT NULL COMMENT '0:normal status,1:defense status',
log_created DATETIME(6) NOT NULL COMMENT 'create datetime',
log_modified DATETIME(6) NOT NULL COMMENT 'modify datetime',
UNIQUE KEY ux_undo_log (xid, branch_id)
) ENGINE = InnoDB COMMENT ='AT transaction mode undo table';
1、模块说明
Demo 一共四个模块，是经典的下单流程。按照如下顺序启动：
- 账户模块（Port：8083）
- 订单模块（Port：8082）
- 库存模块（Port：8081）
- 业务模块（Port：8084）
模块间使用 openfeign 进行调用。
2、调用逻辑说明
入口：业务模块
http://127.0.0.1:8084/purchase
业务逻辑：
- 调用业务模块接口（business-xa）
- 扣减商品库存（stock-xa）
- 新增账户订单（order-xa）
- 账户余额扣减（account-xa）
（截图自 GitHub README.md）
3、分析流程说明
整个下单操作是一个全局事务，各个模块分属于各个分支事务。下面对源码进行分析时只对其中一个分支操作进行说明，其余分支操作都是相同的，就不再展开说明。
分析分为 Commit 和 Rollback 两种流程。
官方文档 对于 AT 模式有详细的说明，本文在此基础上进行展开。
4、注意事项
由于 XA 模式中出现了重试锁表的问题，所以本文的分析是基于控制台日志输出以及 Debug 堆栈信息。下文没有对每一个方法进行 Debug 截图，而是按照调用流程贴出了相应的主要方法。
为了完整体现整个全局事务流程，也在不断点的情况下对流程进行了截取分析并制作了流程图，详细的见下文。
Seata AT 模式 Commit 调用流程分析
1、调用流程图
步骤前面由数字标识，根据各模块控制台输出整理，详细见附录。
2、全局事务开启 Global Begin
io.seata.tm.api.DefaultGlobalTransaction#begin
io.seata.tm.DefaultTransactionManager#begin
这一步骤向 Server 端（TC）发送了全局事务开启请求。下面来看下 Server 端处理逻辑：
io.seata.core.rpc.processor.server.ServerOnRequestProcessor#onRequestMessage
控制台打印：
11:40:09.610 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalBeginRequest{transactionName='purchase(java.lang.String, java.lang.String, int, boolean)', timeout=60000}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
io.seata.server.coordinator.DefaultCoordinator#doGlobalBegin
控制台打印：
11:40:09.624 INFO --- [verHandlerThread_1_11_500] [coordinator.DefaultCoordinator] [ doGlobalBegin] [192.168.2.117:8091:2252230319988862988] : Begin new global transaction applicationId: business-xa,transactionServiceGroup: my_test_tx_group, transactionName: purchase(java.lang.String, java.lang.String, int, boolean),timeout:60000,xid:192.168.2.117:8091:2252230319988862988
io.seata.server.coordinator.DefaultCore#begin
io.seata.server.session.GlobalSession#GlobalSession
io.seata.core.rpc.processor.server.ServerOnResponseProcessor#process
控制台打印：
11:40:09.625 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalBeginResponse{xid='192.168.2.117:8091:2252230319988862988', extraData='null', resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
Server 端处理完毕后，回到 Client 端主方法，事务开启。
11:40:09.635 INFO 17724 --- [nio-8084-exec-1] io.seata.sample.service.BusinessService : New Transaction Begins: 192.168.2.117:8091:2252230319988862988
3、分支注册
分支还是以库存业务分支为例进行说明。
因为调用的方法很多，所以截了一张 Debug 堆栈信息图方便比对。
从上图可以看出，先执行了 SQL 相关的一些操作，然后进行 Commit 操作，在提交之前进行分支注册操作。来看下一些关键的方法：
io.seata.rm.datasource.PreparedStatementProxy#executeUpdate
io.seata.rm.datasource.exec.ExecuteTemplate#execute
io.seata.rm.datasource.exec.BaseTransactionalExecutor#execute
io.seata.rm.datasource.exec.AbstractDMLBaseExecutor#doExecute
这里获取到前后镜像，并执行了SQL语句。然后进行 Commit 操作。
io.seata.rm.datasource.ConnectionProxy#commit
直到方法 io.seata.rm.datasource.ConnectionProxy#processGlobalTransactionCommit 终于到了注册逻辑。
io.seata.rm.datasource.ConnectionProxy#register
io.seata.rm.AbstractResourceManager#branchRegister
这里还是通过 Netty 向 Server 端（TC）进行分支注册请求。来看下 Server 端的处理逻辑：
io.seata.core.rpc.processor.server.ServerOnRequestProcessor#handleRequestsByMergedWarpMessage
控制台打印：
11:40:09.882 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.117:8091:2252230319988862988', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='order_tbl:15', applicationData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
io.seata.server.coordinator.DefaultCoordinator#onRequest
io.seata.server.AbstractTCInboundHandler#handle
io.seata.server.coordinator.DefaultCoordinator#doBranchRegister
Server 端分支注册方法：
io.seata.server.coordinator.AbstractCore#branchRegister
该方法的主要逻辑：
- 使用 xid 获取到全局会话。
- 锁定会话并在事务上下文进行操作。
- 全局会话状态检查。
- 全局会话添加会话生命周期监听器。
- 新建全局事务分支，获得分支会话对象。
- 锁定分支会话。
- 将分支会话添加到全局会话中，如果出现异常，解锁分支并抛出异常。
- 打印日志并返回分支id。
io.seata.server.session.SessionHelper#newBranchByGlobal
控制台打印：
11:40:09.962 INFO --- [nPool.commonPool-worker-3] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.117:8091:2252230319988862988] : Register branch successfully, xid = 192.168.2.117:8091:2252230319988862988, branchId = 2252230319988862992, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = order_tbl:15
11:40:09.962 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252230319988862992, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
Server 端分支注册完成，回到 Client 端打印日志并返回分支 id 。
控制台打印：
11:40:09.963 INFO 17280 --- [nio-8082-exec-4] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.117:8091:2252230319988862988, branchId:2252230319988862992, lockKeys:order_tbl:15
4、UndoLog
我认为 AT 模式与 XA 模式最大的不同，在于 SQL commit 的时机：
- XA 模式在一阶段只是执行 SQL 语句，但是不提交，等到业务调用链中所有 SQL 执行无异常后，在二阶段才进行提交。
- AT 模式则是在一阶段执行 SQL 执行就会进行提交，然后把 SQL 执行前后的变化通过 undo_log 表进行记录，如果执行无异常，二阶段提交就把 undo_log 表记录进行删除，如果有异常，则根据 undo_log 表记录进行数据回滚操作。
SQL 执行前后的数据，Seata 称之为前后镜像。
io.seata.rm.datasource.exec.AbstractDMLBaseExecutor#executeAutoCommitFalse
io.seata.rm.datasource.exec.BaseTransactionalExecutor#prepareUndoLog
在上一步分支注册完成后，UndoLog 记录就会存入数据库中。
io.seata.rm.datasource.ConnectionProxy#processGlobalTransactionCommit
io.seata.rm.datasource.undo.AbstractUndoLogManager#flushUndoLogs
详细的信息都存在 rollback_info 字段中。三个事务分支的 undo_log 信息：
Stock 库存：
Order 订单：
Account 账户：
5、全局事务提交 Commit
io.seata.tm.api.DefaultGlobalTransaction#commit
io.seata.tm.DefaultTransactionManager#commit
向 Server 端发起 Commit 请求。
控制台打印：
11:40:10.294 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalCommitRequest{xid='192.168.2.117:8091:2252230319988862988', extraData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.511 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalCommitResponse{globalStatus=Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
全局事务提交成功。
控制台打印：
11:40:10.515 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : transaction end, xid = 192.168.2.117:8091:2252230319988862988
11:40:10.515 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : [192.168.2.117:8091:2252230319988862988] commit status: Committed
6、分支提交处理
io.seata.core.rpc.processor.client.RmBranchCommitProcessor#process
io.seata.rm.AbstractRMHandler#doBranchCommit
因为一阶段 SQL 已经 Commit，因此二阶段分支提交主要是删除 UndoLog。
io.seata.rm.datasource.AsyncWorker#dealWithGroupedContexts
io.seata.server.coordinator.DefaultCore#doGlobalCommit
Client 端控制台打印：
11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchCommitProcessor : rm client handle branch commit process:BranchCommitRequest{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862990, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch committing: 192.168.2.117:8091:2252230319988862988 2252230319988862990 jdbc:mysql://192.168.2.158:3326/seata null
11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch commit result: PhaseTwo_Committed
Server 端控制台打印：
11:40:11.342 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchCommitResponse{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862990, branchStatus=PhaseTwo_Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.356 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [bda$doGlobalCommit$1] [192.168.2.117:8091:2252230319988862988] : Commit branch transaction successfully, xid = 192.168.2.117:8091:2252230319988862988 branchId = 2252230319988862990
所有分支提交完成后，全局提交完成。
11:40:11.461 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [ doGlobalCommit] [192.168.2.117:8091:2252230319988862988] : Committing global transaction is successfully done, xid = 192.168.2.117:8091:2252230319988862988.
Seata AT 模式 Rollback 调用流程分析
1、调用流程图
Rollback 业务流程中，在执行 Account 相关业务逻辑时抛出了运行时异常，然后各分支进行回滚操作。
2、全局事务回滚 Rollback
io.seata.tm.api.DefaultGlobalTransaction#rollback
io.seata.tm.DefaultTransactionManager#rollback
与 Commit 操作类似，向 Server 端发起请求。
控制台打印：
11:20:12.756 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', extraData='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
3、分支回滚处理
io.seata.core.rpc.processor.client.RmBranchRollbackProcessor#process
io.seata.rm.AbstractRMHandler#doBranchRollback
io.seata.rm.datasource.DataSourceManager#branchRollback
在 io.seata.rm.datasource.undo.AbstractUndoLogManager#undo 这一步完成数据的回滚以及 undo_log 记录删除操作。
Client 端控制台打印：
11:20:12.789 INFO 7432 --- [h_RMROLE_1_4_16] i.s.c.r.p.c.RmBranchRollbackProcessor : rm handle branch rollback process:BranchRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714227, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
11:20:12.790 INFO 7432 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacking: 192.168.2.126:8091:2252231336169714223 2252231336169714227 jdbc:mysql://192.168.2.158:3326/seata
11:20:12.857 INFO 7432 --- [h_RMROLE_1_4_16] i.s.r.d.undo.AbstractUndoLogManager : xid 192.168.2.126:8091:2252231336169714223 branch 2252231336169714227, undo_log deleted with GlobalFinished
11:20:12.859 INFO 7432 --- [h_RMROLE_1_4_16] i.seata.rm.datasource.DataSourceManager : branch rollback success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714227
11:20:12.859 INFO 7432 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacked result: PhaseTwo_Rollbacked
Server 端控制台打印：
11:20:12.861 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchRollbackResponse{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714227, branchStatus=PhaseTwo_Rollbacked, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.880 INFO --- [verHandlerThread_1_43_500] [server.coordinator.DefaultCore] [a$doGlobalRollback$3] [192.168.2.126:8091:2252231336169714223] : Rollback branch transaction successfully, xid = 192.168.2.126:8091:2252231336169714223 branchId = 2252231336169714227
所有分支回滚完成后，全局回滚完成。
11:20:12.991 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : transaction end, xid = 192.168.2.126:8091:2252231336169714223
11:20:12.992 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : [192.168.2.126:8091:2252231336169714223] rollback status: Rollbacked
11:22:23.467 INFO --- [ RetryRollbacking_1_1] [server.coordinator.DefaultCore] [ doGlobalRollback] [192.168.2.126:8091:2252231336169714223] : Rollback global transaction successfully, xid = 192.168.2.126:8091:2252231336169714223.
附录
Commit 调用流程 Client 端控制台输出
业务模块（business-xa）
2023-09-01 11:40:09.539 INFO 17724 --- [nio-8084-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2023-09-01 11:40:09.540 INFO 17724 --- [nio-8084-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2023-09-01 11:40:09.547 INFO 17724 --- [nio-8084-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 7 ms
2023-09-01 11:40:09.603 INFO 17724 --- [nio-8084-exec-1] io.seata.tm.TransactionManagerHolder : TransactionManager Singleton io.seata.tm.DefaultTransactionManager@76dc29e2
2023-09-01 11:40:09.630 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : Begin new global transaction [192.168.2.117:8091:2252230319988862988]
2023-09-01 11:40:09.635 INFO 17724 --- [nio-8084-exec-1] io.seata.sample.service.BusinessService : New Transaction Begins: 192.168.2.117:8091:2252230319988862988
2023-09-01 11:40:10.291 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : transaction 192.168.2.117:8091:2252230319988862988 will be commit
2023-09-01 11:40:10.515 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : transaction end, xid = 192.168.2.117:8091:2252230319988862988
2023-09-01 11:40:10.515 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : [192.168.2.117:8091:2252230319988862988] commit status: Committed
库存模块（stock-xa）
2023-09-01 11:40:09.651 INFO 1296 --- [nio-8081-exec-2] io.seata.sample.service.StockService : deduct stock balance in transaction: 192.168.2.117:8091:2252230319988862988
2023-09-01 11:40:09.765 INFO 1296 --- [nio-8081-exec-2] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.117:8091:2252230319988862988, branchId:2252230319988862990, lockKeys:stock_tbl:9
2023-09-01 11:40:09.818 WARN 1296 --- [nio-8081-exec-2] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.117:8091:2252230319988862988 to null
2023-09-01 11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchCommitProcessor : rm client handle branch commit process:BranchCommitRequest{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862990, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
2023-09-01 11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch committing: 192.168.2.117:8091:2252230319988862988 2252230319988862990 jdbc:mysql://192.168.2.158:3326/seata null
2023-09-01 11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch commit result: PhaseTwo_Committed
订单模块（order-xa）
2023-09-01 11:40:09.839 INFO 17280 --- [nio-8082-exec-4] io.seata.sample.service.OrderService : create order in transaction: 192.168.2.117:8091:2252230319988862988
2023-09-01 11:40:09.963 INFO 17280 --- [nio-8082-exec-4] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.117:8091:2252230319988862988, branchId:2252230319988862992, lockKeys:order_tbl:15
2023-09-01 11:40:10.290 WARN 17280 --- [nio-8082-exec-4] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.117:8091:2252230319988862988 to null
2023-09-01 11:40:11.356 INFO 17280 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchCommitProcessor : rm client handle branch commit process:BranchCommitRequest{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862992, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
2023-09-01 11:40:11.357 INFO 17280 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch committing: 192.168.2.117:8091:2252230319988862988 2252230319988862992 jdbc:mysql://192.168.2.158:3326/seata null
2023-09-01 11:40:11.357 INFO 17280 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch commit result: PhaseTwo_Committed
账户模块（account-xa）
2023-09-01 11:40:10.012 INFO 7696 --- [nio-8083-exec-3] io.seata.sample.service.AccountService : reduce account balance in transaction: 192.168.2.117:8091:2252230319988862988
2023-09-01 11:40:10.093 INFO 7696 --- [nio-8083-exec-3] io.seata.sample.service.AccountService : balance after transaction: 7000
2023-09-01 11:40:10.203 INFO 7696 --- [nio-8083-exec-3] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.117:8091:2252230319988862988, branchId:2252230319988862994, lockKeys:account_tbl:9
2023-09-01 11:40:10.289 WARN 7696 --- [nio-8083-exec-3] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.117:8091:2252230319988862988 to null
2023-09-01 11:40:11.384 INFO 7696 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchCommitProcessor : rm client handle branch commit process:BranchCommitRequest{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862994, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='{"autoCommit":false}'}
2023-09-01 11:40:11.385 INFO 7696 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch committing: 192.168.2.117:8091:2252230319988862988 2252230319988862994 jdbc:mysql://192.168.2.158:3326/seata {"autoCommit":false}
2023-09-01 11:40:11.385 INFO 7696 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch commit result: PhaseTwo_Committed
Commit 调用流程 Server 端控制台输出
11:40:09.610 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalBeginRequest{transactionName='purchase(java.lang.String, java.lang.String, int, boolean)', timeout=60000}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.624 INFO --- [verHandlerThread_1_11_500] [coordinator.DefaultCoordinator] [ doGlobalBegin] [192.168.2.117:8091:2252230319988862988] : Begin new global transaction applicationId: business-xa,transactionServiceGroup: my_test_tx_group, transactionName: purchase(java.lang.String, java.lang.String, int, boolean),timeout:60000,xid:192.168.2.117:8091:2252230319988862988
11:40:09.625 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalBeginResponse{xid='192.168.2.117:8091:2252230319988862988', extraData='null', resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.697 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.117:8091:2252230319988862988', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='stock_tbl:9', applicationData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.764 INFO --- [nPool.commonPool-worker-3] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.117:8091:2252230319988862988] : Register branch successfully, xid = 192.168.2.117:8091:2252230319988862988, branchId = 2252230319988862990, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = stock_tbl:9
11:40:09.764 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252230319988862990, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.882 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.117:8091:2252230319988862988', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='order_tbl:15', applicationData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.962 INFO --- [nPool.commonPool-worker-3] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.117:8091:2252230319988862988] : Register branch successfully, xid = 192.168.2.117:8091:2252230319988862988, branchId = 2252230319988862992, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = order_tbl:15
11:40:09.962 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252230319988862992, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.096 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.117:8091:2252230319988862988', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='account_tbl:9', applicationData='{"autoCommit":false}'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.202 INFO --- [nPool.commonPool-worker-3] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.117:8091:2252230319988862988] : Register branch successfully, xid = 192.168.2.117:8091:2252230319988862988, branchId = 2252230319988862994, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = account_tbl:9
11:40:10.203 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252230319988862994, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.294 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalCommitRequest{xid='192.168.2.117:8091:2252230319988862988', extraData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.511 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalCommitResponse{globalStatus=Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.342 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchCommitResponse{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862990, branchStatus=PhaseTwo_Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.356 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [bda$doGlobalCommit$1] [192.168.2.117:8091:2252230319988862988] : Commit branch transaction successfully, xid = 192.168.2.117:8091:2252230319988862988 branchId = 2252230319988862990
11:40:11.359 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchCommitResponse{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862992, branchStatus=PhaseTwo_Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.383 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [bda$doGlobalCommit$1] [192.168.2.117:8091:2252230319988862988] : Commit branch transaction successfully, xid = 192.168.2.117:8091:2252230319988862988 branchId = 2252230319988862992
11:40:11.387 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchCommitResponse{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862994, branchStatus=PhaseTwo_Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.402 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [bda$doGlobalCommit$1] [192.168.2.117:8091:2252230319988862988] : Commit branch transaction successfully, xid = 192.168.2.117:8091:2252230319988862988 branchId = 2252230319988862994
11:40:11.461 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [ doGlobalCommit] [192.168.2.117:8091:2252230319988862988] : Committing global transaction is successfully done, xid = 192.168.2.117:8091:2252230319988862988.
按时序整理的完整流程输出（包含Client 端、Server 端）
11:40:09.603 INFO 17724 --- [nio-8084-exec-1] io.seata.tm.TransactionManagerHolder : TransactionManager Singleton io.seata.tm.DefaultTransactionManager@76dc29e2
11:40:09.610 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalBeginRequest{transactionName='purchase(java.lang.String, java.lang.String, int, boolean)', timeout=60000}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.624 INFO --- [verHandlerThread_1_11_500] [coordinator.DefaultCoordinator] [ doGlobalBegin] [192.168.2.117:8091:2252230319988862988] : Begin new global transaction applicationId: business-xa,transactionServiceGroup: my_test_tx_group, transactionName: purchase(java.lang.String, java.lang.String, int, boolean),timeout:60000,xid:192.168.2.117:8091:2252230319988862988
11:40:09.625 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalBeginResponse{xid='192.168.2.117:8091:2252230319988862988', extraData='null', resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.630 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : Begin new global transaction [192.168.2.117:8091:2252230319988862988]
11:40:09.635 INFO 17724 --- [nio-8084-exec-1] io.seata.sample.service.BusinessService : New Transaction Begins: 192.168.2.117:8091:2252230319988862988
11:40:09.651 INFO 1296 --- [nio-8081-exec-2] io.seata.sample.service.StockService : deduct stock balance in transaction: 192.168.2.117:8091:2252230319988862988
11:40:09.697 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.117:8091:2252230319988862988', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='stock_tbl:9', applicationData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.764 INFO --- [nPool.commonPool-worker-3] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.117:8091:2252230319988862988] : Register branch successfully, xid = 192.168.2.117:8091:2252230319988862988, branchId = 2252230319988862990, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = stock_tbl:9
11:40:09.764 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252230319988862990, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.765 INFO 1296 --- [nio-8081-exec-2] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.117:8091:2252230319988862988, branchId:2252230319988862990, lockKeys:stock_tbl:9
11:40:09.818 WARN 1296 --- [nio-8081-exec-2] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.117:8091:2252230319988862988 to null
11:40:09.839 INFO 17280 --- [nio-8082-exec-4] io.seata.sample.service.OrderService : create order in transaction: 192.168.2.117:8091:2252230319988862988
11:40:09.882 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.117:8091:2252230319988862988', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='order_tbl:15', applicationData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.962 INFO --- [nPool.commonPool-worker-3] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.117:8091:2252230319988862988] : Register branch successfully, xid = 192.168.2.117:8091:2252230319988862988, branchId = 2252230319988862992, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = order_tbl:15
11:40:09.962 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252230319988862992, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:09.963 INFO 17280 --- [nio-8082-exec-4] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.117:8091:2252230319988862988, branchId:2252230319988862992, lockKeys:order_tbl:15
11:40:10.012 INFO 7696 --- [nio-8083-exec-3] io.seata.sample.service.AccountService : reduce account balance in transaction: 192.168.2.117:8091:2252230319988862988
11:40:10.093 INFO 7696 --- [nio-8083-exec-3] io.seata.sample.service.AccountService : balance after transaction: 7000
11:40:10.096 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.117:8091:2252230319988862988', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='account_tbl:9', applicationData='{"autoCommit":false}'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.202 INFO --- [nPool.commonPool-worker-3] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.117:8091:2252230319988862988] : Register branch successfully, xid = 192.168.2.117:8091:2252230319988862988, branchId = 2252230319988862994, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = account_tbl:9
11:40:10.203 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252230319988862994, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.203 INFO 7696 --- [nio-8083-exec-3] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.117:8091:2252230319988862988, branchId:2252230319988862994, lockKeys:account_tbl:9
11:40:10.289 WARN 7696 --- [nio-8083-exec-3] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.117:8091:2252230319988862988 to null
11:40:10.290 WARN 17280 --- [nio-8082-exec-4] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.117:8091:2252230319988862988 to null
11:40:10.291 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : transaction 192.168.2.117:8091:2252230319988862988 will be commit
11:40:10.294 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalCommitRequest{xid='192.168.2.117:8091:2252230319988862988', extraData='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.511 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalCommitResponse{globalStatus=Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:10.515 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : transaction end, xid = 192.168.2.117:8091:2252230319988862988
11:40:10.515 INFO 17724 --- [nio-8084-exec-1] i.seata.tm.api.DefaultGlobalTransaction : [192.168.2.117:8091:2252230319988862988] commit status: Committed
11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchCommitProcessor : rm client handle branch commit process:BranchCommitRequest{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862990, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch committing: 192.168.2.117:8091:2252230319988862988 2252230319988862990 jdbc:mysql://192.168.2.158:3326/seata null
11:40:11.340 INFO 1296 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch commit result: PhaseTwo_Committed
11:40:11.342 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchCommitResponse{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862990, branchStatus=PhaseTwo_Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.356 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [bda$doGlobalCommit$1] [192.168.2.117:8091:2252230319988862988] : Commit branch transaction successfully, xid = 192.168.2.117:8091:2252230319988862988 branchId = 2252230319988862990
11:40:11.356 INFO 17280 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchCommitProcessor : rm client handle branch commit process:BranchCommitRequest{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862992, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
11:40:11.357 INFO 17280 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch committing: 192.168.2.117:8091:2252230319988862988 2252230319988862992 jdbc:mysql://192.168.2.158:3326/seata null
11:40:11.357 INFO 17280 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch commit result: PhaseTwo_Committed
11:40:11.359 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchCommitResponse{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862992, branchStatus=PhaseTwo_Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.383 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [bda$doGlobalCommit$1] [192.168.2.117:8091:2252230319988862988] : Commit branch transaction successfully, xid = 192.168.2.117:8091:2252230319988862988 branchId = 2252230319988862992
11:40:11.384 INFO 7696 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchCommitProcessor : rm client handle branch commit process:BranchCommitRequest{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862994, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='{"autoCommit":false}'}
11:40:11.385 INFO 7696 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch committing: 192.168.2.117:8091:2252230319988862988 2252230319988862994 jdbc:mysql://192.168.2.158:3326/seata {"autoCommit":false}
11:40:11.385 INFO 7696 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch commit result: PhaseTwo_Committed
11:40:11.387 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchCommitResponse{xid='192.168.2.117:8091:2252230319988862988', branchId=2252230319988862994, branchStatus=PhaseTwo_Committed, resultCode=Success, msg='null'}, clientIp: 192.168.2.117, vgroup: my_test_tx_group
11:40:11.402 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [bda$doGlobalCommit$1] [192.168.2.117:8091:2252230319988862988] : Commit branch transaction successfully, xid = 192.168.2.117:8091:2252230319988862988 branchId = 2252230319988862994
11:40:11.461 INFO --- [ AsyncCommitting_1_1] [server.coordinator.DefaultCore] [ doGlobalCommit] [192.168.2.117:8091:2252230319988862988] : Committing global transaction is successfully done, xid = 192.168.2.117:8091:2252230319988862988.
Rollback 调用流程 Client 端控制台输出
业务模块（business-xa）
2023-09-04 11:20:12.590 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : Begin new global transaction [192.168.2.126:8091:2252231336169714223]
2023-09-04 11:20:12.590 INFO 21468 --- [nio-8084-exec-5] io.seata.sample.service.BusinessService : New Transaction Begins: 192.168.2.126:8091:2252231336169714223
2023-09-04 11:20:12.754 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : transaction 192.168.2.126:8091:2252231336169714223 will be rollback
2023-09-04 11:20:12.991 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : transaction end, xid = 192.168.2.126:8091:2252231336169714223
2023-09-04 11:20:12.992 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : [192.168.2.126:8091:2252231336169714223] rollback status: Rollbacked
库存模块（stock-xa）
2023-09-04 11:20:12.592 INFO 23144 --- [nio-8081-exec-4] io.seata.sample.service.StockService : deduct stock balance in transaction: 192.168.2.126:8091:2252231336169714223
2023-09-04 11:20:12.635 INFO 23144 --- [nio-8081-exec-4] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714225, lockKeys:stock_tbl:13
2023-09-04 11:20:12.663 WARN 23144 --- [nio-8081-exec-4] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.126:8091:2252231336169714223 to null
2023-09-04 11:20:12.883 INFO 23144 --- [h_RMROLE_1_4_16] i.s.c.r.p.c.RmBranchRollbackProcessor : rm handle branch rollback process:BranchRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714225, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
2023-09-04 11:20:12.885 INFO 23144 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacking: 192.168.2.126:8091:2252231336169714223 2252231336169714225 jdbc:mysql://192.168.2.158:3326/seata
2023-09-04 11:20:12.949 INFO 23144 --- [h_RMROLE_1_4_16] i.s.r.d.undo.AbstractUndoLogManager : xid 192.168.2.126:8091:2252231336169714223 branch 2252231336169714225, undo_log deleted with GlobalFinished
2023-09-04 11:20:12.953 INFO 23144 --- [h_RMROLE_1_4_16] i.seata.rm.datasource.DataSourceManager : branch rollback success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714225
2023-09-04 11:20:12.953 INFO 23144 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacked result: PhaseTwo_Rollbacked
订单模块（order-xa）
2023-09-04 11:20:12.667 INFO 7432 --- [nio-8082-exec-4] io.seata.sample.service.OrderService : create order in transaction: 192.168.2.126:8091:2252231336169714223
2023-09-04 11:20:12.711 INFO 7432 --- [nio-8082-exec-4] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714227, lockKeys:order_tbl:28
java.lang.RuntimeException: Failed to call Account Service.
at io.seata.sample.service.OrderService.create(OrderService.java:37)
at io.seata.sample.controller.OrderController.create(OrderController.java:21)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:879)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
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:634)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
2023-09-04 11:20:12.753 WARN 7432 --- [nio-8082-exec-4] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.126:8091:2252231336169714223 to null
2023-09-04 11:20:12.789 INFO 7432 --- [h_RMROLE_1_4_16] i.s.c.r.p.c.RmBranchRollbackProcessor : rm handle branch rollback process:BranchRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714227, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
2023-09-04 11:20:12.790 INFO 7432 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacking: 192.168.2.126:8091:2252231336169714223 2252231336169714227 jdbc:mysql://192.168.2.158:3326/seata
2023-09-04 11:20:12.857 INFO 7432 --- [h_RMROLE_1_4_16] i.s.r.d.undo.AbstractUndoLogManager : xid 192.168.2.126:8091:2252231336169714223 branch 2252231336169714227, undo_log deleted with GlobalFinished
2023-09-04 11:20:12.859 INFO 7432 --- [h_RMROLE_1_4_16] i.seata.rm.datasource.DataSourceManager : branch rollback success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714227
2023-09-04 11:20:12.859 INFO 7432 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacked result: PhaseTwo_Rollbacked
账户模块（account-xa）
2023-09-04 11:20:12.730 INFO 16208 --- [nio-8083-exec-4] io.seata.sample.service.AccountService : reduce account balance in transaction: 192.168.2.126:8091:2252231336169714223
2023-09-04 11:20:12.740 INFO 16208 --- [nio-8083-exec-4] io.seata.sample.service.AccountService : balance after transaction: -2000
2023-09-04 11:20:12.749 WARN 16208 --- [nio-8083-exec-4] c.a.c.seata.web.SeataHandlerInterceptor : xid in change during RPC from 192.168.2.126:8091:2252231336169714223 to null
java.lang.RuntimeException: Not Enough Money ...
at io.seata.sample.service.AccountService.reduce(AccountService.java:31)
at io.seata.sample.service.AccountService$$FastClassBySpringCGLIB$$533284cb.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:771)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:367)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
at io.seata.sample.service.AccountService$$EnhancerBySpringCGLIB$$a0f97bf3.reduce(<generated>)
at io.seata.sample.controller.AccountController.reduce(AccountController.java:21)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:879)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
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:634)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
Rollback 调用流程 Server 端控制台输出
11:20:12.576 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalBeginRequest{transactionName='purchase(java.lang.String, java.lang.String, int, boolean)', timeout=60000}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.589 INFO --- [verHandlerThread_1_40_500] [coordinator.DefaultCoordinator] [ doGlobalBegin] [192.168.2.126:8091:2252231336169714223] : Begin new global transaction applicationId: business-xa,transactionServiceGroup: my_test_tx_group, transactionName: purchase(java.lang.String, java.lang.String, int, boolean),timeout:60000,xid:192.168.2.126:8091:2252231336169714223
11:20:12.590 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalBeginResponse{xid='192.168.2.126:8091:2252231336169714223', extraData='null', resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.601 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.126:8091:2252231336169714223', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='stock_tbl:13', applicationData='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.633 INFO --- [nPool.commonPool-worker-9] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.126:8091:2252231336169714223] : Register branch successfully, xid = 192.168.2.126:8091:2252231336169714223, branchId = 2252231336169714225, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = stock_tbl:13
11:20:12.634 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252231336169714225, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.675 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.126:8091:2252231336169714223', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='order_tbl:28', applicationData='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.709 INFO --- [nPool.commonPool-worker-9] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.126:8091:2252231336169714223] : Register branch successfully, xid = 192.168.2.126:8091:2252231336169714223, branchId = 2252231336169714227, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = order_tbl:28
11:20:12.710 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252231336169714227, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.756 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', extraData='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.861 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchRollbackResponse{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714227, branchStatus=PhaseTwo_Rollbacked, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.880 INFO --- [verHandlerThread_1_43_500] [server.coordinator.DefaultCore] [a$doGlobalRollback$3] [192.168.2.126:8091:2252231336169714223] : Rollback branch transaction successfully, xid = 192.168.2.126:8091:2252231336169714223 branchId = 2252231336169714227
11:20:12.957 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchRollbackResponse{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714225, branchStatus=PhaseTwo_Rollbacked, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.984 INFO --- [verHandlerThread_1_43_500] [server.coordinator.DefaultCore] [a$doGlobalRollback$3] [192.168.2.126:8091:2252231336169714223] : Rollback branch transaction successfully, xid = 192.168.2.126:8091:2252231336169714223 branchId = 2252231336169714225
11:20:12.985 INFO --- [verHandlerThread_1_43_500] [server.coordinator.DefaultCore] [ doGlobalRollback] [192.168.2.126:8091:2252231336169714223] : Rollback global transaction successfully, xid = 192.168.2.126:8091:2252231336169714223.
11:20:12.986 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalRollbackResponse{globalStatus=Rollbacked, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:22:23.467 INFO --- [ RetryRollbacking_1_1] [server.coordinator.DefaultCore] [ doGlobalRollback] [192.168.2.126:8091:2252231336169714223] : Rollback global transaction successfully, xid = 192.168.2.126:8091:2252231336169714223.
按时序整理的完整流程输出（包含Client 端、Server 端）
11:20:12.576 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalBeginRequest{transactionName='purchase(java.lang.String, java.lang.String, int, boolean)', timeout=60000}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.589 INFO --- [verHandlerThread_1_40_500] [coordinator.DefaultCoordinator] [ doGlobalBegin] [192.168.2.126:8091:2252231336169714223] : Begin new global transaction applicationId: business-xa,transactionServiceGroup: my_test_tx_group, transactionName: purchase(java.lang.String, java.lang.String, int, boolean),timeout:60000,xid:192.168.2.126:8091:2252231336169714223
11:20:12.590 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalBeginResponse{xid='192.168.2.126:8091:2252231336169714223', extraData='null', resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.590 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : Begin new global transaction [192.168.2.126:8091:2252231336169714223]
11:20:12.590 INFO 21468 --- [nio-8084-exec-5] io.seata.sample.service.BusinessService : New Transaction Begins: 192.168.2.126:8091:2252231336169714223
11:20:12.592 INFO 23144 --- [nio-8081-exec-4] io.seata.sample.service.StockService : deduct stock balance in transaction: 192.168.2.126:8091:2252231336169714223
11:20:12.601 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.126:8091:2252231336169714223', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='stock_tbl:13', applicationData='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.633 INFO --- [nPool.commonPool-worker-9] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.126:8091:2252231336169714223] : Register branch successfully, xid = 192.168.2.126:8091:2252231336169714223, branchId = 2252231336169714225, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = stock_tbl:13
11:20:12.634 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252231336169714225, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.635 INFO 23144 --- [nio-8081-exec-4] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714225, lockKeys:stock_tbl:13
11:20:12.667 INFO 7432 --- [nio-8082-exec-4] io.seata.sample.service.OrderService : create order in transaction: 192.168.2.126:8091:2252231336169714223
11:20:12.675 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[merged]: BranchRegisterRequest{xid='192.168.2.126:8091:2252231336169714223', branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', lockKey='order_tbl:28', applicationData='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.709 INFO --- [nPool.commonPool-worker-9] [erver.coordinator.AbstractCore] [bda$branchRegister$0] [192.168.2.126:8091:2252231336169714223] : Register branch successfully, xid = 192.168.2.126:8091:2252231336169714223, branchId = 2252231336169714227, resourceId = jdbc:mysql://192.168.2.158:3326/seata ,lockKeys = order_tbl:28
11:20:12.710 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[merged]: BranchRegisterResponse{branchId=2252231336169714227, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.711 INFO 7432 --- [nio-8082-exec-4] io.seata.rm.AbstractResourceManager : branch register success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714227, lockKeys:order_tbl:28
11:20:12.730 INFO 16208 --- [nio-8083-exec-4] io.seata.sample.service.AccountService : reduce account balance in transaction: 192.168.2.126:8091:2252231336169714223
11:20:12.740 INFO 16208 --- [nio-8083-exec-4] io.seata.sample.service.AccountService : balance after transaction: -2000
java.lang.RuntimeException: Not Enough Money ...
11:20:12.754 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : transaction 192.168.2.126:8091:2252231336169714223 will be rollback
11:20:12.756 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: GlobalRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', extraData='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.789 INFO 7432 --- [h_RMROLE_1_4_16] i.s.c.r.p.c.RmBranchRollbackProcessor : rm handle branch rollback process:BranchRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714227, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
11:20:12.790 INFO 7432 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacking: 192.168.2.126:8091:2252231336169714223 2252231336169714227 jdbc:mysql://192.168.2.158:3326/seata
11:20:12.857 INFO 7432 --- [h_RMROLE_1_4_16] i.s.r.d.undo.AbstractUndoLogManager : xid 192.168.2.126:8091:2252231336169714223 branch 2252231336169714227, undo_log deleted with GlobalFinished
11:20:12.859 INFO 7432 --- [h_RMROLE_1_4_16] i.seata.rm.datasource.DataSourceManager : branch rollback success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714227
11:20:12.859 INFO 7432 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacked result: PhaseTwo_Rollbacked
11:20:12.861 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchRollbackResponse{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714227, branchStatus=PhaseTwo_Rollbacked, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.880 INFO --- [verHandlerThread_1_43_500] [server.coordinator.DefaultCore] [a$doGlobalRollback$3] [192.168.2.126:8091:2252231336169714223] : Rollback branch transaction successfully, xid = 192.168.2.126:8091:2252231336169714223 branchId = 2252231336169714227
11:20:12.883 INFO 23144 --- [h_RMROLE_1_4_16] i.s.c.r.p.c.RmBranchRollbackProcessor : rm handle branch rollback process:BranchRollbackRequest{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714225, branchType=AT, resourceId='jdbc:mysql://192.168.2.158:3326/seata', applicationData='null'}
11:20:12.885 INFO 23144 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacking: 192.168.2.126:8091:2252231336169714223 2252231336169714225 jdbc:mysql://192.168.2.158:3326/seata
11:20:12.949 INFO 23144 --- [h_RMROLE_1_4_16] i.s.r.d.undo.AbstractUndoLogManager : xid 192.168.2.126:8091:2252231336169714223 branch 2252231336169714225, undo_log deleted with GlobalFinished
11:20:12.953 INFO 23144 --- [h_RMROLE_1_4_16] i.seata.rm.datasource.DataSourceManager : branch rollback success, xid:192.168.2.126:8091:2252231336169714223, branchId:2252231336169714225
11:20:12.953 INFO 23144 --- [h_RMROLE_1_4_16] io.seata.rm.AbstractRMHandler : Branch Rollbacked result: PhaseTwo_Rollbacked
11:20:12.957 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : receive msg[single]: BranchRollbackResponse{xid='192.168.2.126:8091:2252231336169714223', branchId=2252231336169714225, branchStatus=PhaseTwo_Rollbacked, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.984 INFO --- [verHandlerThread_1_43_500] [server.coordinator.DefaultCore] [a$doGlobalRollback$3] [192.168.2.126:8091:2252231336169714223] : Rollback branch transaction successfully, xid = 192.168.2.126:8091:2252231336169714223 branchId = 2252231336169714225
11:20:12.985 INFO --- [verHandlerThread_1_43_500] [server.coordinator.DefaultCore] [ doGlobalRollback] [192.168.2.126:8091:2252231336169714223] : Rollback global transaction successfully, xid = 192.168.2.126:8091:2252231336169714223.
11:20:12.986 INFO --- [ batchLoggerPrint_1_1] [ocessor.server.BatchLogHandler] [ run] [] : result msg[single]: GlobalRollbackResponse{globalStatus=Rollbacked, resultCode=Success, msg='null'}, clientIp: 192.168.2.126, vgroup: my_test_tx_group
11:20:12.991 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : transaction end, xid = 192.168.2.126:8091:2252231336169714223
11:20:12.992 INFO 21468 --- [nio-8084-exec-5] i.seata.tm.api.DefaultGlobalTransaction : [192.168.2.126:8091:2252231336169714223] rollback status: Rollbacked
11:22:23.467 INFO --- [ RetryRollbacking_1_1] [server.coordinator.DefaultCore] [ doGlobalRollback] [192.168.2.126:8091:2252231336169714223] : Rollback global transaction successfully, xid = 192.168.2.126:8091:2252231336169714223.
（完）
