Spring-Webflux: Add jaeger traceId to log via MDC

Question

I use Sping-Webflux and want to automatically add jaeger traceId into my @Slf4j log.

I have an appender in my logback.xml with %X{traceId} pattern like this

<Pattern>
     %d{yyyy-MM-dd HH:mm:ss} %X{traceId} -2048msg%n
</Pattern>

Following to this answer on a similiar topic I have created a custom web filter where I added traceId into MDC:

@Component
@RequiredArgsConstructor
public class CustomWebFilter implements WebFilter {

    private final Tracer tracer;

    @Override
    public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) {
        SpanContext spanContext = tracer.activeSpan().context();
        MDC.put("traceId", spanContext.toTraceId());
        return chain
            .filter(exchange);
    }
}

I have tested it and it seems it works. But I have doubts that this solution is correct. I do not understand how a static MDC.put can handle simultaneously multiple different log events if they happen at the same time? When I put traceId into MDC will it affect all logs or only the required log which is linked to the web request?

MDC stores the key/values per thread context and a request is handle by a single thread. — sge, Jan 23 '23 at 14:27
it means that you cant use MDC in webflux since MDC stores its value in ThreadLocal, and Webflux is thread agnostic meaning that you need to use the reactive context if you want this value to logged deeper into your application — Toerktumlare, Jan 23 '23 at 17:50
I tried this `return chain.filter(exchange).contextWrite(context -> context.put("traceId", spanContext.toTraceId()))` but it does not work: `%X{traceId}` stays undefined in the log pattern. — Mikhail Geyer, Jan 24 '23 at 07:20
It looks like logback xml pattren variables do not see anything from reactive `context`. — Mikhail Geyer, Jan 24 '23 at 07:28

Mikhail Geyer · Accepted Answer · 2023-01-29T08:41:16.533

I found the answer in this very helpful article on habr. I followed the solution described in the article and realized the following:

@Component
@RequiredArgsConstructor
public class CustomWebFilter implements WebFilter {

    private final Tracer tracer;

    @Override
    public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) {
        return chain.filter(exchange)
                .doOnSubscribe(subscription -> {
                    SpanContext spanContext = tracer.activeSpan().context();
                    MDC.put("traceId", spanContext.toTraceId());
                })
                .doFinally(signalType -> {
                    MDC.remove("traceId");
                });
    }
}

As described in the article that solution has a limitation: it will not work if you will operate manually with a new thread creation - for example when using subscribeOn(Schedulers.boundedElastic()). This case is covered in the chapter "Дополнение" via Schedulers.onScheduleHook.

There is also an official solution from projectreactor faq on how to handle mdc for logging. You will find it here. This solution is different from the habr article as it requires extra code and explicit set of contextWrite everytime you want to log the event.

Firstly, you introduce this helper function

public static <T> Consumer<Signal<T>> logOnNext(Consumer<T> logStatement) {
    return signal -> {
        if (!signal.isOnNext()) return;
        Optional<String> toPutInMdc = signal.getContext().getOrEmpty("traceId");

        toPutInMdc.ifPresentOrElse(tpim -> {
        try (MDC.MDCCloseable cMdc = MDC.putCloseable("traceId", tpim)) {
            logStatement.accept(signal.get());
        }
    },
    () -> logStatement.accept(signal.get()));
    };
}

Secondly, everytime you log something you need to call explicitly logOnNext and put traceId into reactive context:

@GetMapping("/byPrice")
public Flux<Restaurant> byPrice(@RequestParam Double maxPrice) {    
    return restaurantService.byPrice(maxPrice))
        .doOnEach(logOnNext(r -> LOG.debug("found restaurant {}", r.getName())))
        .contextWrite(Context.of("traceId", traceId));
}

Spring-Webflux: Add jaeger traceId to log via MDC

1 Answers1