SpringWebflux中WebClient怎么打印日志

一、背景

去年高峰压测的时候，有个服务是专门调用其它系统的，在测试接口http请求的时候，那TPS唰唰的往下掉，还专门用Arthas看了一下方法执行时间，那家伙，我sleep 2s，看时间都3-4s了，所以就想着后面优化一下。

所以，这不就到我们的主角SpringWebflux了，就想着用服务用Webflux，Http请求直接用WebClient了。但是有一个问题就不得不思考了，怎么记录请求的日志呢？这个日志很重要，必须的记录的清楚，不然不用系统间沟通（扯皮背锅）着实难搞。

二、怎么记录日志？

2.1 思考记录

打印日志，那第一步得去看看官网咯？看看官网提供了什么解决方案

2.1.1 官网寻答案

打开官网，翻到Filter这一页，发现着实有可以记录日志的，我把官网代码粘贴在下图。

WebClient client = WebClient.builder()
        .filter((request, next) -> {
            ClientRequest filtered = ClientRequest.from(request)
                    .header("foo", "bar")
                    .build();

            return next.exchange(filtered);
        })
        .build();

可以看到，我们是可以拿到Request的，这让我一顿高兴，那这操作起来不简单？ 但是呢，凡事不能高兴太早。

拿到这ClientRequest去代码一顿敲(clientRequest.xx)，这个点都被我按烂了，发现并没有可以获取RequestBody的方法，只有Headers，URI... 可惜这都不是我要的啊。没办法，那就只有换别的方法了。

顺便点了一下filter的ExchangeFilterFunction，发现里面有方法还能拿到Rresponse。代码如下：

static ExchangeFilterFunction ofResponseProcessor(Function<ClientResponse, Mono<ClientResponse>> processor) {
  Assert.notNull(processor, "ClientResponse Function must not be null");
  return (request, next) -> next.exchange(request).flatMap(processor);
}

然后拿着Response又来一顿操作，可以拿到Response Body等，但是...但是...如果我们在Response里面把Response Body 使用掉，就会报错:nested exception is java.lang.IllegalStateException: The client response body can only be consumed once。如图所示。

没有办法，查看了ClientResponse实现类org.springframework.web.reactive.function.client.DefaultClientResponse，这个是个包权限的类，虽然很想直接用，比如：requestDescription（URL路径），getBody, 但是是在拿不到啊~~难受

既然如此，那就只有从别的地方寻找。

2.1.2 其它方案

在官网上WebFlux有三种方案，分别是集成Jetty, Netty, HttpComponent5。由于我使用的是HttpComponent5，所以就直接从http这个寻找方案了。

寻寻觅觅，找到了了相似的方案，也可以添加Interceptor。我就直接贴出代码，如下图。

但是在实现时，发现了有两个问题。

问题一

打印Request日志的时候会出现两次。

问题二

打印Response的时候也会出现nested exception is java.lang.IllegalStateException: The client response body can only be consumed once这个异常。

出现这个问题，没有发现啥好用的解决方案。

2.1.3 Google

后来就想着想换成Jetty和Netty，就google了一波，我直接把连接贴出来，就不过多描述了。 连接如下：

Logging Spring WebClient Calls | Baeldung 这个方案也尝试了一波，但是效果如上。会出现问题一，或者在获取Body的时候出现问题。

2.2 解决方案

在经历了好几天Debug和测试后，就选择了妥协方案，直接在webClient请求的时候打印日志。这还算是一个完美的解决方案。

我贴出一部分代码，如下。

    /**
     * 打印全流程日志，需要外部传入参数
     */
    public static Function<ClientResponse, Mono<String>> logging(String url, String method, Object reqBody) {
        return (clientResponse -> clientResponse.bodyToMono(String.class).doOnSuccess(body -> {
            if (log.isDebugEnabled()) {
                log.info("\n" +
                                "TraceId      : {}, {}\n" +
                                "URI          : {}, \n" +
                                "Param        : {}, \n" +
                                "RespHeader   : {}, \n" +
                                "RespStatus   : {}, \n" +
                                "Response     : {}", clientResponse.logPrefix(), method, url, JsonUtils.toJson(reqBody),
                        clientResponse.headers().asHttpHeaders(), clientResponse.rawStatusCode(),
                        StringUtils.abbreviate(body, 4000));
            }
        }));
    }

在获取到Body的时候，直接转化成String.class，如果直接转成ParameterizedTypeReference就会失去部分原请求的数据，这样在扯皮的时候不好找证据呀！（我们打印清晰的日志是为了更好的查询问题，不是扯皮︿(￣︶￣)︿ ）

这样打印出来的日志就是我们想要的了，舒服啊~ 这样看起来才舒服。

还写了一些其它的小工具，获取连接，使用方式如下：

三、总结

以上是探索WebClient的打印日志的方式，还有不足，欢迎大家讨论，提出更好的方式。谢谢！