Issue in Micrometer interceptor if intercept calls another endpoint

[grahammkelly]

As of Spring boot 2.2.2 (and 2.1.9), there is an issue in the micrometer integration when you have a RestTemplate call being intercepted and redirected to another URL.

Use case

The main use case I have, being affected by the issue, is where I intercept a call to an external API to provide authentication on the call.

For instance, we call an external API, but intercept to check if already authenticated. If authenticated, add the auth token to the call. If NOT authenticated, place a call to another endpoint to perform the authentication, then add the auth token to the original call and complete the original call.

In the case where the auth call is being made, the metrics details for the original call is being lost. TBF, this mainly affects calls with path parameters.

This seems to be an issue in how the org.springframework.boot.actuate.metrics.web.client.MetricsClientHttpRequestInterceptor stores the urlTemplate, as a ThreadLocal. In the example supplied, the intercept method will wipe the urlTemplate after completion of the auth call.

    @Override
	public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution)
			throws IOException {
		...
		try {
			response = execution.execute(request, body);
			return response;
		}
		finally {
			getTimeBuilder(request, response).register(this.meterRegistry).record(System.nanoTime() - startTime,
					TimeUnit.NANOSECONDS);
			urlTemplate.remove();   // <-- This is the offending command
		}
	}

Ideally, the urlTemplate needs to be a thread local stack of some type, OR if the performance hit on this is too large, there needs to be some way to override the default functionality for anyone needing this sort of functionality.

PS - If a fix is created for this, can it be backported to 2.1.X?

Example project

Project demonstrating the issue is available here: https://github.com/grahammkelly/sb-issue

[bclozel]

I've reproduced this issue with a simpler repro:

A sample controller exposing two endpoints:

@RestController
public class SampleController {

	private final RestTemplate restTemplate;

	public SampleController(RestTemplate restTemplate) {
		this.restTemplate = restTemplate;
	}

	@GetMapping("/test")
	public String test() {
		return restTemplate.getForObject("http://localhost:8080/{test}", String.class, "resource");
	}

	@GetMapping("/resource")
	public String resource() {
		return "resource";
	}
}

An interceptor nesting requests:

public class MyInterceptor implements ClientHttpRequestInterceptor {

	final RestTemplate restTemplate;

	public MyInterceptor(RestTemplate restTemplate) {
		this.restTemplate = restTemplate;
	}

	@Override
	public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException {
		ResponseEntity<String> response = restTemplate.getForEntity("http://localhost:8080/{intercept}", String.class, "resource");
		return execution.execute(request, body);
	}
}

And a configuration connecting all the pieces:

@Configuration
public class RestClientConfig {

	@Bean
	public RestTemplate restTemplate(RestTemplateBuilder builder) {
		MyInterceptor myInterceptor = new MyInterceptor(builder.build());
		return builder.additionalInterceptors(myInterceptor).build();
	}

}

Nesting requests is not really permitted by the ClientHttpRequestInterceptor - it's not easy to reuse the ClientHttpRequestExecution for different requests. So this approach makes sense.
On the WebClient side, it's much easier to reuse the ExchangeFunction in an ExchangeFilterFunction, but in this case the nested requests won't be instrumented again since they won't be processed by the metrics filter a second time.

We should indeed find a way to allow nested requests when instrumenting RestTemplate instances. I'm targeting this change for 2.3.x for now, as I'm wondering if this could create unexpected behavior changes, depending on the implementation. We can reconsider that then.

[grahammkelly]

Thanks for that. Robably made it too complex. I was trying to show the usage and not familiar with how much to show on these issues. Graham

…

On Mon 16 Dec 2019 at 21:57, Brian Clozel ***@***.***> wrote: I've reproduced this issue with a simpler repro: A sample controller exposing two endpoints: @RestController public class SampleController { private final RestTemplate restTemplate; public SampleController(RestTemplate restTemplate) { this.restTemplate = restTemplate; } @GetMapping("/test") public String test() { return restTemplate.getForObject("http://localhost:8080/{test}", String.class, "resource"); } @GetMapping("/resource") public String resource() { return "resource"; } } An interceptor nesting requests: public class MyInterceptor implements ClientHttpRequestInterceptor { final RestTemplate restTemplate; public MyInterceptor(RestTemplate restTemplate) { this.restTemplate = restTemplate; } @OverRide public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException { ResponseEntity<String> response = restTemplate.getForEntity("http://localhost:8080/{intercept}", String.class, "resource"); return execution.execute(request, body); } } And a configuration connecting all the pieces: @configuration public class RestClientConfig { @bean public RestTemplate restTemplate(RestTemplateBuilder builder) { MyInterceptor myInterceptor = new MyInterceptor(builder.build()); return builder.additionalInterceptors(myInterceptor).build(); } } Nesting requests is not really permitted by the ClientHttpRequestInterceptor - it's not easy to reuse the ClientHttpRequestExecution for different requests. So this approach makes sense. On the WebClient side, it's much easier to reuse the ExchangeFunction in an ExchangeFilterFunction, but in this case the nested requests won't be instrumented again since they won't be processed by the metrics filter a second time. We should indeed find a way to allow nested requests when instrumenting RestTemplate instances. I'm targeting this change for 2.3.x for now, as I'm wondering if this could create unexpected behavior changes, depending on the implementation. We can reconsider that then. — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#19381?email_source=notifications&email_token=AAXUIQXXRYBKVCNQYB75DQ3QY72TTA5CNFSM4J3HVOMKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEHAHWEI#issuecomment-566262545>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAXUIQUY5UQWPNP7HI67ISTQY72TTANCNFSM4J3HVOMA> .

[grahammkelly]

This mean a projected fix for Oct 2020 (ish)?

…

On Mon 16 Dec 2019 at 22:01, Graham Kelly ***@***.***> wrote: Thanks for that. Robably made it too complex. I was trying to show the usage and not familiar with how much to show on these issues. Graham On Mon 16 Dec 2019 at 21:57, Brian Clozel ***@***.***> wrote: > I've reproduced this issue with a simpler repro: > > A sample controller exposing two endpoints: > > @RestController > public class SampleController { > > private final RestTemplate restTemplate; > > public SampleController(RestTemplate restTemplate) { > this.restTemplate = restTemplate; > } > > @GetMapping("/test") > public String test() { > return restTemplate.getForObject("http://localhost:8080/{test}", String.class, "resource"); > } > > @GetMapping("/resource") > public String resource() { > return "resource"; > } > } > > An interceptor nesting requests: > > public class MyInterceptor implements ClientHttpRequestInterceptor { > > final RestTemplate restTemplate; > > public MyInterceptor(RestTemplate restTemplate) { > this.restTemplate = restTemplate; > } > > @OverRide > public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException { > ResponseEntity<String> response = restTemplate.getForEntity("http://localhost:8080/{intercept}", String.class, "resource"); > return execution.execute(request, body); > } > } > > And a configuration connecting all the pieces: > > @configuration > public class RestClientConfig { > > @bean > public RestTemplate restTemplate(RestTemplateBuilder builder) { > MyInterceptor myInterceptor = new MyInterceptor(builder.build()); > return builder.additionalInterceptors(myInterceptor).build(); > } > > } > > Nesting requests is not really permitted by the > ClientHttpRequestInterceptor - it's not easy to reuse the > ClientHttpRequestExecution for different requests. So this approach > makes sense. > On the WebClient side, it's much easier to reuse the ExchangeFunction in > an ExchangeFilterFunction, but in this case the nested requests won't be > instrumented again since they won't be processed by the metrics filter a > second time. > > We should indeed find a way to allow nested requests when instrumenting > RestTemplate instances. I'm targeting this change for 2.3.x for now, as > I'm wondering if this could create unexpected behavior changes, depending > on the implementation. We can reconsider that then. > > — > You are receiving this because you authored the thread. > Reply to this email directly, view it on GitHub > <#19381?email_source=notifications&email_token=AAXUIQXXRYBKVCNQYB75DQ3QY72TTA5CNFSM4J3HVOMKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEHAHWEI#issuecomment-566262545>, > or unsubscribe > <https://github.com/notifications/unsubscribe-auth/AAXUIQUY5UQWPNP7HI67ISTQY72TTANCNFSM4J3HVOMA> > . >

[bclozel]

@grahammkelly milestones dates are on the dedicated page. We can't promise a release date for this fix until it's assigned to a milestone with a scheduled release date. We're working on our backlog and priorities.

[snicoll]

Closing in favour of PR #19464