Description
Hi all,
We are logging the outgoing FeignClient requests in our Spring Boot applications.
These logs include traceId, spanId and parentId.
On the called service side the same information gets logged (e.g. when logging the incoming HTTP request).
Since the migration to micrometer (i.e. Spring Boot 2.7 to Spring Boot 3.1/3.2 migration) the "chain of spanId" is missing.
Note: a sample application with minimal dependencies has been created to demonstrate the issue.
The sample app provides a /doit
endpoint which invokes its second endpoint /execute
using a FeignClient.
in Spring Boot 2.7
Previous to the migration to micrometer it used to look like:
...
2024-02-01 13:24:18.189 DEBUG [traceId-demo,ac648962656d9825,ac648962656d9825,] 53547 --- [nio-8080-exec-1] o.s.w.f.CommonsRequestLoggingFilter : Before request [GET /doit, headers=[host:"localhost:8080", user-agent:"curl/8.2.1", accept:"*/*"]]
2024-02-01 13:24:18.217 INFO [traceId-demo,ac648962656d9825,ac648962656d9825,] 53547 --- [nio-8080-exec-1] o.m.traceiddemo.TraceIdDemoApplication : doIt()
2024-02-01 13:24:18.234 DEBUG [traceId-demo,ac648962656d9825,468b1628cf4058a1,ac648962656d9825] 53547 --- [nio-8080-exec-2] o.s.w.f.CommonsRequestLoggingFilter : Before request [GET /execute, headers=[x-b3-traceid:"ac648962656d9825", x-b3-spanid:"468b1628cf4058a1", x-b3-parentspanid:"ac648962656d9825", x-b3-sampled:"1", accept:"*/*", user-agent:"Java/17.0.9", host:"localhost:8080", connection:"keep-alive"]]
2024-02-01 13:24:18.235 INFO [traceId-demo,ac648962656d9825,468b1628cf4058a1,ac648962656d9825] 53547 --- [nio-8080-exec-2] o.m.traceiddemo.TraceIdDemoApplication : execute()
...
Where the parentId on the called server side is equals to the spanId logged on the client side. In the example above: ac648962656d9825
in Spring Boot 3.2
After the migration to micrometer i.e. Spring Boot 3.1/3.2 it looks like:
...
2024-02-01T13:29:17.941+01:00 DEBUG [traceId-demo,65bb8e9da8001e399361afdcea28771e,9361afdcea28771e,] 54088 --- [traceId-demo] [nio-8080-exec-1] [65bb8e9da8001e399361afdcea28771e-9361afdcea28771e] o.s.w.f.CommonsRequestLoggingFilter : Before request [GET /doit, headers=[host:"localhost:8080", user-agent:"curl/8.2.1", accept:"*/*"]]
2024-02-01T13:29:17.965+01:00 INFO [traceId-demo,65bb8e9da8001e399361afdcea28771e,9361afdcea28771e,] 54088 --- [traceId-demo] [nio-8080-exec-1] [65bb8e9da8001e399361afdcea28771e-9361afdcea28771e] o.m.traceiddemo.TraceIdDemoApplication : doIt()
2024-02-01T13:29:17.990+01:00 DEBUG [traceId-demo,65bb8e9da8001e399361afdcea28771e,bb68df5602dcb801,61609605eb741c8d] 54088 --- [traceId-demo] [nio-8080-exec-2] [65bb8e9da8001e399361afdcea28771e-bb68df5602dcb801] o.s.w.f.CommonsRequestLoggingFilter : Before request [GET /execute, headers=[b3:"65bb8e9da8001e399361afdcea28771e-61609605eb741c8d-0-9361afdcea28771e", traceparent:"00-65bb8e9da8001e399361afdcea28771e-61609605eb741c8d-00", x-b3-parentspanid:"9361afdcea28771e", x-b3-sampled:"0", x-b3-spanid:"61609605eb741c8d", x-b3-traceid:"65bb8e9da8001e399361afdcea28771e", accept:"*/*", user-agent:"Java/17.0.9", host:"localhost:8080", connection:"keep-alive"]]
2024-02-01T13:29:17.990+01:00 INFO [traceId-demo,65bb8e9da8001e399361afdcea28771e,bb68df5602dcb801,61609605eb741c8d] 54088 --- [traceId-demo] [nio-8080-exec-2] [65bb8e9da8001e399361afdcea28771e-bb68df5602dcb801] o.m.traceiddemo.TraceIdDemoApplication : execute()
...
Where the spanId 9361afdcea28771e
logged on the client side is not present in the log on the server side.
Can this be configured?
How can we get the whole "chain of spanId" back?
It is very important to us so we can chain the logs correctly together.
Please find 2 samples in the attachment:
- Spring Boot 2.7 showing the correct/expected behaviour traceid-demo-sb2.7.tar.gz
- spring Boot 3.2 showing the (from our point of view) broken behaviour traceid-demo-sb3.2.tar.gz
Just start the Spring Boot app and call the /doit
endpoint:
curl http://localhost:8080/doit
Kind regards,
Valentin