前置内容：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 合并日志看整体执行顺序
|
服务 |
时间 |
日志 |
|
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] |
|
business |
2019-10-11 09:19:56,876 |
开始全局事务，XID = 10.42.1.30:8091:2024332051 |
|
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 >= ? |
|
storage |
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) |
|
storage |
2019-10-11 09:19:57,677 |
[DubboServerHandler-10.10.10.130:20882-thread-4] DEBUG c.n.s.d.T.decreaseStorage - <== Updates: 1 |
|
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] |
|
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 > ? |
|
account |
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) |
|
account |
2019-10-11 09:19:58,852 |
[DubboServerHandler-10.10.10.130:20880-thread-6] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 1 |
|
account |
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 > ? |
|
account |
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) |
|
account |
2019-10-11 09:19:58,990 |
[DubboServerHandler-10.10.10.130:20880-thread-7] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 0 |
|
account |
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 |
|
order |
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 |
|
account |
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 |
|
account |
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 |
|
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 |
|
account |
2019-10-11 09:19:59,155 |
[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - Branch Rollbacked result: PhaseTwo_Rollbacked |
|
storage |
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 |
|
storage |
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 |
|
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 |
|
storage |
2019-10-11 09:19:59,487 |
[rpcDispatch_RMROLE_3_8] INFO i.s.r.AbstractRMHandler - Branch Rollbacked result: PhaseTwo_Rollbacked |
|
business |
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 |
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×tamp=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×tamp=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×tamp=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®ister=true&release=2.7.1&retries=0&revision=1.0&side=provider&timeout=10000×tamp=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×tamp=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×tamp=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®ister=true®ister.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×tamp=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 合并日志看整体执行顺序
|
服务 |
时间 |
日志 |
|
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] |
|
business |
2019-10-11 09:47:36,456 |
开始全局事务，XID = 10.42.1.30:8091:2024332392 |
|
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 >= ? |
|
storage |
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) |
|
storage |
2019-10-11 09:47:36,462 |
[DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - <== Updates: 1 |
|
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 > ? |
|
account |
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) |
|
account |
2019-10-11 09:47:36,490 |
[DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 1 |
|
account |
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 > ? |
|
account |
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) |
|
account |
2019-10-11 09:47:36,517 |
[DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - <== Updates: 1 |
|
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 |
|
order |
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×tamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130 |
|
order |
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×tamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130 |
|
order |
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×tamp=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®ister=true&release=2.7.1&retries=0&revision=1.0&side=provider&timeout=10000×tamp=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×tamp=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×tamp=1570758456541&version=1.0], dubbo version: 2.7.1, current host: 10.10.10.130 |
|
order |
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 |
|
order |
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 |
|
order |
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®ister=true®ister.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×tamp=1570758456541&version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130 |
|
order |
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 |
|
order |
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( ?,?,?,?,?,? ) |
|
order |
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) |
|
order |
2019-10-11 09:47:36,946 |
[DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - <== Updates: 1 |
|
order |
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] |
|
order |
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] |
|
business |
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 |
|
storage |
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 |
|
storage |
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 |
|
storage |
2019-10-11 09:47:37,303 |
[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed |
|
account |
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 |
|
account |
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 |
|
account |
2019-10-11 09:47:37,311 |
[rpcDispatch_RMROLE_5_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed |
|
account |
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 |
|
account |
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 |
|
account |
2019-10-11 09:47:37,318 |
[rpcDispatch_RMROLE_6_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed |
|
order |
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 |
|
order |
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 |
|
order |
2019-10-11 09:47:37,329 |
[rpcDispatch_RMROLE_1_8] INFO i.s.r.AbstractRMHandler - Branch commit result: PhaseTwo_Committed |
