Spring Boot 3 - Micrometer Tracing @SLF4J Not Displaying New SpanID

Question

I'm currently working with Spring Boot - version 3.2.1, utilizing io.micrometer for tracing and configured Zipkin tracing.

Within my controller:

@GetMapping("/product")
public ResponseEntity<APIResponse<ProductResponseDTO>> getProduct() throws JsonProcessingException {
    log.info("Executing getProduct function");

    ParameterizedTypeReference<ProductResponseDTO> typeRef = new ParameterizedTypeReference<>() {};

    ProductResponseDTO response = apiUtil.get("https://dummyjson.com/products", typeRef);

    log.info("Everything is okay");
    test_1();
    test_2();
    return apiUtil.okay(response, MessageCode.SUCCESS);
}

@NewSpan
public void test_2(){
    log.info("test_2 function");
}

public void test_1(){
    Span newspan = tracer.nextSpan();
    newspan.name("test_1-span");

    try {
        Thread.sleep(1000);  // delay for 1 second
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
    log.info("test_1 function");
}

Logback Configuration:

%X{traceId:-}/%X{spanId:-}

Additionally, I've enabled Hooks.enableAutomaticContextPropagation(); in the main class.

While I can see new span IDs in Zipkin (not for logs but HTTP), the console consistently displays the same span ID.

How can I ensure that the new span IDs are correctly reflected in the console logs?

Answer 1

If you're referring to spanId from test_1 method, you won't see it in MDC.

The reason is, you are creating a new span but not adding it to MDC. You can do that by opening the scope for new span. Following is an example.

public void test_1(){
    Span newSpan = tracer.nextSpan();
    newSpan.name("test_1-span");

    try (Tracer.SpanInScope ws = tracer.withSpan(newSpan)) {
        log.info("Started new span: {} ", newSpan.context().spanId());
        
    } finally {
        newSpan.end();
    }

    log.info("test_1 function");
}

Started new span log should have spanId available in the MDC and in turn in the logs as well.