Seata 分布式事务功能测试(二)

前置内容:Seata 分布式事务功能测试(一)

增加了一个特殊逻辑,只为验证能否多次调用同一个服务。

//扣减用户账户
//为了测试多次调用同一个服务,这里分成两次扣款
TAccountVO accountVO = new TAccountVO();
accountVO.setUserId(orderVO.getUserId());
Double totalMount = orderVO.getAmount();
accountVO.setAmount(totalMount/2);
//第一次扣款
accountService.decreaseAccount(accountVO);
//第二次扣款
accountService.decreaseAccount(accountVO);

1. 测试用例 1

属性
库存500
余额5000
商品编号C201901140001
用户1

结果:由于 5000 分两次扣款第一次成功,第二次失败,应该全部回滚。库存应该不变!

1.1 business 日志:

2019-10-11 09:19:56,876 [DubboServerHandler-10.10.10.130:20883-thread-18] INFO  i.s.t.a.DefaultGlobalTransaction - Begin new global transaction [10.42.1.30:8091:2024332051]
开始全局事务,XID = 10.42.1.30:8091:2024332051
2019-10-11 09:19:59,528 [DubboServerHandler-10.10.10.130:20883-thread-18] INFO  i.s.t.a.DefaultGlobalTransaction - [10.42.1.30:8091:2024332051] rollback status:Rollbacked

1.2 storage 日志:

2019-10-11 09:19:57,335 [DubboServerHandler-10.10.10.130:20882-thread-4] DEBUG c.n.s.d.T.decreaseStorage - ==>  Preparing: update t_storage set count = count-500 where commodity_code = ? and count >= ?
2019-10-11 09:19:57,336 [DubboServerHandler-10.10.10.130:20882-thread-4] DEBUG c.n.s.d.T.decreaseStorage - ==> Parameters: C201901140001(String), 500(Integer)
2019-10-11 09:19:57,677 [DubboServerHandler-10.10.10.130:20882-thread-4] DEBUG c.n.s.d.T.decreaseStorage - <==    Updates: 1
2019-10-11 09:19:59,427 [rpcDispatch_RMROLE_3_8] INFO  i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332051,branchId=2024332054,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_storage,applicationData=null
2019-10-11 09:19:59,432 [rpcDispatch_RMROLE_3_8] INFO  i.s.r.AbstractRMHandler - Branch Rollbacking: 10.42.1.30:8091:2024332051 2024332054 jdbc:mysql://10.10.10.233:3306/seata_demo_storage
2019-10-11 09:19:59,476 [rpcDispatch_RMROLE_3_8] INFO  i.s.r.d.u.m.MySQLUndoLogManager - xid 10.42.1.30:8091:2024332051 branch 2024332054, undo_log deleted with GlobalFinished
2019-10-11 09:19:59,487 [rpcDispatch_RMROLE_3_8] INFO  i.s.r.AbstractRMHandler - Branch Rollbacked result: PhaseTwo_Rollbacked

1.3 account 日志:

2019-10-11 09:19:58,447 [DubboServerHandler-10.10.10.130:20880-thread-6] DEBUG c.n.a.d.T.decreaseAccount - ==>  Preparing: update t_account set amount = amount-2500.0 where user_id = ? and amount > ?
2019-10-11 09:19:58,448 [DubboServerHandler-10.10.10.130:20880-thread-6] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 2500.0(Double)
2019-10-11 09:19:58,852 [DubboServerHandler-10.10.10.130:20880-thread-6] DEBUG c.n.a.d.T.decreaseAccount - <==    Updates: 1
2019-10-11 09:19:58,971 [DubboServerHandler-10.10.10.130:20880-thread-7] DEBUG c.n.a.d.T.decreaseAccount - ==>  Preparing: update t_account set amount = amount-2500.0 where user_id = ? and amount > ?
2019-10-11 09:19:58,972 [DubboServerHandler-10.10.10.130:20880-thread-7] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 2500.0(Double)
2019-10-11 09:19:58,990 [DubboServerHandler-10.10.10.130:20880-thread-7] DEBUG c.n.a.d.T.decreaseAccount - <==    Updates: 0
2019-10-11 09:19:59,001 [DubboServerHandler-10.10.10.130:20880-thread-7] ERROR o.a.d.r.f.ExceptionFilter -  [DUBBO] Got unchecked and undeclared exception which called by 10.10.10.130. service: com.netstar.account.api.TAccountService, method: decreaseAccount, exception: java.lang.RuntimeException: 扣款失败, dubbo version: 2.7.1, current host: 10.10.10.130
java.lang.RuntimeException: 扣款失败
2019-10-11 09:19:59,068 [rpcDispatch_RMROLE_2_8] INFO  i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332051,branchId=2024332058,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_account,applicationData=null
2019-10-11 09:19:59,069 [rpcDispatch_RMROLE_2_8] INFO  i.s.r.AbstractRMHandler - Branch Rollbacking: 10.42.1.30:8091:2024332051 2024332058 jdbc:mysql://10.10.10.233:3306/seata_demo_account
2019-10-11 09:19:59,148 [rpcDispatch_RMROLE_2_8] INFO  i.s.r.d.u.m.MySQLUndoLogManager - xid 10.42.1.30:8091:2024332051 branch 2024332058, undo_log deleted with GlobalFinished
2019-10-11 09:19:59,155 [rpcDispatch_RMROLE_2_8] INFO  i.s.r.AbstractRMHandler - Branch Rollbacked result: PhaseTwo_Rollbacked

1.4 order 日志:

2019-10-11 09:19:58,098 [DubboServerHandler-10.10.10.130:20881-thread-2] INFO  i.s.c.l.EnhancedServiceLoader - load ContextCore[null] extension by class[io.seata.core.context.ThreadLocalContextCore]
2019-10-11 09:19:59,015 [DubboServerHandler-10.10.10.130:20881-thread-2] ERROR o.a.d.r.f.ExceptionFilter -  [DUBBO] Got unchecked and undeclared exception which called by 10.10.10.130. service: com.netstar.order.api.TOrderService, method: createOrder, exception: java.lang.RuntimeException: 扣款失败, dubbo version: 2.7.1, current host: 10.10.10.130
java.lang.RuntimeException: 扣款失败

1.5 合并日志看整体执行顺序

