Tracing context is lost while logging request body

[baglai]

I have created a simple REST controller (using Spring Boot version 2.7.1, Spring WebFlux version 5.3.27, and Spring Sleuth version 3.1.5). This controller makes a call to an external service using a Reactive Feign client version 3.3.0.
When invoking an external service, the trace is lost when logging the request body. However, the trace is present when logging the request headers, and it's also present when logging the response (both headers and body).

19:29:58.615 [] [] [Test worker] INFO  org.eclipse.jetty.server.Server jetty-11.0.15; built: 2023-04-11T18:37:53.775Z; git: 5bc5e562c8d05c5862505aebe5cf83a61bdbcb96; jvm 17.0.7+7-LTS
19:29:58.657 [] [] [Test worker] INFO  o.e.j.server.handler.ContextHandler Started o.e.j.s.ServletContextHandler@52d434c1{/__admin,null,AVAILABLE}
19:29:58.674 [] [] [Test worker] INFO  o.e.j.s.handler.ContextHandler.ROOT RequestHandlerClass from context returned com.github.tomakehurst.wiremock.http.StubRequestHandler. Normalized mapped under returned 'null'
19:29:58.675 [] [] [Test worker] INFO  o.e.j.server.handler.ContextHandler Started o.e.j.s.ServletContextHandler@5b5a89d1{/,null,AVAILABLE}
19:29:58.688 [] [] [Test worker] INFO  o.e.jetty.server.AbstractConnector Started NetworkTrafficServerConnector@173797f0{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:50000}
19:29:58.691 [] [] [Test worker] INFO  org.eclipse.jetty.server.Server Started Server@7901a5ab{STARTING}[11.0.15,sto=1000] @8390ms
19:29:58.850 [traceId=94679931a68679c9, spanId=94679931a68679c9] [] [parallel-1] INFO  c.e.feigntracing.TestController start request
19:29:58.869 [traceId=94679931a68679c9, spanId=94679931a68679c9] [] [parallel-1] DEBUG r.client.log.DefaultReactiveLogger [FeignTestApi#somePostRequest(String)]--->POST http://localhost:50000/icecream/bills/pay HTTP/1.1
19:29:58.870 [traceId=94679931a68679c9, spanId=94679931a68679c9] [] [parallel-1] TRACE r.client.log.DefaultReactiveLogger [FeignTestApi#somePostRequest(String)] REQUEST HEADERS

19:29:59.177 [] [] [reactor-http-nio-2] TRACE r.client.log.DefaultReactiveLogger [FeignTestApi#somePostRequest(String)] REQUEST BODY
foo
19:29:59.432 [traceId=94679931a68679c9, spanId=94679931a68679c9] [] [reactor-http-nio-2] TRACE r.client.log.DefaultReactiveLogger [FeignTestApi#somePostRequest(String)] RESPONSE HEADERS
Matched-Stub-Id:fbdda2fd-1c00-4c0f-885d-4671cd5d1ec8
Transfer-Encoding:chunked
19:29:59.435 [traceId=94679931a68679c9, spanId=94679931a68679c9] [] [reactor-http-nio-2] DEBUG r.client.log.DefaultReactiveLogger [FeignTestApi#somePostRequest(String)]<--- headers takes 563 milliseconds
19:29:59.458 [traceId=94679931a68679c9, spanId=94679931a68679c9] [] [reactor-http-nio-2] TRACE r.client.log.DefaultReactiveLogger [FeignTestApi#somePostRequest(String)] RESPONSE BODY
Hello World!
19:29:59.458 [traceId=94679931a68679c9, spanId=94679931a68679c9] [] [reactor-http-nio-2] DEBUG r.client.log.DefaultReactiveLogger [FeignTestApi#somePostRequest(String)]<--- body takes 589 milliseconds
19:29:59.490 [] [] [Test worker] INFO  org.eclipse.jetty.server.Server Stopped Server@7901a5ab{STOPPING}[11.0.15,sto=1000]
19:29:59.490 [] [] [Test worker] INFO  org.eclipse.jetty.server.Server Shutdown Server@7901a5ab{STOPPING}[11.0.15,sto=1000]
19:29:59.501 [] [] [Test worker] INFO  o.e.jetty.server.AbstractConnector Stopped NetworkTrafficServerConnector@173797f0{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:50000}
19:29:59.504 [] [] [Test worker] INFO  o.e.j.server.handler.ContextHandler Stopped o.e.j.s.ServletContextHandler@5b5a89d1{/,null,STOPPED}
19:29:59.504 [] [] [Test worker] INFO  o.e.j.server.handler.ContextHandler Stopped o.e.j.s.ServletContextHandler@52d434c1{/__admin,null,STOPPED}

The Controller class looks like this:

@RestController
@RequestMapping("/")
public class TestController {

  private Logger logger = LoggerFactory.getLogger(TestController.class);

  public TestController(WebClient.Builder builder) {
    this.client = WebReactiveFeign.<FeignTestApi>builder(builder)
      .target(FeignTestApi.class, "http://localhost:50000");
  }

  private final FeignTestApi client;


  @GetMapping
  public Mono<String> feign() {
    logger.info("start request");
    return client.somePostRequest("foo")
      .mapNotNull(String::toUpperCase);
  }
}

The api interface looks like

public interface FeignTestApi {

  @RequestLine("POST /icecream/bills/pay")
  Mono<String> somePostRequest(String bill);
}

You can see a full example of a controller here https://github.com/baglai/feign-tracing-test/tree/master
You can run test with ./gradlew test to see the same result

Spring Boot version 2.7.1
Spring WebFlux version 5.3.27
Spring Sleuth version 3.1.5
Reactive Feign client version 3.3.0