ICode9

精准搜索请尝试: 精确搜索
首页 > 其他分享> 文章详细

(WebFlux)002、如何打印日志与链路ID

2022-08-12 23:01:40  阅读:178  来源: 互联网

标签:traceId return Mono joinPoint WebFlux 002 result 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,代码如下。

/**
 * <p>记录traceId</p>
 *
 * @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;
                });
    }
}

实现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
@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;
    }
}

我们直接通过切面,来判断响应结果是否是属于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;
    }
}

一激动,马上唰唰写出来了,但是这样写可不可以呢(文章已标记是错误的写法)?为啥说是错误的写法呢,那是因为在Reactor3中,有一个至理名言,那就是nothing happens until you subscribe()。我们没有订阅,所以Mono.subscriberContext().map()这一个流不会被执行的(点完餐付完钱店家才确定要做)。

所以我们稍微动一下代码,如下。

/**
 * <br>日志切面</br>
 *
 * @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;
    }
}

我们在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);
    }
}
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是完全可行的,所以我们在实际使用的时候还是要注意下方式。

三、总结

先实践,实操,在理解原理。以上为实际实践,如果发现有问题,欢迎指出,交流!

标签:traceId,return,Mono,joinPoint,WebFlux,002,result,ID
来源: https://www.cnblogs.com/lifacheng/p/16581654.html

本站声明: 1. iCode9 技术分享网(下文简称本站)提供的所有内容,仅供技术学习、探讨和分享;
2. 关于本站的所有留言、评论、转载及引用,纯属内容发起人的个人观点,与本站观点和立场无关;
3. 关于本站的所有言论和文字,纯属内容发起人的个人观点,与本站观点和立场无关;
4. 本站文章均是网友提供,不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属;如您发现该文章侵犯了您的权益,可联系我们第一时间进行删除;
5. 本站为非盈利性的个人网站,所有内容不会用来进行牟利,也不会利用任何形式的广告来间接获益,纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。

专注分享技术,共同学习,共同进步。侵权联系[81616952@qq.com]

Copyright (C)ICode9.com, All Rights Reserved.

ICode9版权所有