Search code examples
spring-bootlogbackspring-cloud-sleuth

How did Spring Cloud Sleuth add tracing information to logback log lines?


I have web application based on Spring Boot and it uses logback for logging.

I also inherit some logback defaults from spring boot using:

<include resource="org/springframework/boot/logging/logback/base.xml"/>

I want to start logging tracing information, so I added:

<dependency>
    <groupId>org.springframework.cloud</groupId>
    <artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>

Sleuth adds tracing information to log lines, but I can't find any %X or %mdc in patterns: https://github.com/spring-projects/spring-boot/blob/2.3.x/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback/defaults.xml

How does Sleuth add tracing information into log lines?

I use spring-cloud-starter-parent Hoxton.SR9 parent which brings Spring Boot 2.3.5.RELEASE and spring-cloud-starter-sleuth 2.2.6.RELEASE


Solution

  • (tl;dr at the bottom)
    From the question I suppose you already figured out that the traceId and spanId are placed into the MDC.

    If you take a look at the log integration section of the sleuth docs you will see that the tracing info in the example is between the log level (ERROR) and the pid (97192). If you try to match this with the logback config you will see that there is nothing between the log level and the pid: ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } so how the tracing information get there could be a valid question.

    If you take another look to the docs, it says this:

    This log configuration was automatically setup by Sleuth. You can disable it by disabling Sleuth via spring.sleuth.enabled=false property or putting your own logging.pattern.level property.

    Which still not explicitly explains the mechanism but it gives you a huge hint:

    putting your own logging.pattern.level property

    Based on this, you could think that there is nothing between the log level and the pid, Sleuth simply overrides the log level and places the tracing information into it. And if you search for the property that the docs mention in the code, you will found out that it is exactly what happens:

    TL;DR

    Sleuth overrides the log level pattern and adds tracing info into it:

    map.put("logging.pattern.level", "%5p [${spring.zipkin.service.name:" + "${spring.application.name:}},%X{traceId:-},%X{spanId:-}]");