客户端数据没有进行回滚 #2

juneryo · 2017-11-20T10:36:40Z

参考spring cloud的demo做了一下测试，服务端异常后，客户端没有进行回滚。。。
服务端和客户端的service代码都比较简单。

服务端的service：

    @Override
    @Transactional(rollbackFor = Exception.class)
    public Server addOne(Server entity) {
        Server one = null;
        if (entity.getStatus() == 0) {
            one = dao.addOne(entity);
        } else {
            // throw new RuntimeException("status should be 0");
            entity.setVersion("12345678901234567890");  // 字段超长
            one = dao.addOne(entity);
        }
        return one;
    }

客户端的service：

    @Override
    @TxTransaction
    @Transactional(rollbackFor = Exception.class)
    public Client addOne(Client entity) {
        Client one = dao.addOne(entity);
        Map<String, String> map = new HashMap<String, String>();
        map.put("name", one.getName() + "-server");
        map.put("version", one.getVersion());
        map.put("status", one.getStatus().toString());
        // 这里调用服务
        serverConsumer.addOne(map);
        return one;
    }

客户端的Feign：

// LcnTxConfiguration的内容和demo一样，除了名字
@FeignClient(name = "sample-cloud-server", configuration = LcnTxConfiguration.class, fallback = ServerConsumerFallback.class)
public interface ServerConsumer {
    @PostMapping("/server")
    String addOne(Map<String, String> map);
}

主要不同的地方在于：

服务端和客户端都有一个全局异常处理 (后来注释掉之后进入了fallback，但客户端数据仍未回滚)：

@ControllerAdvice
public class GlobalExceptionHandler {
    @ExceptionHandler(value = Exception.class)
    @ResponseBody
    public CommonInfo<String> jsonErrorHandler(HttpServletRequest req, Exception e) throws Exception {
        StringBuilder sb = new StringBuilder();
        sb.append("request.exception").append(" ").append(req.getRequestURL().toString());
        return CommonInfo.fail(new String(sb), e.getMessage());
    }
}

数据源是采用Processor处理的：

@Component
public class LcnTxDataSourceProxyProcessor implements BeanPostProcessor {
    final private static Logger logger = LoggerFactory.getLogger(LcnTxDataSourceProxyProcessor.class);
    final private static String DATA_SOURCE = "dataSource";
    @Override
    public Object postProcessBeforeInitialization(Object bean, String beanName) throws BeansException {
        if (DATA_SOURCE.equals(beanName)) {
            // 这里在启动时候已经打印了
            logger.info("Use lcn data source proxy override data source");
            LCNTransactionDataSource dataSourceProxy = new LCNTransactionDataSource();
            dataSourceProxy.setDataSource((DataSource) bean);
            dataSourceProxy.setMaxCount(10);
            return dataSourceProxy;
        } else {
            return bean;
        }
    }
    @Override
    public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
        return bean;
    }
}

拦截器的切入点用的通配符：

@Aspect
@Component
public class LcnTxTransactionInterceptor implements Ordered {
    @Autowired
    private TxManagerInterceptor txManagerInterceptor;
    @Override
    public int getOrder() {  return 1;  }
    // 这里service前用了 *
    @Around("execution(* com.xxx.boot.*.service.impl.*Impl.*(..))")
    public Object around(ProceedingJoinPoint point) throws Throwable {
        return txManagerInterceptor.around(point);
    }
}

请问问题有可能出现在哪里呢？

The text was updated successfully, but these errors were encountered:

xlorne · 2017-11-20T10:46:00Z

你主要观察一下参与模块的日志信息，看一下参与模块有没有参与到事务中。正常会看到tx-running-start end 的日志打印。再就是提交或者回滚的日志打印消息

juneryo · 2017-11-20T10:51:36Z

@1991wangliang 看了下客户端日志，start 和 end 是有的，但是没有回滚相关的信息。

