Potential memory leak in MetricsClientHttpRequestInterceptor

[arimetso]

Looks like there's a bug in this code in org.springframework.boot.actuate.metrics.web.client.MetricsClientHttpRequestInterceptor class, lines 97 - 99:

    if (urlTemplate.get().isEmpty()) {
        urlTemplate.remove();
    }

I believe the if condition should have a not operator in front of it, meaning item(s) should be removed if the list held by urlTemplate thread-local is not empty.

This came up when looking at a memory leak in code, which is likely an edge case and also uses RestTemplate and UriTemplateHandler in a way some could characterize as misuse. The problem can be reproduced with roughly this kind of logic:

    String template = "https://example.org/api/users/{userId}";
    for (int i : IntStream.range(0, 10000).toArray()) {
        logger.debug("Request to {}", restTemplate.getUriTemplateHandler().expand(template, UUID.randomUUID()));
    }

New items are added to the list, but never removed due to the missing not operator. The accumulated list is visible in heap dump after that loop has finished.

This doesn't seem to be an issue for example in handling of incoming requests. It also looks like there's no problem in how RestTemplate uses the mechanism internally. Long-lived thread with manual UriTemplateHandler.expand() usage with metrics actuator enabled is the key.

[wilkinsona]

Thanks for the report.

The behaviour that you have observed is a side-effect of the fix for #19381. The urlTemplate thread local now holds a Deque that is used as a stack to keep track of the URI template for nested requests. As the nested requests unwind, getTimeBuilder is called which polls the deque and pops the top-most element off the stack. Once all of the requests have unwound, the deque will be empty and it can be removed from the thread local. If it was removed before it was empty, it would be removed too soon and the problem described in #19381 we reoccur.

I'm not sure what we should do about this. bf6f36a has introduced CapturingUriTemplateHandler that is currently package-private. One option would be to make that public and add a method to get its delegate. You could then do an instanceof check and then get and use the delegate for the expansion. Flagging for a team meeting so that we can discuss our options.

[arimetso]

Thanks for the comment.

If I can suggest, removing those lines 97 - 99 should at least remove the confusion about the condition's correctness, if the code otherwise is working as planned.

In my case it's likely the usage for logging, which could lead to bypassing something that would otherwise be done. The condition however caught my eye.

[wilkinsona]

I don't think those lines should be removed as it will make things slightly worse. If they were removed, the thread local would be left holding onto an empty LinkedList for every thread that's been used to make a request.

[arimetso]

You're right, after a closer look at the previous issue #19381 the current implementation makes sense.

I'll leave this open if you want to discuss it more, but it seems to me the "borrowing" of the UriTemplateHandler for manual template expansion was probably just a bit too clever for you own good type of solution.

[wilkinsona]

@mbechtold1, with reference to #26853, how are you using the URL template handler?

[mbechtold1]

Hope this is what you're asking for...

String url = UriComponentsBuilder.fromUriString(template).buildAndExpand(params).toUriString();
RestTemplate.exchange(url, HttpMethod.GET, requestEntity, Void.class);

I've seen another instance using...

RestTemplate.exchange(url, HttpMethod.GET, requestEntity, Void.class, variables);

[wilkinsona]

That style of usage shouldn't cause a problem. URL templates are pushed onto the Deque<String> when a request is being sent and are then removed when the response is received. The removal is done in a finally block so I believe it should always happen. After the URL template's been removed from the Deque<String> the thread local is cleared if it's empty. It will only not be empty in the unusual situation of nested requests being made. Even then it should become empty as those request-response exchanges unwind and will be cleared from the thread local when it does.

If you believe you're seeing behaviour that's contrary to what I've described above it'd be great if you could provide a sample project that reproduces it so that we can investigate further.

[mbechtold1]

projects.zip
hope this helps in the overall conversation

[wilkinsona]

Thanks very much, @mbechtold1. That sample has allowed me to identify a different problem. In your case, auto-timing is disabled so MetricsClientHttpRequestInterceptor doesn't record any request metrics. This also means that it never polls the deque. However, MetricsRestTemplateCustomizer still installs the interceptor's URI template handler which pushes URL templates onto the deque. As a result, it grows unbounded. I've opened #26915.

[mbechtold1]

Sorry I struggle with the code. I just tried to put something together quickly. Please feel free to correctly update my configuration.

