Proxied GET requests fail with a 400 BAD_REQUEST at Spring-Core Version >= 6.1.8

jorekai commented 1 month ago

Affects: Spring-Core Version 6.1.8++

Bug Description

In a Spring Boot microservice setup running in an AWS EKS cluster, there is an intermittent issue between two services in the same namespace. When Service A (touchpoint) makes a GET request to Service B (proxy Spring Boot microservice), Service C (another Spring Boot microservice) denies the proxied request with a 400 BAD Request error. This error occurs without the request being handled in Service C's controller. The issue only appears from Spring Core version 6.1.8 onwards, affecting approximately 0.2% of all proxied GET requests.

Steps to Reproduce

Spring Version: 6.1.8 and above.
Java Version: 17.
Project Setup:
- Services are deployed in an AWS EKS cluster.
- Service A makes a GET request to Service B, which proxies the request to Service C.
- Service C returns a 400 BAD Request error intermittently without handling the request in its controller.

Expected Behavior

Service C should process all proxied GET requests from Service B without returning a 400 BAD Request error.

Actual Behavior

Approximately 0.2% of proxied GET requests from Service B to Service C are denied with a 400 BAD Request error, without being handled by Service C's controller.

Additional Context

Operating System: AWS EKS environment.
IDE: IntelliJ IDEA.
Additional Libraries: Various dependencies as specified in the provided pom.xml setup.

Proxy Service Setup

pom.xml

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">

    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>3.3.1</version>
        <relativePath/>
    </parent>

    <!-->Needed for Pipeline "Build Version"</-->
    <modelVersion>4.0.0</modelVersion>
    <artifactId>...</artifactId>
    <groupId>...</groupId>
    <description>...</description>
    <version>1.1.266</version>
    <packaging>pom</packaging>

    <properties>
        <bcprov-jdk15on.version>1.70</bcprov-jdk15on.version>
        <commons-codec.version>1.15</commons-codec.version>
        <commons-collections4.version>4.4</commons-collections4.version>
        <commons-io.version>2.16.1</commons-io.version>
        <commons-text.version>1.12.0</commons-text.version>
        <commons-lang3.version>3.14.0</commons-lang3.version>
        <cucumber-junit.version>7.18.0</cucumber-junit.version>
        <easy-random-core.version>5.0.0</easy-random-core.version>
        <gitlog.version>1.14.0</gitlog.version>
        <guava.version>33.2.1-jre</guava.version>
        <h2.version>2.2.224</h2.version>
        <jacoco.version>0.8.12</jacoco.version>
        <jsonwebtoken.version>0.12.5</jsonwebtoken.version>
        <spring-boot-starter-oauth2-resource-server.version>3.3.1</spring-boot-starter-oauth2-resource-server.version>
        <logback.version>1.2.10</logback.version>
        <lombok.version>1.18.32</lombok.version>
        <mapstruct.version>1.5.5.Final</mapstruct.version>
        <java.version>17</java.version>
        <maven.compiler.source>17</maven.compiler.source>
        <maven.compiler.target>17</maven.compiler.target>
        <metrics-core.version>4.2.18</metrics-core.version>
        <micrometer.version>1.13.1</micrometer.version>
        <net.jodah.failsafe.version>2.4.4</net.jodah.failsafe.version>
        <nimbus-jose-jwt.version>9.40</nimbus-jose-jwt.version>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <quartz.version>2.3.2</quartz.version>
        <spring-boot-maven-plugin.version>3.3.1</spring-boot-maven-plugin.version>
        <spring-cloud-dependencies.version>2023.0.2</spring-cloud-dependencies.version>
        <spring-cloud-contract.version>4.1.3</spring-cloud-contract.version>
        <spring-retry.version>2.0.6</spring-retry.version>
        <swagger-request-validator.version>2.40.0</swagger-request-validator.version>
        <testcontainers.version>1.19.8</testcontainers.version>
        <wiremock.version>3.0.1</wiremock.version>
        <jackson-bom.version>2.15.0</jackson-bom.version>
        <snakeyaml.version>2.0</snakeyaml.version>
        <postgresql.version>42.7.3</postgresql.version>
        <mockito-inline.version>5.2.0</mockito-inline.version>
    </properties>

    <dependencyManagement>
        <dependencies>
            <dependency>
                <groupId>org.mapstruct</groupId>
                <artifactId>mapstruct-jdk8</artifactId>
                <version>${mapstruct.version}</version>
            </dependency>
            <dependency>
                <groupId>org.mapstruct</groupId>
                <artifactId>mapstruct</artifactId>
                <version>${mapstruct.version}</version>
            </dependency>
            <dependency>
                <groupId>org.apache.commons</groupId>
                <artifactId>commons-collections4</artifactId>
                <version>${commons-collections4.version}</version>
            </dependency>
            <dependency>
                <groupId>commons-io</groupId>
                <artifactId>commons-io</artifactId>
                <version>${commons-io.version}</version>
            </dependency>
            <dependency>
                <groupId>org.mapstruct</groupId>
                <artifactId>mapstruct-processor</artifactId>
                <version>${mapstruct.version}</version>
                <scope>provided</scope>
            </dependency>
            <dependency>
                <groupId>com.nimbusds</groupId>
                <artifactId>nimbus-jose-jwt</artifactId>
                <version>${nimbus-jose-jwt.version}</version>
            </dependency>
            <dependency>
                <groupId>com.h2database</groupId>
                <artifactId>h2</artifactId>
                <version>${h2.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>org.springframework.cloud</groupId>
                <artifactId>spring-cloud-dependencies</artifactId>
                <version>${spring-cloud-dependencies.version}</version>
                <type>pom</type>
                <scope>import</scope>
            </dependency>
            <dependency>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-starter-oauth2-resource-server</artifactId>
                <version>${spring-boot-starter-oauth2-resource-server.version}</version>
            </dependency>
            <dependency>
                <groupId>org.bouncycastle</groupId>
                <artifactId>bcprov-jdk15on</artifactId>
                <version>${bcprov-jdk15on.version}</version>
            </dependency>
            <dependency>
                <groupId>org.apache.commons</groupId>
                <artifactId>commons-text</artifactId>
                <version>${commons-text.version}</version>
            </dependency>
            <dependency>
                <groupId>org.springframework.cloud</groupId>
                <artifactId>spring-cloud-starter-contract-verifier</artifactId>
                <version>${spring-cloud-contract.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>org.springframework.cloud</groupId>
                <artifactId>spring-cloud-starter-contract-stub-runner</artifactId>
                <version>${spring-cloud-contract.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>org.apache.commons</groupId>
                <artifactId>commons-lang3</artifactId>
                <version>${commons-lang3.version}</version>
            </dependency>
            <dependency>
                <groupId>com.google.guava</groupId>
                <artifactId>guava</artifactId>
                <version>${guava.version}</version>
            </dependency>
            <dependency>
                <groupId>org.projectlombok</groupId>
                <artifactId>lombok</artifactId>
                <version>${lombok.version}</version>
                <scope>provided</scope>
            </dependency>
            <dependency>
                <groupId>io.micrometer</groupId>
                <artifactId>micrometer-spring-legacy</artifactId>
                <version>${micrometer.version}</version>
            </dependency>
            <dependency>
                <groupId>io.micrometer</groupId>
                <artifactId>micrometer-core</artifactId>
                <version>${micrometer.version}</version>
            </dependency>
            <dependency>
                <groupId>io.micrometer</groupId>
                <artifactId>micrometer-registry-prometheus</artifactId>
                <version>${micrometer.version}</version>
            </dependency>
            <dependency>
                <groupId>com.atlassian.oai</groupId>
                <artifactId>swagger-request-validator-core</artifactId>
                <version>${swagger-request-validator.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>com.atlassian.oai</groupId>
                <artifactId>swagger-request-validator-mockmvc</artifactId>
                <version>${swagger-request-validator.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>io.cucumber</groupId>
                <artifactId>cucumber-java</artifactId>
                <version>${cucumber-junit.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>io.cucumber</groupId>
                <artifactId>cucumber-junit</artifactId>
                <version>${cucumber-junit.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>io.cucumber</groupId>
                <artifactId>cucumber-spring</artifactId>
                <version>${cucumber-junit.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>com.github.tomakehurst</groupId>
                <artifactId>wiremock</artifactId>
                <version>${wiremock.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>io.jsonwebtoken</groupId>
                <artifactId>jjwt-api</artifactId>
                <version>${jsonwebtoken.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>io.jsonwebtoken</groupId>
                <artifactId>jjwt-impl</artifactId>
                <version>${jsonwebtoken.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>io.jsonwebtoken</groupId>
                <artifactId>jjwt-jackson</artifactId>
                <version>${jsonwebtoken.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>org.springframework.retry</groupId>
                <artifactId>spring-retry</artifactId>
                <version>${spring-retry.version}</version>
            </dependency>
            <dependency>
                <groupId>net.jodah</groupId>
                <artifactId>failsafe</artifactId>
                <version>${net.jodah.failsafe.version}</version>
            </dependency>
            <dependency>
                <groupId>org.testcontainers</groupId>
                <artifactId>junit-jupiter</artifactId>
                <version>${testcontainers.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>org.jeasy</groupId>
                <artifactId>easy-random-core</artifactId>
                <version>${easy-random-core.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>org.mockito</groupId>
                <artifactId>mockito-inline</artifactId>
                <version>${mockito-inline.version}</version>
                <scope>test</scope>
            </dependency>
            <dependency>
                <groupId>io.dropwizard.metrics</groupId>
                <artifactId>metrics-core</artifactId>
                <version>${metrics-core.version}</version>
            </dependency>
        </dependencies>
    </dependencyManagement>
    <build>
        <pluginManagement>
            <plugins>
                <plugin>
                    <!-- used to generate changelog.txt -->
                    <groupId>com.github.danielflower.mavenplugins</groupId>
                    <artifactId>gitlog-maven-plugin</artifactId>
                    <version>${gitlog.version}</version>
                    <executions>
                        <execution>
                            <goals>
                                <goal>generate</goal>
                            </goals>
                        </execution>
                    </executions>
                    <configuration>
                        <simpleHTMLChangeLogFilename>changelog-${project.name}.html</simpleHTMLChangeLogFilename>
                        <markdownChangeLogFilename>changelog-${project.name}.md</markdownChangeLogFilename>
                        <generateMarkdownChangeLog>true</generateMarkdownChangeLog>
                        <includeCommitsAfter>2019-05-07 14:00:15</includeCommitsAfter>
                        <!-- For release notes with only merged branches you a sample configuration. -->
                        <fullGitMessage>false</fullGitMessage>
                        <mergeCommitFilter>false</mergeCommitFilter>
                        <!-- only use commits that start with a Jira Ticket -->
                        <excludeCommitsPattern>(^(?!([A-Z]+-[0-9]+)).*$)</excludeCommitsPattern>
                        <!-- For release notes with only merged branches you a sample configuration. -->
                        <reportTitle>Changelog for ${project.name}</reportTitle>

                    </configuration>
                </plugin>
                <plugin>
                    <groupId>org.springframework.cloud</groupId>
                    <artifactId>spring-cloud-contract-maven-plugin</artifactId>
                    <version>${spring-cloud-contract.version}</version>
                </plugin>
            </plugins>
        </pluginManagement>
    </build>

    <modules>
        <module>....</module>
    </modules>

    <distributionManagement>
        ...
    </distributionManagement>

</project>

ProxyController

@GetMapping(value = "proxy-path/xyz", produces = "application/content-type-xyz")
@PreAuthorize("hasRole('role-xyz')")
public ResponseEntity searchXyzProxy(final HttpServletRequest request,
                                     @RequestHeader final MultiValueMap<String, String> allHeaders) throws IOException {
    final ResponseEntity proxiedResponseEntity = searchXyzProxyAdapter.searchXyz(request, allHeaders);

    return ResponseEntity
            .status(proxiedResponseEntity.getStatusCode())
            .headers(createResponseHeaders(proxiedResponseEntity))
            .body(proxiedResponseEntity.getBody());
}

Proxy Adapter

public ResponseEntity searchXyzProxy(final HttpServletRequest request,
                                     final MultiValueMap<String, String> allHeaders) throws IOException {
    try {
        final UriComponentsBuilder builder = createAndMapRequestParameter(request);
        final String searchUrl = builder.buildAndExpand().toUriString();
        final String requestBody = IOUtils.toString(request.getReader());
        final HttpEntity<String> httpEntity = new HttpEntity<>(requestBody, allHeaders);

        return restTemplateProxy.exchange(searchUrl,
                HttpMethod.valueOf(request.getMethod()),
                httpEntity,
                ResponseProxy[].class);

    } catch (final HttpClientErrorException | HttpServerErrorException e) {
        return handleHttpStatusCodeException(e);
    }
}

private ResponseEntity handleHttpStatusCodeException(final HttpStatusCodeException e) {
    logginCatalog.signalHttpClientError(...);
    technicalCatalog.signalExceptionWithLogLevelWarn(e);
    return new ResponseEntity<>(e.getResponseBodyAsString(), e.getResponseHeaders(), e.getStatusCode());
}

RestTemplate Proxy Config

import org.apache.hc.client5.http.config.ConnectionConfig;
import org.apache.hc.client5.http.impl.classic.CloseableHttpClient;
import org.apache.hc.client5.http.impl.classic.HttpClientBuilder;
import org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager;
import org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManagerBuilder;
import org.apache.hc.core5.util.Timeout;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.boot.web.client.RestTemplateBuilder;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.http.HttpHeaders;
import org.springframework.http.client.ClientHttpRequestFactory;
import org.springframework.http.client.ClientHttpRequestInterceptor;
import org.springframework.http.client.HttpComponentsClientHttpRequestFactory;
import org.springframework.web.client.RestTemplate;

import java.nio.charset.StandardCharsets;
import java.time.Duration;

@Bean(name = "restTemplateProxy")
public RestTemplate restTemplateProxy(final RestTemplateBuilder builder) {
    return builder
            .requestFactory(() -> customClientHttpRequestFactory(
                    maxConnectionPerRouteProxy, maxTotalConnectionProxy, connectTimeoutProxy, socketTimeoutProxy, keepAliveTimeProxy))
            .build();
}

public ClientHttpRequestFactory customClientHttpRequestFactory(final int maxConnectionPerRoute, final int maxTotalConnection, final int connectTimeout, final int socketTimeout, final int keepAliveTime) {
    final PoolingHttpClientConnectionManager poolingHttpClientConnectionManager = PoolingHttpClientConnectionManagerBuilder.create()
            .setMaxConnPerRoute(maxConnectionPerRoute)
            .setMaxConnTotal(maxTotalConnection)
            .setDefaultConnectionConfig(ConnectionConfig.custom()
                    .setConnectTimeout(Timeout.of(Duration.ofMillis(connectTimeout)))
                    .setSocketTimeout(Timeout.of(Duration.ofMillis(socketTimeout)))
                    .setTimeToLive(Timeout.of(Duration.ofMillis(keepAliveTime)))
                    .build())
            .build();
    final CloseableHttpClient httpClient = HttpClientBuilder.create()
            .setConnectionManager(poolingHttpClientConnectionManager)
            .build();
    return new HttpComponentsClientHttpRequestFactory(httpClient);
}

Screenshots / Logs

Trimmed Message: cmp.name="..." details.error.code="TECHNICAL_ERROR" details.error.description="Unexpected technical error during processing." details.error.link="org.springframework.web.client.HttpClientErrorException$BadRequest: 400 : "<!doctype html><html lang="en"><head><title>HTTP Status 400 – Bad Request</title><style type="text/css">body {font-family:Tahoma,Arial,sans-serif;} h1, h2, h3, b {color:white;background-color:#525D76;} h1 {font-size:22px;} h2 {font-size:16px;} h3 {font-size:14px;} p {font-size:12px;} a {color:black;} .line {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP Status 400 – Bad Request</h1></body></html>" at 
org.springframework.web.client.HttpClientErrorException.create(HttpClientErrorException.java:103) at 
org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:183) at 
org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:137) at 
org.springframework.web.client.ResponseErrorHandler.handleError(ResponseErrorHandler.java:63) at 
org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:942) at 
org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:891) at 
org.springframework.web.client.RestTemplate.execute(RestTemplate.java:790) at 
org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:672) at 
...ProxyAdapter.searchXyzProxy(ProxyAdapter.java:65) at 
jdk.internal.reflect.GeneratedMethodAccessor339.invoke(Unknown Source) at java.base/
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/
java.lang.reflect.Method.invoke(Method.java:568) at 
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:354) at 
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at 
org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768) at 
org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89) at zml.lib.springboot.internal.aoplogging.AopLoggingAspect.requiredServiceAdvice(AopLoggingAspect.java:185) at zml.lib.springboot.internal.aoplogging.AopLoggingAspect.loggableAdvice(AopLoggingAspect.java:74) at 
jdk.internal.reflect.GeneratedMethodAccessor102.invoke(Unknown Source) at java.base/
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/
java.lang.reflect.Method.invoke(Method.java:568) at 
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:637) at 
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:627) at 
org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:71) at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:173) at 
org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768) at 
org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java
:58) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:173) at 
org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768) at 
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) at 
org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768) at 
org.springframework.aop.framework.Cglib