2017-11-20 18:20:04,941:INFO 56:http-nio-7071-exec-1(5) TxStartTransactionServerImpl.java:36 - tx-start
2017-11-20 18:20:04,945:INFO 83:pool-4-thread-2(5) SocketManager.java:84 - send-msg->{"a":"cg","k":"tMZ9NGnl","p":{}}
2017-11-20 18:20:04,947:INFO 40:nioEventLoopGroup-2-1(10) TransactionHandler.java:51 - 接受->{"d":"{\"st\":1511173204945,\"s\":0,\"nt\":1511173204946,\"g\":\"VIvaGzTf\",\"i\":0,\"o\":0}","k":"tMZ9NGnl"}
2017-11-20 18:20:04,963:INFO 56:http-nio-7071-exec-1(5) ServiceLogAspect.java:36 - SERVICE START: classMethod=>com.tangdi.boot.sample.service.impl.ClientServiceImpl.addOne, args=>[com.tangdi.boot.sample.entity.Client@e392521[name=test01,version=0.0.1,status=1,createTime=<null>,updateTime=<null>,id=<null>]]
2017-11-20 18:20:06,021:WARN 90:hystrix-sample-cloud-server-1(5) ServerConsumerFallback.java:20 - [post] consumer /server fallback
2017-11-20 18:20:06,054:INFO 56:http-nio-7071-exec-1(5) ServiceLogAspect.java:41 - SERVICE END: spendTime=>1105ms, return=>com.tangdi.boot.sample.entity.Client@e392521[name=test01,version=0.0.1,status=1,createTime=20171120182005,updateTime=<null>,id=8]
2017-11-20 18:20:06,070:INFO 92:pool-4-thread-3(5) SocketManager.java:84 - send-msg->{"a":"ctg","k":"wMHBuV7C","p":{"s":1,"g":"VIvaGzTf"}}
2017-11-20 18:20:06,072:INFO 40:nioEventLoopGroup-2-1(10) TransactionHandler.java:51 - 接受->{"d":"1","k":"wMHBuV7C"}
2017-11-20 18:20:06,106:INFO 56:http-nio-7071-exec-1(5) TxStartTransactionServerImpl.java:81 - tx-end-VIvaGzTf>1

倒是服务端没有 start end 这些信息。

xlorne · 2017-11-20T13:59:46Z

tx-start、tx-end 是客户端（启动方）的日志，tx-running-start/tx-running-end 是服务（参与方）的日志，你的参与方没有这样的日志那么首先怀疑你的参与方没有配置好，可能与你的配置有关系。再就是你的发起方既然有日志了但是没有回滚，是由于你客户端发起并没有出现异常，你只是走了fallback而已。（LCN本身不会创建事务的，只是会协调事务）

xlorne · 2017-11-20T14:03:13Z

{"a":"ctg","k":"wMHBuV7C","p":{"s":1,"g":"VIvaGzTf"}} 协议文档有介绍，其中s标示的事务模块正常执行。非异常状态，这也是不会回滚事务的

juneryo · 2017-11-21T03:11:19Z

@1991wangliang
话说启动方和参与方，在配置文件上，应该没区别吧。
我对比了一下两方的配置文件，是一样的。
在使用方面，也和demo一样，启动方的service加上@TxTransaction，但参与方的不需要。
但是参与方的日志里面始终没有出现 tx-running-start/tx-running-end 这样的日志。。。

xlorne · 2017-11-21T03:53:02Z

那说明应该是你在发起方的时候没有将数据传递给参与方模块（groupId），你可以在configuration下的配置requestintercept是否将数据传递出去。可以加断点看一下。怀疑你这里是多线程的方式调用的，threadlocal就拿不到数据了.

juneryo · 2017-11-21T04:13:55Z

@1991wangliang
一提到多线程，突然发现demo中，
只有在feign.hystrix.enabled=true的情况下，才有调整hystrix的策略：
hystrix.command.default.execution.isolation.strategy= SEMAPHORE

修改之后，果然参与方出现了相关日志。。。

