一、背景
最近在持续改造项目，想通过日志查看用户所有的接口链路日志。在原来基于 SpirngMVC 的时候，那是比较好处理的，通过 ThreadLocal，放入 TraceId，就可以把一个 TraceId 传到各个地方，然后再需要的地方取出来，相当简单。但是在换了 WebFlux，老实说，真还是有些麻烦。但这并不能难倒我们，发车！
现在把使用过程中问题和解决方式列出来，供大家参考。参考原文链接
SpringBoot 版本号：2.6.10
二、 正文
2.1 实现方案
要实现用户调用链路所有的日志，那么我们就得通过唯一的 ID 去追踪。大致可以通过在请求的 header 中携带 token，或者通过 cookie 这样的方式。考虑到大多数的使用场景，我们就使用在 header 中携带 token 的方式来实现。
2.2 实现方式
既然我们采取的是在 header 在添加 token 的方式，那么如何取出来，然后又在打印日志中获取到，这才是关键点。我们在 SpringMVC 中通常采用 AOP 的方式打印日志，那我们在 WebFlux 中是否也可以这样做呢？
2.2.1 步骤 1 - 过滤器
当然可以了。要实现拦截，当然还是先实现 WebFilter，代码如下。
/** * <p>记录traceId</p> * * @author fattycal@qq.com * @since 2022/8/8 */@Slf4j@Configurationpublic class TraceIdWebFilter implements WebFilter {
private static final String TRACE_ID = ConstantsFields.TRACE_ID;
@Override public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) {
return chain.filter(exchange) // 放入当前上下文，类似于ThreadLocal .contextWrite(context -> { // header 中是否有TRACE-ID String traceId = exchange.getRequest().getHeaders().getFirst(TRACE_ID);
traceId = Optional.ofNullable(traceId).orElse(""); if (!StringUtils.hasText(traceId)) { log.warn("TRACE_ID not present in header: {}", exchange.getRequest().getURI()); } Context contextTmp = context.put(TRACE_ID, traceId); exchange.getAttributes().put(TRACE_ID, traceId);
return contextTmp; }); }}
复制代码
实现WebFilter，通过contextWrite方法，把 Header 中的 trace-id 存入到上下文中。这个ContextWrite很重要，它是类似于 ThreadLocal 的东西，如果有老铁不知道，可以参考Context翻译文章，这里我们就不在一一赘述啦。
实现了WebFilter后，并且放入了 Context 中，这样我们是不是想 ThreadLocal 一样，取出来直接用就可以了？of course！
2.2.2 步骤 2 - 切面
直接贴代码，如下（方式一）。
/** * <br>日志切面</br> * * @author fattyca1@qq.com * @since 2022/8/10 */
@Aspect@Configuration@Slf4jpublic class LoggerAspect {
@Around("@annotation(com.fattycal.demo.webflux.annotation.Loggable)") public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable {
long start = System.currentTimeMillis(); Object result = joinPoint.proceed(); if (result instanceof Mono) { Mono monoResult = (Mono) result; AtomicReference<String> traceId = new AtomicReference<>(""); return monoResult.flatMap(ret -> Mono.subscriberContext().map(ctx -> { // 从Context中取出traceId, 放入到了AtomicReference，正常变量没办法操作（内部类）。 traceId.set(ctx.getOrDefault(ConstantsFields.TRACE_ID, "")); return ret; })) .doOnSuccess(o -> { String response = ""; if (Objects.nonNull(o)) { response = o.toString(); } log.info("【{}】,Enter: {}.{}() with argument[s] = {}", traceId, joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(), joinPoint.getArgs()); log.info("【{}】,Exit: {}.{}() had arguments = {}, with result = {}, Execution time = {} ms", traceId, joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(), joinPoint.getArgs()[0], response, (System.currentTimeMillis() - start)); }); }
return result; }}
复制代码
我们直接通过切面，来判断响应结果是否是属于 Mono，如果是，则通过 flatmap 结合Mono.subscriberContext()拿到 traceId，然后在 doOnSuccess 中打印日志。这样的好处是，不用自己订阅Mono.subscriberContext()。
有的哥们就会问，为啥不在doOnSuccess()中去订阅呢？ 好问题，我们的尝试一下。代码如下（方式二）。
@Aspect@Configuration@Slf4jpublic class LoggerAspect {
@Around("@annotation(com.fattycal.demo.webflux.annotation.Loggable)") public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable {
long start = System.currentTimeMillis(); Object result = joinPoint.proceed(); if (result instanceof Mono) { Mono monoResult = (Mono) result; // 错误的实现方式 return monoResult.doOnSuccess(obj -> Mono.subscriberContext() .map(ctx -> { String traceId = ctx.getOrDefault(ConstantsFields.TRACE_ID, ""); String response = ""; if (Objects.nonNull(obj)) { response = obj.toString(); } log.info("【{}】,Enter: {}.{}() with argument[s] = {}", traceId, joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(), joinPoint.getArgs()); log.info("【{}】,Exit: {}.{}() had arguments = {}, with result = {}, Execution time = {} ms", traceId, joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(), joinPoint.getArgs()[0], response, (System.currentTimeMillis() - start)); return ctx; }) );
} return result; }}
复制代码
一激动，马上唰唰写出来了，但是这样写可不可以呢（文章已标记是错误的写法）？为啥说是错误的写法呢，那是因为在 Reactor3 中，有一个至理名言，那就是nothing happens until you subscribe()。我们没有订阅，所以Mono.subscriberContext().map()这一个流不会被执行的（点完餐付完钱才确定要做）。
所以我们稍微动一下代码，如下。
/** * <br>日志切面</br> * * @author fattyca1@qq.com * @since 2022/8/10 */@Aspect@Configuration@Slf4jpublic class LoggerAspect {
@Around("@annotation(com.fattycal.demo.webflux.annotation.Loggable)") public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable {
long start = System.currentTimeMillis(); Object result = joinPoint.proceed(); if (result instanceof Mono) { Mono monoResult = (Mono) result; // 把doOnSuccess这个操作放到单独线程池里做 return monoResult.publishOn(Schedulers.newElastic("fattyca1-thread-pool")).doOnSuccess(obj -> Mono.subscriberContext() .map(ctx -> { String traceId = ctx.getOrDefault(ConstantsFields.TRACE_ID, ""); String response = ""; if (Objects.nonNull(obj)) { response = obj.toString(); } log.info("【{}】,Enter: {}.{}() with argument[s] = {}", traceId, joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(), joinPoint.getArgs()); log.info("【{}】,Exit: {}.{}() had arguments = {}, with result = {}, Execution time = {} ms", traceId, joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(), joinPoint.getArgs()[0], response, (System.currentTimeMillis() - start)); return ctx; }).subscribe() );
} return result; }}
复制代码
我们在 map 方法后面又增加了subscribe()方法，这个时候，付钱了，餐馆才给你做饭。当然，我们又添加了 publishOn 这个方法，那是因为 subscribe()是阻塞的，为了不阻塞，我们放进了一个新的线程池中处理。这样我们就大功告成啦！ 马上动手测试一下
2.2.3 品尝果实
我们直接来一个朴实无华的测试，代码如下。
@RestControllerpublic class WebfluxController {
@RequestMapping("/hi/{name}") @Loggable public Mono<String> helloWorld(@PathVariable("name") String name) { return Mono.fromSupplier(() -> "hi, " + name); }}
复制代码
2.2.3.1 （方式一）
先按照方式一的方式来测试，结果如图所示。
方式一测试
方式一测试出来，的确没问题，我们把 Header 中的 Trace-id 打印出来了。那接下来试试方式二。
2.2.3.2 （方式二）
方式一实现方式测试，结果如图所示。
方式二测试
擦，扑街了~，从测试结果看，这样的方式是取不到 Context 中的值，我在尝试去掉线程池后，也还是取不到 Context 中的值。为什么没有取到这一点，还没研究透，后面研究透了给大家补上。
从结果看，我们还是通过 FlatMap 的方式，提前拿到 Trace-id 还是靠谱一点。
2.2.3.2 测试三
我们修改了一下 Controller 中的代码，通过 flatMap，从 Context 中获取 traceId。再测试一下。结果如图所示。
修改Controller
通过测试我们发下，通过 flatmap，然后再从 Context 中获取 traceId 是完全可行的，所以我们在实际使用的时候还是要注意下方式。
三、总结
先实践，实操，在理解原理。以上为实际实践，如果发现有问题，欢迎指出，交流！
评论