[wilkinsona]

The problem's in your MetricsConfig where you define the customizer. This will fix the problem:

@Bean
public MetricsRestTemplateCustomizer getMetricsRestTemplateCustomizer(MeterRegistry meterRegistry) {
    return new MetricsRestTemplateCustomizer(meterRegistry, 
            new DefaultRestTemplateExchangeTagsProvider(), "http.client.requests", AutoTimer.ENABLED);
}

I've made two changes:

• Passing in meterRegistry rather than null
• Passing in AutoTimer.ENABLED rather than null

[mbechtold1]

Thanks Andy. I appreciate your help.

[sinsuren]

Facing similar issue in our production application, below image shows Deque holding a reference of objects worth 107 MB. We are still trying to reproduce the same on local machine.

Items in the Deque are urls which has been visited by above thread.

Springboot version: 2.2.x

[wilkinsona]

@sinsuren Spring Boot 2.2.x is missing fixes for bugs in this area such as #26915 that's linked to above. Its open source support also ended in October 2020. You should upgrade to Spring Boot 2.6.x or 2.7.x as soon as possible.

[sinsuren]

We upgraded our application to 2.6.x as well, but issue was still there. Then we started looking the way we are using RestTemplate and found the issue that we have misconfigured our Rest Template interceptors.

    //Wrong way
    @Bean
    public RestTemplate wrongWayTemplate(final RestTemplateBuilder builder) {
        List<ClientHttpRequestInterceptor> interceptors = new ArrayList<>();
        interceptors.add(new RestTemplateHeaderModifierInterceptor());

        RestTemplate restTemplate = builder.requestFactory(() -> createRequestFactory(config)).build();
        restTemplate.setInterceptors(interceptors);

        return restTemplate;
    }

Correct ways:

   @Bean
   public RestTemplate restTemplate() {
          RestTemplate restTemplate = new RestTemplate();
  
          List<ClientHttpRequestInterceptor> interceptors
            = restTemplate.getInterceptors();
          if (CollectionUtils.isEmpty(interceptors)) {
              interceptors = new ArrayList<>();
          }
          interceptors.add(new RestTemplateHeaderModifierInterceptor());
          restTemplate.setInterceptors(interceptors);
          return restTemplate;
   }

Posting for future users who might face the same issue.

[bclozel]

I don't think we're going to be able to close this issue in the 2.x line without breaking other use cases. This all comes from the fact that RestTemplate is instrumented through a contract that's not meant for this. We're going to address this in Spring Framework 6 & Spring Boot 3 by instrumenting the HTTP clients directly with micrometer Observation.

I'm closing in favor of spring-projects/spring-framework#28341

[vasiliy-sarzhynskyi]

A memory leak is still present in Spring Boot 2.7.18 due to logic in MetricsClientHttpRequestInterceptor.
We did a heap dump and saw that each LinkedList from MetricsClientHttpRequestInterceptor contains millions of URIs hung there and not removed appropriately.
The reason for that is in some cases method URI expand(String uriTemplate, Map<String, ?> uriVariables) might be invoked multiple times per a single request (and, as a result, the same URI will be pushed a few times into urlTemplate field), but will be removed only once. The current logic works fine only if we have a single invocation of expand(..) per request. In our case, one more additional invocation of expand(..) is done by autogenerated code from openapi-generator-maven-plugin, and it leads to memory leak.

CapturingUriTemplateHandler has method expand(..) which breaks the idempotence property, and it leads to the mentioned issue. It looks like there is no elegant way to fix that due to absence of a notion for idempotency ID, especially at the moment when someone might invoke expand(..) earlier than request object will be created.

One potential solution to mitigate issue is to use a fixed size evicting deque that will store only up to N latest items, e.g. N = 100. If size exceeds the limit for such deque, it will evict old items from the head of the deque. I can't imagine when someone needs to invoke from interceptor more than N=100 additional nested requests by a single initial API request. Even if it is exceeded, logic could generate metrics only by N nested requests and skip others.

What do you think about this proposal? If the idea is accepted, I could contribute such fix.

[philwebb]

Thanks for the offer @vasiliy-sarzhynskyi but 2.7.x has reached end of OSS support. Please upgrade your application to a supported version of Spring Boot.