2017-11-21 12:00:58,846:INFO 56:http-nio-7070-exec-3(5) TxRunningTransactionServerImpl.java:44 - tx-running-start->p4k8h93u
2017-11-21 12:00:58,848:INFO 56:http-nio-7070-exec-3(5) ServiceLogAspect.java:36 - SERVICE START: classMethod=>com.tangdi.boot.sample.service.impl.ServerServiceImpl.addOne, args=>[com.tangdi.boot.sample.entity.Server@374ac92c[name=test01-server,version=0.0.1,status=1,createTime=<null>,updateTime=<null>,id=<null>]]
2017-11-21 12:00:58,849:INFO 56:http-nio-7070-exec-3(5) LCNDBConnection.java:60 - task-create-> datasource_fx1lQvI4
2017-11-21 12:00:58,850:INFO 56:http-nio-7070-exec-3(5) LCNTransactionDataSource.java:38 - get new connection ->p4k8h93u
2017-11-21 12:00:58,851:INFO 56:http-nio-7070-exec-3(5) LCNDBConnection.java:103 - rollback
2017-11-21 12:00:58,858:INFO 56:http-nio-7070-exec-3(5) LCNDBConnection.java:128 - close-state->0,p4k8h93u
2017-11-21 12:00:58,860:INFO 56:http-nio-7070-exec-3(5) LCNDBConnection.java:113 - close-connection->p4k8h93u
2017-11-21 12:00:58,861:INFO 56:http-nio-7070-exec-3(5) LCNDBConnection.java:139 - rollback->p4k8h93u
2017-11-21 12:00:58,861:INFO 56:http-nio-7070-exec-3(5) TxRunningTransactionServerImpl.java:100 - tx-running-end->p4k8h93u,time->14

但是发起方仍未做回滚。。。

2017-11-21 12:00:58,830:INFO 58:http-nio-7071-exec-3(5) TxStartTransactionServerImpl.java:36 - tx-start
2017-11-21 12:00:58,831:INFO 102:pool-4-thread-4(5) SocketManager.java:84 - send-msg->{"a":"cg","k":"pWo9HVuq","p":{}}
2017-11-21 12:00:58,833:INFO 40:nioEventLoopGroup-2-1(10) TransactionHandler.java:51 - 接受->{"d":"{\"st\":1511236858832,\"s\":0,\"nt\":1511236858832,\"g\":\"p4k8h93u\",\"i\":0,\"o\":0}","k":"pWo9HVuq"}
2017-11-21 12:00:58,834:INFO 58:http-nio-7071-exec-3(5) ServiceLogAspect.java:36 - SERVICE START: classMethod=>com.tangdi.boot.sample.service.impl.ClientServiceImpl.addOne, args=>[com.tangdi.boot.sample.entity.Client@44810af7[name=test01,version=0.0.1,status=1,createTime=<null>,updateTime=<null>,id=<null>]]
Hibernate: insert into CLIENT (CREATE_TIME, UPDATE_TIME, STATUS, NAME, VERSION) values (?, ?, ?, ?, ?)
2017-11-21 12:00:58,879:INFO 58:http-nio-7071-exec-3(5) ServiceLogAspect.java:41 - SERVICE END: spendTime=>45ms, return=>com.tangdi.boot.sample.entity.Client@44810af7[name=test01,version=0.0.1,status=1,createTime=20171121120058,updateTime=<null>,id=10]
2017-11-21 12:00:58,880:INFO 107:pool-4-thread-5(5) SocketManager.java:84 - send-msg->{"a":"ctg","k":"8zm3LLvj","p":{"s":1,"g":"p4k8h93u"}}
2017-11-21 12:00:58,882:INFO 40:nioEventLoopGroup-2-1(10) TransactionHandler.java:51 - 接受->{"d":"1","k":"8zm3LLvj"}
2017-11-21 12:00:58,886:INFO 58:http-nio-7071-exec-3(5) TxStartTransactionServerImpl.java:81 - tx-end-p4k8h93u>1

也就是说，发起方必须手动抛出异常，才能引发回滚操作，而不是tx-manager通过消息通知触发？

xlorne · 2017-11-21T06:20:03Z

是的，只有触发异常才会执行回滚的。

juneryo · 2017-11-21T06:25:43Z

@1991wangliang 原来如此，了解了，感谢。

juneryo · 2017-11-21T08:32:22Z

@1991wangliang 再咨询一个问题。。。
~~发起方调用的某个方法如果抛出RuntimeException，为啥不会触发参与方的事物回滚。。。~~
~~而直接在在service方法中抛出则没问题。~~

    @Override
    @TxTransaction
    @Transactional(rollbackFor = Exception.class)
    public Client addOne(Client entity) {
        Map<String, String> map = new HashMap<>(3);
        map.put("name", entity.getName() + "-server");
        map.put("version", entity.getVersion());
        map.put("status", entity.getStatus().toString());
        String result = serverConsumer.addOne(map);

        // 这个方法抛出 RuntimeException 不会触发参与方回滚
        parseConsumerResult(result, true);

        // 这里可以成功触发参与方回滚
        // lcn tx starter should throw exception to make service provider rollback
        if (entity.getStatus() == 1) {
            throw new RuntimeException("status should be 0");
        }

        return super.addOne(entity);
    }

更新一下，上面的描述不对，
应该是参与方调用超时(参与方再保存数据之后，sleep了5秒钟)，发起方进入_fallback_之后
parseConsumerResult这个方法解析了_fallback_的返回值，抛出RuntimeException
这个情况下无法触发参与方的回滚。。。

xlorne · 2017-11-21T08:59:27Z

看一下tx-start的打印日志

juneryo · 2017-11-21T09:07:43Z

@1991wangliang 刚才更新了一下描述。。。

更新一下，上面的描述不对，
应该是参与方调用超时(参与方再保存数据之后，sleep了5秒钟)，发起方进入fallback之后
parseConsumerResult这个方法解析了fallback的返回值，抛出RuntimeException
这个情况下无法触发参与方的回滚。。。

日志方面的话：

发起方：

2017-11-21 17:05:39,426:INFO 57:http-nio-7071-exec-2(5) TxStartTransactionServerImpl.java:36 - tx-start
2017-11-21 17:05:39,429:INFO 97:pool-4-thread-4(5) SocketManager.java:84 - send-msg->{"a":"cg","k":"Z04sl2YI","p":{}}
2017-11-21 17:05:39,431:INFO 40:nioEventLoopGroup-2-1(10) TransactionHandler.java:51 - 接受->{"d":"{\"st\":1511255139430,\"s\":0,\"nt\":1511255139430,\"g\":\"Lkl1ZPMZ\",\"i\":0,\"o\":0}","k":"Z04sl2YI"}
2017-11-21 17:05:39,435:INFO 57:http-nio-7071-exec-2(5) ServiceLogAspect.java:36 - SERVICE START: classMethod=>com.tangdi.boot.sample.service.impl.ClientServiceImpl.addOne, args=>[com.tangdi.boot.sample.entity.Client@79f5a58e[name=test01,version=0.0.1,status=1,createTime=<null>,updateTime=<null>,id=<null>]]
2017-11-21 17:05:44,438:WARN 88:HystrixTimer-1(5) ConsumerHelper.java:25 - [POST /server] fallback
2017-11-21 17:05:44,441:INFO 57:http-nio-7071-exec-2(5) ConsumerHelper.java:41 - Call consumer result: {"code":201,"message":"[POST /server] Service fallback"}
2017-11-21 17:05:44,496:INFO 101:pool-4-thread-5(5) SocketManager.java:84 - send-msg->{"a":"ctg","k":"YrofVsoI","p":{"s":0,"g":"Lkl1ZPMZ"}}
2017-11-21 17:05:44,500:INFO 40:nioEventLoopGroup-2-1(10) TransactionHandler.java:51 - 接受->{"d":"0","k":"YrofVsoI"}
2017-11-21 17:05:44,506:INFO 57:http-nio-7071-exec-2(5) TxStartTransactionServerImpl.java:81 - tx-end-Lkl1ZPMZ>0
2017-11-21 17:05:44,508:ERROR 57:http-nio-7071-exec-2(5) GlobalExceptionHandler.java:28 - [POST /server] Service fallback
 java.lang.RuntimeException: [POST /server] Service fallback
	at com.tangdi.boot.common.helper.ConsumerHelper.parseConsumerResult(ConsumerHelper.java:49) ~[classes/:?]
	at com.tangdi.boot.sample.service.impl.ClientServiceImpl.addOne(ClientServiceImpl.java:44) ~[classes/:?]

