Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Tracing not working for LogbookClientHandler #1512

Closed
rajapanda15 opened this issue May 29, 2023 · 3 comments
Closed

Tracing not working for LogbookClientHandler #1512

rajapanda15 opened this issue May 29, 2023 · 3 comments

Comments

@rajapanda15
Copy link

Description

The LogbookClientHandler in Spring Boot 3 is not printing trace IDs when logging requests and responses using the LogbookClientHandler.

Expected Behavior

The logbook instance passed to LogbookClientHandler should log the trace and span ids.

Actual Behavior

The logs are printing empty/blank values.
image

The below project can be referred
https://github.com/rajapanda15/Springboot3-Logbook.git

@kasmarian
Copy link
Member

Related to #1513 ?

@kasmarian kasmarian added the minor Minor changes label Jun 26, 2023
@grassehh
Copy link

grassehh commented Jul 13, 2023

I have the same issue.
I don't know if you are using Micrometer and Webflux, but you can check my issue on Reactor Netty.
I managed to make webClient calls working by overriding Logbook's logbookNettyClientCustomizers and wrapping the LogbookClientHandlerwith a custom Netty's ChannelDuplexHandler as suggested by Violeta.
However, using the same mecanism for customizing the Netty HttpServerdoes not work, even though the LogbookServerHandler is called.

Checkout my sample here on the issues/reactor-netty branch.

@msdousti
Copy link
Collaborator

You set log pattern to get the traceId and spanId from the MDC:

logging.pattern.console=%d{yyyy-MM-dd HH:mm:ss.SSS} %5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}] ...

And then expect them to be added to the log lines of Logbook (red boxes below, where they are empty):

image

However, notice that green boxes in the above figure: They show that Logbook is being executed from a separate thread called reactor-http-nio-2, while the original thread was called http-nio-8080-exec-* (not shown in the figure). It appears that WebClient runs in a thread separate from the controller.

The important point to note, from Logback documentation (Logback is an implementation of SLF4J API, and is used behind the scenes by Logbook):

The MDC manages contextual information on a per thread basis.

image

So, here is what happens:

  1. Your controller receives a call, and the MDC is populated by traceId/spanId
  2. The controller calls WebClient without propagating the MDC. It creates a new thread with an empty MDC map.
  3. Any logs printed (regardless whether they are by Logbook or not) will not have traceId/spanId.

This article might be helpful: https://ttddyy.github.io/mdc-with-webclient-in-webmvc/

Pay special attention to Spring Boot 3 section. Hope this helps!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants