RestTemplate logging interceptor + Spring Cloud Sleuth

I’ve created a RestTemplate interceptor (ClientHttpRequestInterceptor) to log requests and responses and enabled Spring Cloud Sleuth with the goal of tracing transactions from when the interceptor receives a request to the point where it returns a result. However, Sleuth’s trace and span ids do not appear in the interceptors log messages; it seems they are only at a later stage in processing the request. I would like to be able to trace into services that do not have explicit logging, so the interceptor seemed like a good approach, but if there is no way to add the trace and span ids at this stage then I may need to find another approach. Looking for any suggestion which would either add the trace and span to the interceptors log messages or another way to log requests and responses across services with trace and span ids. Thanks!

EDIT: Here’s an example of the log output I’m currently getting from my RestTemplate interceptor with Spring Cloud Sleuth enabled:

2020-08-21 18:53:17.164 DEBUG [,,,] 14256 --- [           main] .c.o.l.RequestResponseLoggingInterceptor : ⇒ HTTP REQUEST: METHOD 'POST', URI 'http://localhost:59742/….

What I’d really like to get is the request (or repsonse) logged with the Sleuth trace and span ids:

2020-08-21 18:53:17.164 DEBUG [my-service-name,d3cb8a2fa7d1d9ac,80b023cb829bf254,false] 14256 --- [           main] .c.o.l.RequestResponseLoggingInterceptor : ⇒ HTTP REQUEST: METHOD 'POST', URI 'http://localhost:59742/….

I’m wondering whether this is possible (ie, adding logging to all service through a RestTemplate interceptor and having those log messages contain the Sleuth ids) or whether there is a different approach I should take to log all requests and responses with the Sleuth trace/span ids. I would appreciate any suggestions!

EDIT 2: A bit more information…My Sleuth config at this point is nothing more than enabling it in a bootstrap.yml file:

spring:
    cloud:
        sleuth:
            enabled: true

I also created / configured a custom CommonsRequestLoggingFilter, which executes just after the interceptor (it’s the next line in the log) and does have the trace / span ids in its log message:

2020-08-21 18:53:17.164 DEBUG [my-app,d3cb8a2fa7d1d9ac,80b023cb829bf254,false] 3479 --- [c-auto-1-exec-2] c.t.c.o.l.CustomRequestLoggingFilter  : ⇒ POST ...

So Sleuth seems to be configured correctly (at least for my purposes now); it just isn’t adding the trace ids to the interceptor’s log messages. Thanks!

Answer

Sleuth documentation says

You have to register RestTemplate as a bean so that the interceptors will get injected. If you create a RestTemplate instance with a new keyword then the instrumentation WILL NOT work.

I hope you are not using new keyword to instantiate RestTemplate.

Advertisement

Answer