Seata 分布式事务功能测试（二）

今天药忘吃喽~ 2023-06-06 10:49 35阅读 0赞

> 前置内容：[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 ##

> 结果：由于 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 合并日志看整体执行顺序 ###

## 2. 测试用例 2 ##

> 结果：分两次各扣款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 合并日志看整体执行顺序 ###

<table> 
 <thead> 
  <tr> 
   <th align="left">服务</th> 
   <th align="left">时间</th> 
   <th align="left">日志</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td align="left">business</td> 
   <td align="left">2019-10-11 09:47:36,456</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20883-thread-26] INFO i.s.t.a.DefaultGlobalTransaction - Begin new global transaction [10.42.1.30:8091:2024332392]</td> 
  </tr> 
  <tr> 
   <td align="left">business</td> 
   <td align="left">2019-10-11 09:47:36,456</td> 
   <td align="left">开始全局事务，XID = 10.42.1.30:8091:2024332392</td> 
  </tr> 
  <tr> 
   <td align="left">storage</td> 
   <td align="left">2019-10-11 09:47:36,458</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - ==&gt; Preparing: update t_storage set count = count-500 where commodity_code = ? and count &gt;= ?</td> 
  </tr> 
  <tr> 
   <td align="left">storage</td> 
   <td align="left">2019-10-11 09:47:36,459</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - ==&gt; Parameters: C201901140001(String), 500(Integer)</td> 
  </tr> 
  <tr> 
   <td align="left">storage</td> 
   <td align="left">2019-10-11 09:47:36,462</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20882-thread-12] DEBUG c.n.s.d.T.decreaseStorage - &lt;== Updates: 1</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:36,486</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - ==&gt; Preparing: update t_account set amount = amount-1500.0 where user_id = ? and amount &gt; ?</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:36,486</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - ==&gt; Parameters: 1(String), 1500.0(Double)</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:36,490</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20880-thread-10] DEBUG c.n.a.d.T.decreaseAccount - &lt;== Updates: 1</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:36,513</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - ==&gt; Preparing: update t_account set amount = amount-1500.0 where user_id = ? and amount &gt; ?</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:36,514</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - ==&gt; Parameters: 1(String), 1500.0(Double)</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:36,517</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20880-thread-11] DEBUG c.n.a.d.T.decreaseAccount - &lt;== Updates: 1</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,556</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,557</td> 
   <td align="left">[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&amp;category=consumers&amp;check=false&amp;default.check=false&amp;default.lazy=false&amp;default.sticky=false&amp;dubbo=2.0.2&amp;interface=com.robert.vesta.service.intf.IdService&amp;lazy=false&amp;methods=genId,makeId,transTime,gentIds,expId&amp;pid=7380&amp;release=2.7.1&amp;revision=0.0.3&amp;side=consumer&amp;sticky=false&amp;timestamp=1570758456541&amp;version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,561</td> 
   <td align="left">[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&amp;category=providers,configurators,routers&amp;default.check=false&amp;default.lazy=false&amp;default.sticky=false&amp;dubbo=2.0.2&amp;interface=com.robert.vesta.service.intf.IdService&amp;lazy=false&amp;methods=genId,makeId,transTime,gentIds,expId&amp;pid=7380&amp;release=2.7.1&amp;revision=0.0.3&amp;side=consumer&amp;sticky=false&amp;timestamp=1570758456541&amp;version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,564</td> 
   <td align="left">[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&amp;category=providers,configurators,routers&amp;default.check=false&amp;default.lazy=false&amp;default.sticky=false&amp;dubbo=2.0.2&amp;interface=com.robert.vesta.service.intf.IdService&amp;lazy=false&amp;methods=genId,makeId,transTime,gentIds,expId&amp;pid=7380&amp;release=2.7.1&amp;revision=0.0.3&amp;side=consumer&amp;sticky=false&amp;timestamp=1570758456541&amp;version=1.0, urls: [dubbo://10.42.0.139:20880/com.robert.vesta.service.intf.IdService?anyhost=true&amp;application=vesta-server&amp;bean.name=com.robert.vesta.service.intf.IdService&amp;default.deprecated=false&amp;default.dynamic=false&amp;default.register=true&amp;deprecated=false&amp;dubbo=2.0.2&amp;dynamic=true&amp;generic=false&amp;interface=com.robert.vesta.service.intf.IdService&amp;methods=genId,makeId,transTime,gentIds,expId&amp;pid=1&amp;register=true&amp;release=2.7.1&amp;retries=0&amp;revision=1.0&amp;side=provider&amp;timeout=10000&amp;timestamp=1569826292874&amp;version=1.0, empty://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&amp;category=configurators&amp;default.check=false&amp;default.lazy=false&amp;default.sticky=false&amp;dubbo=2.0.2&amp;interface=com.robert.vesta.service.intf.IdService&amp;lazy=false&amp;methods=genId,makeId,transTime,gentIds,expId&amp;pid=7380&amp;release=2.7.1&amp;revision=0.0.3&amp;side=consumer&amp;sticky=false&amp;timestamp=1570758456541&amp;version=1.0, empty://10.10.10.130/com.robert.vesta.service.intf.IdService?application=order-server&amp;category=routers&amp;default.check=false&amp;default.lazy=false&amp;default.sticky=false&amp;dubbo=2.0.2&amp;interface=com.robert.vesta.service.intf.IdService&amp;lazy=false&amp;methods=genId,makeId,transTime,gentIds,expId&amp;pid=7380&amp;release=2.7.1&amp;revision=0.0.3&amp;side=consumer&amp;sticky=false&amp;timestamp=1570758456541&amp;version=1.0], dubbo version: 2.7.1, current host: 10.10.10.130</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,567</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,567</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,568</td> 
   <td align="left">[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&amp;application=order-server&amp;bean.name=com.robert.vesta.service.intf.IdService&amp;check=false&amp;default.check=false&amp;default.deprecated=false&amp;default.dynamic=false&amp;default.lazy=false&amp;default.register=true&amp;default.sticky=false&amp;deprecated=false&amp;dubbo=2.0.2&amp;dynamic=true&amp;generic=false&amp;interface=com.robert.vesta.service.intf.IdService&amp;lazy=false&amp;methods=genId,makeId,transTime,gentIds,expId&amp;pid=7380&amp;register=true&amp;register.ip=10.10.10.130&amp;release=2.7.1&amp;remote.application=vesta-server&amp;remote.timestamp=1569826292874&amp;retries=0&amp;revision=0.0.3&amp;side=consumer&amp;sticky=false&amp;timeout=10000&amp;timestamp=1570758456541&amp;version=1.0, dubbo version: 2.7.1, current host: 10.10.10.130</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,569</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,850</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - ==&gt; Preparing: INSERT INTO t_order ( id,order_no,user_id,commodity_code,count,amount ) VALUES( ?,?,?,?,?,? )</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,868</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - ==&gt; Parameters: 1314752779943674870(Long), 8fc1c283b7de4199b8d6d0fb35c7c8aa(String), 1(String), C201901140001(String), 500(Integer), 3000.0(Double)</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,946</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20881-thread-9] DEBUG c.n.o.d.T.insert - &lt;== Updates: 1</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:36,952</td> 
   <td align="left">[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]</td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:37,044</td> 
   <td align="left">[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]</td> 
  </tr> 
  <tr> 
   <td align="left">business</td> 
   <td align="left">2019-10-11 09:47:37,123</td> 
   <td align="left">[DubboServerHandler-10.10.10.130:20883-thread-26] INFO i.s.t.a.DefaultGlobalTransaction - [10.42.1.30:8091:2024332392] commit status:Committed</td> 
  </tr> 
  <tr> 
   <td align="left">storage</td> 
   <td align="left">2019-10-11 09:47:37,303</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>storage</strong></td> 
   <td align="left">2019-10-11 09:47:37,303</td> 
   <td align="left">[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - <strong>Branch committing</strong>: 10.42.1.30:8091:2024332392 2024332394 jdbc:mysql://10.10.10.233:3306/seata_demo_storage null</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>storage</strong></td> 
   <td align="left">2019-10-11 09:47:37,303</td> 
   <td align="left">[rpcDispatch_RMROLE_2_8] INFO i.s.r.AbstractRMHandler - <strong>Branch commit result</strong>: PhaseTwo_Committed</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:37,309</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>account</strong></td> 
   <td align="left">2019-10-11 09:47:37,310</td> 
   <td align="left">[rpcDispatch_RMROLE_5_8] INFO i.s.r.AbstractRMHandler - <strong>Branch committing</strong>: 10.42.1.30:8091:2024332392 2024332397 jdbc:mysql://10.10.10.233:3306/seata_demo_account null</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>account</strong></td> 
   <td align="left">2019-10-11 09:47:37,311</td> 
   <td align="left">[rpcDispatch_RMROLE_5_8] INFO i.s.r.AbstractRMHandler - <strong>Branch commit result</strong>: PhaseTwo_Committed</td> 
  </tr> 
  <tr> 
   <td align="left">account</td> 
   <td align="left">2019-10-11 09:47:37,318</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>account</strong></td> 
   <td align="left">2019-10-11 09:47:37,318</td> 
   <td align="left">[rpcDispatch_RMROLE_6_8] INFO i.s.r.AbstractRMHandler - <strong>Branch committing</strong>: 10.42.1.30:8091:2024332392 2024332400 jdbc:mysql://10.10.10.233:3306/seata_demo_account null</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>account</strong></td> 
   <td align="left">2019-10-11 09:47:37,318</td> 
   <td align="left">[rpcDispatch_RMROLE_6_8] INFO i.s.r.AbstractRMHandler - <strong>Branch commit result: PhaseTwo_Committed</strong></td> 
  </tr> 
  <tr> 
   <td align="left">order</td> 
   <td align="left">2019-10-11 09:47:37,326</td> 
   <td align="left">[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</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>order</strong></td> 
   <td align="left">2019-10-11 09:47:37,328</td> 
   <td align="left">[rpcDispatch_RMROLE_1_8] INFO i.s.r.AbstractRMHandler - <strong>Branch committing</strong>: 10.42.1.30:8091:2024332392 2024332403 jdbc:mysql://10.10.10.233:3306/seata_demo_order null</td> 
  </tr> 
  <tr> 
   <td align="left"><strong>order</strong></td> 
   <td align="left">2019-10-11 09:47:37,329</td> 
   <td align="left">[rpcDispatch_RMROLE_1_8] INFO i.s.r.AbstractRMHandler - <strong>Branch commit result: PhaseTwo_Committed</strong></td> 
  </tr> 
 </tbody> 
</table>

[Seata]: https://blog.csdn.net/isea533/article/details/102497681