参与方：

2017-11-21 17:05:39,442:INFO 55:http-nio-7070-exec-2(5) TxRunningTransactionServerImpl.java:44 - tx-running-start->Lkl1ZPMZ
2017-11-21 17:05:39,443:INFO 55:http-nio-7070-exec-2(5) ServiceLogAspect.java:36 - SERVICE START: classMethod=>com.tangdi.boot.sample.service.impl.ServerServiceImpl.addOne, args=>[com.tangdi.boot.sample.entity.Server@5c1cc194[name=test01-server,version=0.0.1,status=1,createTime=<null>,updateTime=<null>,id=<null>]]
Hibernate: insert into SERVER (CREATE_TIME, UPDATE_TIME, STATUS, NAME, VERSION) values (?, ?, ?, ?, ?)
2017-11-21 17:05:44,461:INFO 55:http-nio-7070-exec-2(5) ServiceLogAspect.java:41 - SERVICE END: spendTime=>5019ms, return=>com.tangdi.boot.sample.entity.Server@5c1cc194[name=test01-server,version=0.0.1,status=1,createTime=20171121170539,updateTime=<null>,id=9]
2017-11-21 17:05:44,463:INFO 55:http-nio-7070-exec-2(5) TxRunningTransactionServerImpl.java:100 - tx-running-end->Lkl1ZPMZ,time->5020

xlorne · 2017-11-21T09:13:08Z

参与方模块应该会有提交或者回滚的指令数据吧？你现在tx-start状态确实是回滚的状态。

juneryo · 2017-11-21T09:36:57Z

@1991wangliang
Orz。。。实在不好意思。。。
刚才在修改参与方service的时候，发现忘记添加@Transactional了。。。
现在应该可以了，日志里提示 事务模块网络异常回滚
非常感谢。。。

xlorne · 2017-11-21T09:42:34Z

ok 好的

pull

update

#501

update code

xlorne closed this as completed Nov 21, 2017

xlorne pushed a commit that referenced this issue Jul 10, 2020

Merge pull request #2 from codingapi/dev6.0

98188b0

pull

xlorne added a commit that referenced this issue Aug 3, 2020

Merge pull request #2 from codingapi/dev6.0

08b8817

update

xlorne pushed a commit that referenced this issue Aug 11, 2020

Merge pull request #2 from codingapi/dev6.0

ac33449

#501

xlorne pushed a commit that referenced this issue Aug 24, 2020

Merge pull request #2 from codingapi/dev6.0

59c286a

update code

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

客户端数据没有进行回滚 #2

客户端数据没有进行回滚 #2

juneryo commented Nov 20, 2017

xlorne commented Nov 20, 2017

juneryo commented Nov 20, 2017 •

edited

xlorne commented Nov 20, 2017

xlorne commented Nov 20, 2017

juneryo commented Nov 21, 2017

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017 •

edited

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017

juneryo commented Nov 21, 2017 •

edited

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017 •

edited

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017

xlorne commented Nov 21, 2017

客户端数据没有进行回滚 #2

客户端数据没有进行回滚 #2

Comments

juneryo commented Nov 20, 2017

xlorne commented Nov 20, 2017

juneryo commented Nov 20, 2017 • edited

xlorne commented Nov 20, 2017

xlorne commented Nov 20, 2017

juneryo commented Nov 21, 2017

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017 • edited

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017

juneryo commented Nov 21, 2017 • edited

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017 • edited

xlorne commented Nov 21, 2017

juneryo commented Nov 21, 2017

xlorne commented Nov 21, 2017

juneryo commented Nov 20, 2017 •

edited

juneryo commented Nov 21, 2017 •

edited

juneryo commented Nov 21, 2017 •

edited

juneryo commented Nov 21, 2017 •

edited