search

apache / incubator-seata-samples

Apache Seata(incubating) Samples for Java
https://seata.apache.org/
Apache License 2.0
2.27k stars 1.91k forks source link

关于dubbo示例执行中发现没有回滚，同时发现undo_log没有数据添加删除的问题及解决 #197

Open givking opened 5 years ago

givking commented 5 years ago

此错误是我在dubbo那个demo下测试出来的，其他的没有使用过，此测试seata版本为0.7.1 之前按照下载的demo进行测试，发现抛异常后，事务并没有回滚，后续通过源码调试发现可能是demo中少加入了一个包导致undo数据并没有存入undo_log表中，解决方法是添加以下包：

com.fasterxml.jackson.core jackson-databind 2.8.6

加入之后再执行，如果事务执行成功，则undo_log会保存信息进去（数据过会会自动删除）,如果事务回滚，则事务表及undo_log表均不会有数据变化

givking commented 5 years ago

补充错误信息： 1.在没有databind这个包的时候： 1 此时运行accountservice并且注册成功（其他的几个非事务service也一样） image 执行有抛异常的事务 image 开始启动全局事务回滚，但实际回滚无法成功，一直处于RollbackRetrying image 此时查看acountservice控制台发现以下警告信息 image 通过源码调试发现实际就是缺少警告信息中的方法com/fasterxml/jackson/databind/ObjectMapper 后续通过加入databind解决此问题。

favccxx commented 5 years ago

我加上上面说的jar，undo_log还是没有日志，不知道怎么回事。 Service能够连接上seata Server 2019-08-23 17:22:40.043 INFO 17980 --- [imeoutChecker_1] i.s.core.rpc.netty.NettyPoolableFactory : NettyPool create channel to transactionRole:TMROLE,address:127.0.0.1:8091,msg:< RegisterTMRequest{applicationId='dubbo-user', transactionServiceGroup='my_group'} > 2019-08-23 17:22:40.052 INFO 17980 --- [imeoutChecker_1] i.s.core.rpc.netty.NettyPoolableFactory : register success, cost 5 ms, version:0.8.0,role:TMROLE,channel:[id: 0x7a81a706, L:/127.0.0.1:56633 - R:/127.0.0.1:8091]

givking commented 5 years ago

你要执行之后马上看undo_log表，seata会在事务执行成功后把里面的数据给删除了你给我发的日志我只看到注册成功了，具体事务执行是否成功你没有发过来，我看不出来