服务时间日志
business2019-10-11 09:19:56,876[DubboServerHandler-10.10.10.130:20883-thread-18] INFO i.s.t.a.DefaultGlobalTransaction - Begin new global transaction [10.42.1.30:8091:2024332051]
business2019-10-11 09:19:56,876开始全局事务,XID = 10.42.1.30:8091:2024332051
storage2019-10-11 09:19:57,335[DubboServerHandler-10.10.10.130:20882-thread-4] DEBUG c.n.s.d.T.decreaseStorage - ==> Preparing: update t_storage set count = count-500 where commodity_code = ? and count >= ?
storage2019-10-11 09:19:57,336[DubboServerHandler-10.10.10.130:20882-thread-4] DEBUG c.n.s.d.T.decreaseStorage - ==> Parameters: C201901140001(String), 500(Integer)
storage2019-10-11 09:19:57,677[DubboServerHandler-10.10.10.130:20882-thread-4] DEBUG c.n.s.d.T.decreaseStorage - <== Updates: 1
order2019-10-11 09:19:58,098[DubboServerHandler-10.10.10.130:20881-thread-2] INFO i.s.c.l.EnhancedServiceLoader - load ContextCore[null] extension by class[io.seata.core.context.ThreadLocalContextCore]
account2019-10-11 09:19:58,447[DubboServerHandler-10.10.10.130:20880-thread-6] DEBUG c.n.a.d.T.decreaseAccount - ==> Preparing: update t_account set amount = amount-2500.0 where user_id = ? and amount > ?
account2019-10-11 09:19:58,448[DubboServerHandler-10.10.10.130:20880-thread-6] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 2500.0(Double)
account2019-10-11 09:19:58,852[DubboServerHandler-10.10.10.130:20880-thread-6] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 1
account2019-10-11 09:19:58,971[DubboServerHandler-10.10.10.130:20880-thread-7] DEBUG c.n.a.d.T.decreaseAccount - ==> Preparing: update t_account set amount = amount-2500.0 where user_id = ? and amount > ?
account2019-10-11 09:19:58,972[DubboServerHandler-10.10.10.130:20880-thread-7] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 2500.0(Double)
account2019-10-11 09:19:58,990[DubboServerHandler-10.10.10.130:20880-thread-7] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 0
account2019-10-11 09:19:59,001[DubboServerHandler-10.10.10.130:20880-thread-7] ERROR o.a.d.r.f.ExceptionFilter - [DUBBO] Got unchecked and undeclared exception which called by 10.10.10.130. service: com.netstar.account.api.TAccountService, method: decreaseAccount, exception: java.lang.RuntimeException: 扣款失败, dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:19:59,015[DubboServerHandler-10.10.10.130:20881-thread-2] ERROR o.a.d.r.f.ExceptionFilter - [DUBBO] Got unchecked and undeclared exception which called by 10.10.10.130. service: com.netstar.order.api.TOrderService, method: createOrder, exception: java.lang.RuntimeException: 扣款失败, dubbo version: 2.7.1, current host: 10.10.10.130
account2019-10-11 09:19:59,068[rpcDispatch_RMROLE_2_8] INFO i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332051,branchId=2024332058,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_account,applicationData=null
account2019-10-11 09:19:59,069[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - Branch Rollbacking: 10.42.1.30:8091:2024332051 2024332058 jdbc:mysql://10.10.10.233:3306/seata_demo_account
account2019-10-11 09:19:59,148[rpcDispatch_RMROLE_2_8] INFO i.s.r.d.u.m.MySQLUndoLogManager - xid 10.42.1.30:8091:2024332051 branch 2024332058, undo_log deleted with GlobalFinished
account2019-10-11 09:19:59,155[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - Branch Rollbacked result: PhaseTwo_Rollbacked
storage2019-10-11 09:19:59,427[rpcDispatch_RMROLE_3_8] INFO i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332051,branchId=2024332054,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_storage,applicationData=null
storage2019-10-11 09:19:59,432[rpcDispatch_RMROLE_3_8] INFO i.s.r.AbstractRMHandler - Branch Rollbacking: 10.42.1.30:8091:2024332051 2024332054 jdbc:mysql://10.10.10.233:3306/seata_demo_storage
storage2019-10-11 09:19:59,476[rpcDispatch_RMROLE_3_8] INFO i.s.r.d.u.m.MySQLUndoLogManager - xid 10.42.1.30:8091:2024332051 branch 2024332054, undo_log deleted with GlobalFinished
storage2019-10-11 09:19:59,487[rpcDispatch_RMROLE_3_8] INFO i.s.r.AbstractRMHandler - Branch Rollbacked result: PhaseTwo_Rollbacked
business2019-10-11 09:19:59,528[DubboServerHandler-10.10.10.130:20883-thread-18] INFO i.s.t.a.DefaultGlobalTransaction - [10.42.1.30:8091:2024332051] rollback status:Rollbacked

2. 测试用例 2

属性
库存1000
余额3000
商品编号C201901140001
用户1

结果:分两次各扣款1500,应该成功。

2.1 business 日志:

2019-10-11 09:47:36,456 [DubboServerHandler-10.10.10.130:20883-thread-26] INFO  i.s.t.a.DefaultGlobalTransaction - Begin new global transaction [10.42.1.30:8091:2024332392]
开始全局事务,XID = 10.42.1.30:8091:2024332392
2019-10-11 09:47:37,123 [DubboServerHandler-10.10.10.130:20883-thread-26] INFO  i.s.t.a.DefaultGlobalTransaction - [10.42.1.30:8091:2024332392] commit status:Committed

2.2 storage 日志:

2019-10-11 09:47:36,458 [DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - ==>  Preparing: update t_storage set count = count-500 where commodity_code = ? and count >= ?
2019-10-11 09:47:36,459 [DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - ==> Parameters: C201901140001(String), 500(Integer)
2019-10-11 09:47:36,462 [DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - <==    Updates: 1
2019-10-11 09:47:37,303 [rpcDispatch_RMROLE_2_8] INFO  i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332394,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_storage,applicationData=null
2019-10-11 09:47:37,303 [rpcDispatch_RMROLE_2_8] INFO  i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332394 jdbc:mysql://10.10.10.233:3306/seata_demo_storage null
2019-10-11 09:47:37,303 [rpcDispatch_RMROLE_2_8] INFO  i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed

2.3 account 日志:

2019-10-11 09:47:36,486 [DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - ==>  Preparing: update t_account set amount = amount-1500.0 where user_id = ? and amount > ?
2019-10-11 09:47:36,486 [DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 1500.0(Double)
2019-10-11 09:47:36,490 [DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - <==    Updates: 1
2019-10-11 09:47:36,513 [DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - ==>  Preparing: update t_account set amount = amount-1500.0 where user_id = ? and amount > ?
2019-10-11 09:47:36,514 [DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 1500.0(Double)
2019-10-11 09:47:36,517 [DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - <==    Updates: 1
2019-10-11 09:47:37,309 [rpcDispatch_RMROLE_5_8] INFO  i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332397,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_account,applicationData=null
2019-10-11 09:47:37,310 [rpcDispatch_RMROLE_5_8] INFO  i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332397 jdbc:mysql://10.10.10.233:3306/seata_demo_account null
2019-10-11 09:47:37,311 [rpcDispatch_RMROLE_5_8] INFO  i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed
2019-10-11 09:47:37,318 [rpcDispatch_RMROLE_6_8] INFO  i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332400,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_account,applicationData=null
2019-10-11 09:47:37,318 [rpcDispatch_RMROLE_6_8] INFO  i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332400 jdbc:mysql://10.10.10.233:3306/seata_demo_account null
2019-10-11 09:47:37,318 [rpcDispatch_RMROLE_6_8] INFO  i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed

2.4 order 日志:

2019-10-11 09:47:36,556 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  o.a.d.c.AbstractConfig -  [DUBBO] There's no valid monitor config found, if you want to open monitor statistics for Dubbo, please make sure your monitor is configured properly., dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,557 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  o.a.d.r.z.ZookeeperRegistry -  [DUBBO] Register: consumer://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=consumers&check=false&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,561 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  o.a.d.r.z.ZookeeperRegistry -  [DUBBO] Subscribe: consumer://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=providers,configurators,routers&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,564 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  o.a.d.r.z.ZookeeperRegistry -  [DUBBO] Notify urls for subscribe url consumer://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=providers,configurators,routers&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, urls: [dubbo://10.42.0.139:20880/com.robert.vesta.service.intf.IdService?anyhost=true&application=vesta-server&bean.name=com.robert.vesta.service.intf.IdService&default.deprecated=false&default.dynamic=false&default.register=true&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&interface=com.robert.vesta.service.intf.IdService&methods=genId,makeId,transTime,gentIds,expId&pid=1&register=true&release=2.7.1&retries=0&revision=1.0&side=provider&timeout=10000&timestamp=1569826292874&version=1.0, empty://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=configurators&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, empty://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=routers&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0], dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,567 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  o.a.d.r.t.AbstractClient -  [DUBBO] Successed connect to server /10.42.0.139:20880 from NettyClient 10.10.10.130 using dubbo version 2.7.1, channel is NettyChannel [channel=[id: 0x64bc142f, L:/10.10.10.130:55624 - R:/10.42.0.139:20880]], dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,567 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  o.a.d.r.t.AbstractClient -  [DUBBO] Start NettyClient WIN2008-130/10.10.10.130 connect to the server /10.42.0.139:20880, dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,568 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  o.a.d.c.AbstractConfig -  [DUBBO] Refer dubbo service com.robert.vesta.service.intf.IdService from url zookeeper://10.10.10.226:32181/org.apache.dubbo.registry.RegistryService?anyhost=true&application=order-server&bean.name=com.robert.vesta.service.intf.IdService&check=false&default.check=false&default.deprecated=false&default.dynamic=false&default.lazy=false&default.register=true&default.sticky=false&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&register=true&register.ip=10.10.10.130&release=2.7.1&remote.application=vesta-server&remote.timestamp=1569826292874&retries=0&revision=0.0.3&side=consumer&sticky=false&timeout=10000&timestamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,569 [DubboSaveMetadataReport-thread-1] INFO  o.a.d.m.s.z.ZookeeperMetadataReport -  [DUBBO] store consumer metadata. Identifier : org.apache.dubbo.metadata.identifier.MetadataIdentifier@7c57c6d7; definition: {side=consumer, release=2.7.1, methods=genId,makeId,transTime,gentIds,expId, default.lazy=false, lazy=false, default.check=false, dubbo=2.0.2, interface=com.robert.vesta.service.intf.IdService, version=1.0, revision=0.0.3, application=order-server, sticky=false, default.sticky=false}, dubbo version: 2.7.1, current host: 10.10.10.130
2019-10-11 09:47:36,850 [DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - ==>  Preparing: INSERT INTO t_order ( id,order_no,user_id,commodity_code,count,amount ) VALUES( ?,?,?,?,?,? )
2019-10-11 09:47:36,868 [DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - ==> Parameters: 1314752779943674870(Long), 8fc1c283b7de4199b8d6d0fb35c7c8aa(String), 1(String), C201901140001(String), 500(Integer), 3000.0(Double)
2019-10-11 09:47:36,946 [DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - <==    Updates: 1
2019-10-11 09:47:36,952 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  i.s.c.l.EnhancedServiceLoader - load LoadBalance[null] extension by class[io.seata.discovery.loadbalance.RandomLoadBalance]
2019-10-11 09:47:37,044 [DubboServerHandler-10.10.10.130:20881-thread-9] INFO  i.s.c.l.EnhancedServiceLoader - load UndoLogParser[jackson] extension by class[io.seata.rm.datasource.undo.parser.JacksonUndoLogParser]
2019-10-11 09:47:37,326 [rpcDispatch_RMROLE_1_8] INFO  i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332403,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_order,applicationData=null
2019-10-11 09:47:37,328 [rpcDispatch_RMROLE_1_8] INFO  i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332403 jdbc:mysql://10.10.10.233:3306/seata_demo_order null
2019-10-11 09:47:37,329 [rpcDispatch_RMROLE_1_8] INFO  i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed

2.5 合并日志看整体执行顺序

服务时间日志
business2019-10-11 09:47:36,456[DubboServerHandler-10.10.10.130:20883-thread-26] INFO i.s.t.a.DefaultGlobalTransaction - Begin new global transaction [10.42.1.30:8091:2024332392]
business2019-10-11 09:47:36,456开始全局事务,XID = 10.42.1.30:8091:2024332392
storage2019-10-11 09:47:36,458[DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - ==> Preparing: update t_storage set count = count-500 where commodity_code = ? and count >= ?
storage2019-10-11 09:47:36,459[DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - ==> Parameters: C201901140001(String), 500(Integer)
storage2019-10-11 09:47:36,462[DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - <== Updates: 1
account2019-10-11 09:47:36,486[DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - ==> Preparing: update t_account set amount = amount-1500.0 where user_id = ? and amount > ?
account2019-10-11 09:47:36,486[DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 1500.0(Double)
account2019-10-11 09:47:36,490[DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 1
account2019-10-11 09:47:36,513[DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - ==> Preparing: update t_account set amount = amount-1500.0 where user_id = ? and amount > ?
account2019-10-11 09:47:36,514[DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - ==> Parameters: 1(String), 1500.0(Double)
account2019-10-11 09:47:36,517[DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 1
order2019-10-11 09:47:36,556[DubboServerHandler-10.10.10.130:20881-thread-9] INFO o.a.d.c.AbstractConfig - [DUBBO] There’s no valid monitor config found, if you want to open monitor statistics for Dubbo, please make sure your monitor is configured properly., dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,557[DubboServerHandler-10.10.10.130:20881-thread-9] INFO o.a.d.r.z.ZookeeperRegistry - [DUBBO] Register: consumer://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=consumers&check=false&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,561[DubboServerHandler-10.10.10.130:20881-thread-9] INFO o.a.d.r.z.ZookeeperRegistry - [DUBBO] Subscribe: consumer://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=providers,configurators,routers&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,564[DubboServerHandler-10.10.10.130:20881-thread-9] INFO o.a.d.r.z.ZookeeperRegistry - [DUBBO] Notify urls for subscribe url consumer://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=providers,configurators,routers&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, urls: [dubbo://10.42.0.139:20880/com.robert.vesta.service.intf.IdService?anyhost=true&application=vesta-server&bean.name=com.robert.vesta.service.intf.IdService&default.deprecated=false&default.dynamic=false&default.register=true&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&interface=com.robert.vesta.service.intf.IdService&methods=genId,makeId,transTime,gentIds,expId&pid=1&register=true&release=2.7.1&retries=0&revision=1.0&side=provider&timeout=10000&timestamp=1569826292874&version=1.0, empty://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=configurators&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0, empty://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&category=routers&default.check=false&default.lazy=false&default.sticky=false&dubbo=2.0.2&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&release=2.7.1&revision=0.0.3&side=consumer&sticky=false&timestamp=1570758456541&version=1.0], dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,567[DubboServerHandler-10.10.10.130:20881-thread-9] INFO o.a.d.r.t.AbstractClient - [DUBBO] Successed connect to server /10.42.0.139:20880 from NettyClient 10.10.10.130 using dubbo version 2.7.1, channel is NettyChannel [channel=[id: 0x64bc142f, L:/10.10.10.130:55624 - R:/10.42.0.139:20880]], dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,567[DubboServerHandler-10.10.10.130:20881-thread-9] INFO o.a.d.r.t.AbstractClient - [DUBBO] Start NettyClient WIN2008-130/10.10.10.130 connect to the server /10.42.0.139:20880, dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,568[DubboServerHandler-10.10.10.130:20881-thread-9] INFO o.a.d.c.AbstractConfig - [DUBBO] Refer dubbo service com.robert.vesta.service.intf.IdService from url zookeeper://10.10.10.226:32181/org.apache.dubbo.registry.RegistryService?anyhost=true&application=order-server&bean.name=com.robert.vesta.service.intf.IdService&check=false&default.check=false&default.deprecated=false&default.dynamic=false&default.lazy=false&default.register=true&default.sticky=false&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&interface=com.robert.vesta.service.intf.IdService&lazy=false&methods=genId,makeId,transTime,gentIds,expId&pid=7380&register=true&register.ip=10.10.10.130&release=2.7.1&remote.application=vesta-server&remote.timestamp=1569826292874&retries=0&revision=0.0.3&side=consumer&sticky=false&timeout=10000&timestamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,569[DubboSaveMetadataReport-thread-1] INFO o.a.d.m.s.z.ZookeeperMetadataReport - [DUBBO] store consumer metadata. Identifier : org.apache.dubbo.metadata.identifier.MetadataIdentifier@7c57c6d7; definition: {side=consumer, release=2.7.1, methods=genId,makeId,transTime,gentIds,expId, default.lazy=false, lazy=false, default.check=false, dubbo=2.0.2, interface=com.robert.vesta.service.intf.IdService, version=1.0, revision=0.0.3, application=order-server, sticky=false, default.sticky=false}, dubbo version: 2.7.1, current host: 10.10.10.130
order2019-10-11 09:47:36,850[DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - ==> Preparing: INSERT INTO t_order ( id,order_no,user_id,commodity_code,count,amount ) VALUES( ?,?,?,?,?,? )
order2019-10-11 09:47:36,868[DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - ==> Parameters: 1314752779943674870(Long), 8fc1c283b7de4199b8d6d0fb35c7c8aa(String), 1(String), C201901140001(String), 500(Integer), 3000.0(Double)
order2019-10-11 09:47:36,946[DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - <== Updates: 1
order2019-10-11 09:47:36,952[DubboServerHandler-10.10.10.130:20881-thread-9] INFO i.s.c.l.EnhancedServiceLoader - load LoadBalance[null] extension by class[io.seata.discovery.loadbalance.RandomLoadBalance]
order2019-10-11 09:47:37,044[DubboServerHandler-10.10.10.130:20881-thread-9] INFO i.s.c.l.EnhancedServiceLoader - load UndoLogParser[jackson] extension by class[io.seata.rm.datasource.undo.parser.JacksonUndoLogParser]
business2019-10-11 09:47:37,123[DubboServerHandler-10.10.10.130:20883-thread-26] INFO i.s.t.a.DefaultGlobalTransaction - [10.42.1.30:8091:2024332392] commit status:Committed
storage2019-10-11 09:47:37,303[rpcDispatch_RMROLE_2_8] INFO i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332394,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_storage,applicationData=null
storage2019-10-11 09:47:37,303[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332394 jdbc:mysql://10.10.10.233:3306/seata_demo_storage null
storage2019-10-11 09:47:37,303[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed
account2019-10-11 09:47:37,309[rpcDispatch_RMROLE_5_8] INFO i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332397,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_account,applicationData=null
account2019-10-11 09:47:37,310[rpcDispatch_RMROLE_5_8] INFO i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332397 jdbc:mysql://10.10.10.233:3306/seata_demo_account null
account2019-10-11 09:47:37,311[rpcDispatch_RMROLE_5_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed
account2019-10-11 09:47:37,318[rpcDispatch_RMROLE_6_8] INFO i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332400,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_account,applicationData=null
account2019-10-11 09:47:37,318[rpcDispatch_RMROLE_6_8] INFO i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332400 jdbc:mysql://10.10.10.233:3306/seata_demo_account null
account2019-10-11 09:47:37,318[rpcDispatch_RMROLE_6_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed
order2019-10-11 09:47:37,326[rpcDispatch_RMROLE_1_8] INFO i.s.c.r.n.RmMessageListener - onMessage:xid=10.42.1.30:8091:2024332392,branchId=2024332403,branchType=AT,resourceId=jdbc:mysql://10.10.10.233:3306/seata_demo_order,applicationData=null
order2019-10-11 09:47:37,328[rpcDispatch_RMROLE_1_8] INFO i.s.r.AbstractRMHandler - Branch committing: 10.42.1.30:8091:2024332392 2024332403 jdbc:mysql://10.10.10.233:3306/seata_demo_order null
order2019-10-11 09:47:37,329[rpcDispatch_RMROLE_1_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed
  • 0
    点赞
  • 2
    收藏
    觉得还不错? 一键收藏
  • 打赏
    打赏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包

打赏作者

isea533

你的鼓励将是我创作的最大动力

¥1 ¥2 ¥4 ¥6 ¥10 ¥20
扫码支付:¥1
获取中
扫码支付

您的余额不足,请更换扫码支付或充值

打赏作者

实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值