Possible Cause / Solution

Potential issue with Spring Core version 6.1.8 and above affecting proxied GET requests. Further investigation required to identify the root cause. We suspected some mismatch between the Content-Length Header and the Content-Type. We also investigated if any of these calls would succeed if we just remove the proxied header "content-length" and "content-type" as this is unnecessary for GET requests. We inspected the logs of Service B and Service C with DEBUG depth and couldn't find any error in service C.

Workaround

Leave spring-core Dependency at 6.1.7 which does not result in such a behavior. All Requests are proxied and received by Service C successfully

bclozel commented 1 month ago

We had several regressions due to an aspect change (see #32865). Can you try with the latest 6.1.11 version and let us know?

snicoll commented 1 month ago

Going forward, please do not paste partial build configuration and code snippet in the description as they aren't very useful. If what Brian suggested didn't help, we'd need you to edit the description and provide a small sample that we can actually run ourselves. You can attach a zip to this issue or push the code to a GitHub repository.

jorekai commented 1 month ago

I can confirm now that on version 6.1.11 we still see the same issue. It is quite hard to create a reproducible example, as this scenario includes an EKS environment and independent services, however i will try to create something. We also were not able to reproduce this issue from a local CURL including the exact same request information that were used on our server

snicoll commented 1 month ago

That's the crux of the problem, especially since you claim it works for sure in 6.1.7. 6.1.8 was an out of band release with a very limited changeset. As Brian mentioned, the only thing that's vaguely plausible is the aspect change. Given how small the changelog is, you could literally go through all commits to see if something is relevant to your application. But that's only valid if you're certain that 6.1.7 isn't affected.

jorekai commented 1 month ago

Thanks for the hint, we'll go back to 6.1.7 to double-check that it was working there and then look at all the changes in between.

spring-projects-issues commented 1 month ago

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

spring-projects-issues commented 1 month ago

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.

spring-projects / spring-framework