------------------ 原始邮件 ------------------ 发件人: "穿越来客"notifications@github.com; 发送时间: 2019年8月23日(星期五) 下午5:27 收件人: "seata/seata-samples"seata-samples@noreply.github.com; 抄送: "准大叔"125311899@qq.com; "Author"author@noreply.github.com; 主题: Re: [seata/seata-samples] 关于dubbo示例执行中发现没有回滚，同时发现undo_log没有数据添加删除的问题及解决 (#197)

我加上上面说的jar，undo_log还是没有日志，不知道怎么回事。 Service能够连接上seata Server 2019-08-23 17:22:40.043 INFO 17980 --- [imeoutChecker_1] i.s.core.rpc.netty.NettyPoolableFactory : NettyPool create channel to transactionRole:TMROLE,address:127.0.0.1:8091,msg:< RegisterTMRequest{applicationId='dubbo-user', transactionServiceGroup='my_group'} > 2019-08-23 17:22:40.052 INFO 17980 --- [imeoutChecker_1] i.s.core.rpc.netty.NettyPoolableFactory : register success, cost 5 ms, version:0.8.0,role:TMROLE,channel:[id: 0x7a81a706, L:/127.0.0.1:56633 - R:/127.0.0.1:8091]

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or mute the thread.

favccxx commented 5 years ago

业务场景： 用户购物业务，需要从A服务减库存，B服务刷新用户的账户。 所有的服务启动均成功，而且连接到seata事务。

测试场景： 调用RestAPI， 在B服务后添加断点. Rest服务超时关闭，undo_log中没有日志。 继续执行断点服务，B服务运行成功，用户账户更新，但是库存没有更新。导致全局事务没有起作用。

web服务日志： `2019-08-28 09:28:11.472  INFO 14368 --- [nio-7778-exec-4] i.seata.tm.api.DefaultGlobalTransaction  : Begin new global transaction [192.168.72.1:8091:2020279695] 2019-08-28 09:28:11.479  INFO 14368 --- [nio-7778-exec-4] c.f.dubbo.service.ProuctBizServiceImpl  : xid: 192.168.72.1:8091:2020279695 2019-08-28 09:28:15.815  INFO 14368 --- [nio-7778-exec-4] i.seata.tm.api.DefaultGlobalTransaction  : [192.168.72.1:8091:2020279695] rollback status:Rollbacked 2019-08-28 09:28:16.640 ERROR 14368 --- [nio-7778-exec-4] o.a.c.c.C.[.[.[/].[dispatcherServlet]  : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.apache.dubbo.rpc.RpcException: Failed to invoke the method updateUser in the service com.favccxx.dubbo.api.user.UserService. Tried 3 times of the providers [192.168.72.1:20881] (1/1) from the registry 192.168.72.130:2181 on the consumer 192.168.72.1 using the dubbo version 2.7.3. Last error is: Invoke remote method timeout. method: updateUser, provider: dubbo://192.168.72.1:20881/com.favccxx.dubbo.api.user.UserService?anyhost=true&application=dubbo-web&bean.name=ServiceBean:com.favccxx.dubbo.api.user.UserService:1.0.2:UserGroup&check=false&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&group=UserGroup&interface=com.favccxx.dubbo.api.user.UserService&lazy=false&methods=findByUsername,updateUser&pid=14368&qos.enable=false&register=true&register.ip=192.168.72.1&release=2.7.3&remote.application=user-provider&revision=1.0.2&side=consumer&sticky=false&timestamp=1566553015245&version=1.0.2, cause: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-08-28 09:28:14.599, end time: 2019-08-28 09:28:15.607, client elapsed: 1 ms, server elapsed: 1007 ms, timeout: 1000 ms, request: Request [id=13430, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=updateUser, parameterTypes=[class java.lang.String, class java.math.BigDecimal], arguments=[root, 22.3], attachments={path=com.favccxx.dubbo.api.user.UserService, TX_XID=192.168.72.1:8091:2020279695, interface=com.favccxx.dubbo.api.user.UserService, version=1.0.2, group=UserGroup}]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881] with root cause

org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-08-28 09:28:14.599, end time: 2019-08-28 09:28:15.607, client elapsed: 1 ms, server elapsed: 1007 ms, timeout: 1000 ms, request: Request [id=13430, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=updateUser, parameterTypes=[class java.lang.String, class java.math.BigDecimal], arguments=[root, 22.3], attachments={path=com.favccxx.dubbo.api.user.UserService, TX_XID=192.168.72.1:8091:2020279695, interface=com.favccxx.dubbo.api.user.UserService, version=1.0.2, group=UserGroup}]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881 at org.apache.dubbo.remoting.exchange.support.DefaultFuture.doReceived(DefaultFuture.java:189) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.remoting.exchange.support.DefaultFuture.received(DefaultFuture.java:153) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.remoting.exchange.support.DefaultFuture$TimeoutCheckTask.run(DefaultFuture.java:252) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:648) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:727) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.common.timer.HashedWheelTimer$Worker.run(HashedWheelTimer.java:449) ~[dubbo-2.7.3.jar:2.7.3] at java.lang.Thread.run(Unknown Source) [na:1.8.0_111]

2019-08-28 09:29:19.431  WARN 14368 --- [:20881-thread-3] o.a.d.r.exchange.support.DefaultFuture  : [DUBBO] The timeout response finally returned at 2019-08-28 09:29:19.431, response Response [id=13428, version=null, status=20, event=false, error=null, result=AppResponse [value=com.favccxx.dubbo.model.FavUser@1d4fc711, exception=null]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881, dubbo version: 2.7.3, current host: 192.168.72.1 2019-08-28 09:29:19.438  WARN 14368 --- [:20881-thread-3] o.a.d.r.exchange.support.DefaultFuture  : [DUBBO] The timeout response finally returned at 2019-08-28 09:29:19.438, response Response [id=13429, version=null, status=20, event=false, error=null, result=AppResponse [value=com.favccxx.dubbo.model.FavUser@13883ac8, exception=null]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881, dubbo version: 2.7.3, current host: 192.168.72.1 2019-08-28 09:29:19.438  WARN 14368 --- [:20881-thread-4] o.a.d.r.exchange.support.DefaultFuture  : [DUBBO] The timeout response finally returned at 2019-08-28 09:29:19.438, response Response [id=13430, version=null, status=20, event=false, error=null, result=AppResponse [value=com.favccxx.dubbo.model.FavUser@697a92ef, exception=null]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881, dubbo version: 2.7.3, current host: 192.168.72.1 `

givking commented 5 years ago

你的日志里面第五行rollback status:Rollbacked，表明回滚成功了。你要不把代码发我一份，我来看看是哪儿出问题了

------------------ 原始邮件 ------------------ 发件人: "穿越来客"notifications@github.com; 发送时间: 2019年8月28日(星期三) 上午9:44 收件人: "seata/seata-samples"seata-samples@noreply.github.com; 抄送: "准大叔"125311899@qq.com; "Author"author@noreply.github.com; 主题: Re: [seata/seata-samples] 关于dubbo示例执行中发现没有回滚，同时发现undo_log没有数据添加删除的问题及解决 (#197)

业务场景： 用户购物业务，需要从A服务减库存，B服务刷新用户的账户。 所有的服务启动均成功，而且连接到seata事务。

测试场景： 调用RestAPI， 在B服务后添加断点. Rest服务超时关闭，undo_log中没有日志。 继续执行断点服务，B服务运行成功，用户账户更新，但是库存没有更新。导致全局事务没有起作用。

web服务日志： `2019-08-28 09:28:11.472 [0;39m [32m INFO [0;39m [35m14368 [0;39m [2m--- [0;39m [2m[nio-7778-exec-4] [0;39m [36mi.seata.tm.api.DefaultGlobalTransaction [0;39m [2m: [0;39m Begin new global transaction [192.168.72.1:8091:2020279695] [2m2019-08-28 09:28:11.479 [0;39m [32m INFO [0;39m [35m14368 [0;39m [2m--- [0;39m [2m[nio-7778-exec-4] [0;39m [36mc.f.dubbo.service.ProuctBizServiceImpl [0;39m [2m: [0;39m xid: 192.168.72.1:8091:2020279695 [2m2019-08-28 09:28:15.815 [0;39m [32m INFO [0;39m [35m14368 [0;39m [2m--- [0;39m [2m[nio-7778-exec-4] [0;39m [36mi.seata.tm.api.DefaultGlobalTransaction [0;39m [2m: [0;39m [192.168.72.1:8091:2020279695] rollback status:Rollbacked [2m2019-08-28 09:28:16.640 [0;39m [31mERROR [0;39m [35m14368 [0;39m [2m--- [0;39m [2m[nio-7778-exec-4] [0;39m [36mo.a.c.c.C.[.[.[/].[dispatcherServlet] [0;39m [2m: [0;39m Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.apache.dubbo.rpc.RpcException: Failed to invoke the method updateUser in the service com.favccxx.dubbo.api.user.UserService. Tried 3 times of the providers [192.168.72.1:20881] (1/1) from the registry 192.168.72.130:2181 on the consumer 192.168.72.1 using the dubbo version 2.7.3. Last error is: Invoke remote method timeout. method: updateUser, provider: dubbo://192.168.72.1:20881/com.favccxx.dubbo.api.user.UserService?anyhost=true&application=dubbo-web&bean.name=ServiceBean:com.favccxx.dubbo.api.user.UserService:1.0.2:UserGroup&check=false&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&group=UserGroup&interface=com.favccxx.dubbo.api.user.UserService&lazy=false&methods=findByUsername,updateUser&pid=14368&qos.enable=false&register=true&register.ip=192.168.72.1&release=2.7.3&remote.application=user-provider&revision=1.0.2&side=consumer&sticky=false&timestamp=1566553015245&version=1.0.2, cause: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-08-28 09:28:14.599, end time: 2019-08-28 09:28:15.607, client elapsed: 1 ms, server elapsed: 1007 ms, timeout: 1000 ms, request: Request [id=13430, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=updateUser, parameterTypes=[class java.lang.String, class java.math.BigDecimal], arguments=[root, 22.3], attachments={path=com.favccxx.dubbo.api.user.UserService, TX_XID=192.168.72.1:8091:2020279695, interface=com.favccxx.dubbo.api.user.UserService, version=1.0.2, group=UserGroup}]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881] with root cause

org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-08-28 09:28:14.599, end time: 2019-08-28 09:28:15.607, client elapsed: 1 ms, server elapsed: 1007 ms, timeout: 1000 ms, request: Request [id=13430, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=updateUser, parameterTypes=[class java.lang.String, class java.math.BigDecimal], arguments=[root, 22.3], attachments={path=com.favccxx.dubbo.api.user.UserService, TX_XID=192.168.72.1:8091:2020279695, interface=com.favccxx.dubbo.api.user.UserService, version=1.0.2, group=UserGroup}]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881 at org.apache.dubbo.remoting.exchange.support.DefaultFuture.doReceived(DefaultFuture.java:189) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.remoting.exchange.support.DefaultFuture.received(DefaultFuture.java:153) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.remoting.exchange.support.DefaultFuture$TimeoutCheckTask.run(DefaultFuture.java:252) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:648) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:727) ~[dubbo-2.7.3.jar:2.7.3] at org.apache.dubbo.common.timer.HashedWheelTimer$Worker.run(HashedWheelTimer.java:449) ~[dubbo-2.7.3.jar:2.7.3] at java.lang.Thread.run(Unknown Source) [na:1.8.0_111]

[2m2019-08-28 09:29:19.431 [0;39m [33m WARN [0;39m [35m14368 [0;39m [2m--- [0;39m [2m[:20881-thread-3] [0;39m [36mo.a.d.r.exchange.support.DefaultFuture [0;39m [2m: [0;39m [DUBBO] The timeout response finally returned at 2019-08-28 09:29:19.431, response Response [id=13428, version=null, status=20, event=false, error=null, result=AppResponse [value=com.favccxx.dubbo.model.FavUser@1d4fc711, exception=null]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881, dubbo version: 2.7.3, current host: 192.168.72.1 [2m2019-08-28 09:29:19.438 [0;39m [33m WARN [0;39m [35m14368 [0;39m [2m--- [0;39m [2m[:20881-thread-3] [0;39m [36mo.a.d.r.exchange.support.DefaultFuture [0;39m [2m: [0;39m [DUBBO] The timeout response finally returned at 2019-08-28 09:29:19.438, response Response [id=13429, version=null, status=20, event=false, error=null, result=AppResponse [value=com.favccxx.dubbo.model.FavUser@13883ac8, exception=null]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881, dubbo version: 2.7.3, current host: 192.168.72.1 [2m2019-08-28 09:29:19.438 [0;39m [33m WARN [0;39m [35m14368 [0;39m [2m--- [0;39m [2m[:20881-thread-4] [0;39m [36mo.a.d.r.exchange.support.DefaultFuture [0;39m [2m: [0;39m [DUBBO] The timeout response finally returned at 2019-08-28 09:29:19.438, response Response [id=13430, version=null, status=20, event=false, error=null, result=AppResponse [value=com.favccxx.dubbo.model.FavUser@697a92ef, exception=null]], channel: /192.168.72.1:57173 -> /192.168.72.1:20881, dubbo version: 2.7.3, current host: 192.168.72.1 `

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or mute the thread.

favccxx commented 5 years ago

我把代码放到这里了，https://github.com/favccxx/HelloDubbo， 麻烦帮忙看下。 虽然A服务回滚了，但是B服务在断点中断又继续后，仍然执行了，这导致了分布式事务的异常。

givking commented 5 years ago

首先你的项目问题不仅仅有我说的这个问题。 第一个问题： 首先我只是了解springboot，并没有实际使用springboot+dubbo的方式来构建分布式项目，所以不是很明白这种结构的包依赖，不过很明显，你再解决我说的缺少data-bind那个jar包这个问题上是有问题的！ TIM截图20190828155049 上面图可以看到你的这个包实际是有的，但是这也仅限于你的web模块，user和product模块并没有引入这个jar，所以第一步还是加入这个jar包的依赖 image 当然product模块下的pom也需要加入此依赖。 第二个问题： 你的数据源配置是有问题的。 image 由于我没用过mybatisplus,所以不太熟悉你之前注释掉的东西是为什么，默认会读取什么吗？不过按照seata的思路，他使用的是原数据源的代理对象来进行数据库的操作，所以你再注入的时候要进行正确的配置，具体还是参照官方的demo，具体原理可以看看https://mp.weixin.qq.com/s/EzmZ-DAi-hxJhRkFvFhlJQ 这篇文章，我就是从这个文章一步一步调出错误的。 最后是给你修改后的项目：https://github.com/givking/seataTest1

favccxx commented 5 years ago

已经OK了，非常感谢