-
（WebFlux）002、如何打印日志与链路ID
一、背景
最近在持续改造项目，想通过日志查看用户所有的接口链路日志。在原来基于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，代码如下。
/** *记录traceId
* * @author fattycal@qq.com * @since 2022/8/8 */ @Slf4j @Configuration public 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; }); } }- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
- 18
- 19
- 20
- 21
- 22
- 23
- 24
- 25
- 26
- 27
- 28
- 29
- 30
- 31
- 32
- 33
实现
WebFilter，通过contextWrite方法，把Header中的trace-id存入到上下文中。这个ContextWrite很重要，它是类似于ThreadLocal的东西，如果有老铁不知道，可以参考Context翻译文章，这里我们就不在一一赘述啦。实现了
WebFilter后，并且放入了Context中，这样我们是不是想ThreadLocal一样，取出来直接用就可以了？of course！2.2.2 步骤2 - 切面
直接贴代码，如下（方式一）。
/** *
日志切面 * * @author fattyca1@qq.com * @since 2022/8/10 */ @Aspect @Configuration @Slf4j public 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; } }- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
- 18
- 19
- 20
- 21
- 22
- 23
- 24
- 25
- 26
- 27
- 28
- 29
- 30
- 31
- 32
- 33
- 34
- 35
- 36
- 37
- 38
- 39
- 40
- 41
- 42
- 43
我们直接通过切面，来判断响应结果是否是属于Mono，如果是，则通过flatmap结合
Mono.subscriberContext()拿到traceId，然后在doOnSuccess中打印日志。这样的好处是，不用自己订阅Mono.subscriberContext()。有的哥们就会问，为啥不在
doOnSuccess()中去订阅呢？ 好问题，我们的尝试一下。代码如下（方式二）。@Aspect @Configuration @Slf4j public 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; } }- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
- 18
- 19
- 20
- 21
- 22
- 23
- 24
- 25
- 26
- 27
- 28
- 29
- 30
- 31
- 32
- 33
- 34
- 35
一激动，马上唰唰写出来了，但是
这样写可不可以呢（文章已标记是错误的写法）？为啥说是错误的写法呢，那是因为在Reactor3中，有一个至理名言，那就是nothing happens until you subscribe()。我们没有订阅，所以Mono.subscriberContext().map()这一个流不会被执行的（点完餐付完钱店家才确定要做）。所以我们稍微动一下代码，如下。
/** *
日志切面 * * @author fattyca1@qq.com * @since 2022/8/10 */ @Aspect @Configuration @Slf4j public 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; } }- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
- 10
- 11
- 12
- 13
- 14
- 15
- 16
- 17
- 18
- 19
- 20
- 21
- 22
- 23
- 24
- 25
- 26
- 27
- 28
- 29
- 30
- 31
- 32
- 33
- 34
- 35
- 36
- 37
- 38
- 39
- 40
- 41
我们在map方法后面又增加了
subscribe()方法，这个时候，付钱了，餐馆才给你做饭。当然，我们又添加了publishOn这个方法，那是因为subscribe()是阻塞的，为了不阻塞，我们放进了一个新的线程池中处理。这样我们就大功告成啦！ 马上动手测试一下2.2.3 品尝果实
我们直接来一个朴实无华的测试，代码如下。
@RestController public class WebfluxController { @RequestMapping("/hi/{name}") @Loggable public Mono<String> helloWorld(@PathVariable("name") String name) { return Mono.fromSupplier(() -> "hi, " + name); } }- 1
- 2
- 3
- 4
- 5
- 6
- 7
- 8
- 9
2.2.3.1 （方式一）
先按照方式一的方式来测试，结果如图所示。
方式一测试出来，的确没问题，我们把Header中的Trace-id打印出来了。那接下来试试方式二。
2.2.3.2 （方式二）
方式一实现方式测试，结果如图所示。
擦，扑街了~，从测试结果看，这样的方式是取不到Context中的值，我在尝试去掉线程池后，也还是取不到Context中的值。为什么没有取到这一点，还没研究透，后面研究透了给大家补上。
从结果看，我们还是通过FlatMap的方式，提前拿到Trace-id还是靠谱一点。
2.2.3.2 测试三
我们修改了一下Controller中的代码，通过flatMap，从Context中获取traceId。再测试一下。结果如图所示。
通过测试我们发下，通过flatmap，然后再从Context中获取traceId是完全可行的，所以我们在实际使用的时候还是要注意下方式。
三、总结
先实践，实操，在理解原理。以上为实际实践，如果发现有问题，欢迎指出，交流！
-
相关阅读:
Linux ifconfig只显示 lo 网卡，没有ens网卡解决方案
React 入门：组件实例三大属性之props
联盟营销最佳实践：提高联盟计划的投资回报率
maven插件exec-maven-plugin、maven-antrun-plugin使用详解
（14）点云数据处理学习——RGBD 里程计
速通Redis基础（一）：掌握Redis的字符串类型和命令
Redis：19-Redis6新特性
阿里架构师耗时 1 年，把 P8 所需要的整个 Java 体系，都整理到了一起
COM库使用与问题解决
UNI-APP 框架中解决打包后index.html文件中没有引号问题
- 原文地址：https://blog.csdn.net/shiyan719902675/article/details/126312476
