Connection reset when making a rest call with RestTemplate

179 views Asked by At

I'm using

    /* Apache HttpComponents */
    val apacheHttpComponentsVersion = "5.2.1"
    val apacheHttpComponentsGroup = "org.apache.httpcomponents.client5"
    implementation("$apacheHttpComponentsGroup:httpclient5:$apacheHttpComponentsVersion")

    /* Spring */
    val springVersion = "3.1.4"
    val springFrameworkGroup = "org.springframework.boot"
    implementation("$springFrameworkGroup:spring-boot-starter-web:$springVersion")

and I'm getting the following exception when making a restTemplate.exchange(....)

2023-11-07T06:41:19.432149693Z java.net.SocketException: Connection reset
2023-11-07T06:41:19.432192293Z  at java.base/sun.nio.ch.NioSocketImpl.implRead(Unknown Source)
2023-11-07T06:41:19.432199093Z  at java.base/sun.nio.ch.NioSocketImpl.read(Unknown Source)
2023-11-07T06:41:19.432203493Z  at java.base/sun.nio.ch.NioSocketImpl$1.read(Unknown Source)
2023-11-07T06:41:19.432208293Z  at java.base/java.net.Socket$SocketInputStream.read(Unknown Source)
2023-11-07T06:41:19.432212993Z  at java.base/sun.security.ssl.SSLSocketInputRecord.read(Unknown Source)
2023-11-07T06:41:19.432217493Z  at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(Unknown Source)
2023-11-07T06:41:19.432221193Z  at java.base/sun.security.ssl.SSLSocketInputRecord.decode(Unknown Source)
2023-11-07T06:41:19.432224993Z  at java.base/sun.security.ssl.SSLTransport.decode(Unknown Source)
2023-11-07T06:41:19.432229293Z  at java.base/sun.security.ssl.SSLSocketImpl.decode(Unknown Source)
2023-11-07T06:41:19.432233793Z  at java.base/sun.security.ssl.SSLSocketImpl.readHandshakeRecord(Unknown Source)
2023-11-07T06:41:19.432237993Z  at java.base/sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source)
2023-11-07T06:41:19.432241793Z  at java.base/sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source)
2023-11-07T06:41:19.432245993Z  at org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory.executeHandshake(SSLConnectionSocketFactory.java:303)
2023-11-07T06:41:19.432250093Z  at org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:275)
2023-11-07T06:41:19.432254793Z  at org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:251)
2023-11-07T06:41:19.432258893Z  at org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:181)
2023-11-07T06:41:19.432263193Z  at org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:447)
2023-11-07T06:41:19.432267793Z  at org.apache.hc.client5.http.impl.classic.InternalExecRuntime.connectEndpoint(InternalExecRuntime.java:162)
2023-11-07T06:41:19.432272593Z  at org.apache.hc.client5.http.impl.classic.InternalExecRuntime.connectEndpoint(InternalExecRuntime.java:172)
2023-11-07T06:41:19.432277193Z  at org.apache.hc.client5.http.impl.classic.ConnectExec.execute(ConnectExec.java:142)
2023-11-07T06:41:19.432281693Z  at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
2023-11-07T06:41:19.432285693Z  at org.apache.hc.client5.http.impl.classic.ProtocolExec.execute(ProtocolExec.java:192)
2023-11-07T06:41:19.432388493Z  at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
2023-11-07T06:41:19.432397093Z  at org.apache.hc.client5.http.impl.classic.HttpRequestRetryExec.execute(HttpRequestRetryExec.java:96)
2023-11-07T06:41:19.432401293Z  at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
2023-11-07T06:41:19.432405293Z  at org.apache.hc.client5.http.impl.classic.ContentCompressionExec.execute(ContentCompressionExec.java:152)
2023-11-07T06:41:19.432409493Z  at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
2023-11-07T06:41:19.432414093Z  at org.apache.hc.client5.http.impl.classic.RedirectExec.execute(RedirectExec.java:115)
2023-11-07T06:41:19.432418593Z  at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
2023-11-07T06:41:19.432422593Z  at org.apache.hc.client5.http.impl.classic.InternalHttpClient.doExecute(InternalHttpClient.java:170)
2023-11-07T06:41:19.432426293Z  at org.apache.hc.client5.http.impl.classic.CloseableHttpClient.execute(CloseableHttpClient.java:106)
2023-11-07T06:41:19.432430193Z  at org.apache.hc.client5.http.impl.classic.CloseableHttpClient.execute(CloseableHttpClient.java:55)
2023-11-07T06:41:19.432434194Z  at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:93)
2023-11-07T06:41:19.432438594Z  at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)
2023-11-07T06:41:19.432443194Z  at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:66)
2023-11-07T06:41:19.432447494Z  at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:862)
2023-11-07T06:41:19.432451394Z  [wrapped] org.springframework.web.client.ResourceAccessException: I/O error on POST request for "https://shop.schaeferbarthold.com/SBShopTest/rest/part/price": Connection reset
2023-11-07T06:41:19.432455894Z  at org.springframework.web.client.RestTemplate.createResourceAccessException(RestTemplate.java:888)
2023-11-07T06:41:19.432460094Z  at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:868)
2023-11-07T06:41:19.432464194Z  at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:785)
2023-11-07T06:41:19.432468494Z  at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:656)
2023-11-07T06:41:19.432505894Z  at jdk.internal.reflect.GeneratedMethodAccessor50.invoke(Unknown Source)
2023-11-07T06:41:19.432509794Z  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-11-07T06:41:19.432513394Z  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-11-07T06:41:19.432517194Z  at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
2023-11-07T06:41:19.432520994Z  at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196)
2023-11-07T06:41:19.432525294Z  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
2023-11-07T06:41:19.432529994Z  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:751)
2023-11-07T06:41:19.432534494Z  at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
2023-11-07T06:41:19.432542494Z  at jdk.internal.reflect.GeneratedMethodAccessor34.invoke(Unknown Source)
2023-11-07T06:41:19.432546394Z  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-11-07T06:41:19.432550394Z  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2023-11-07T06:41:19.432554394Z  at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:637)
2023-11-07T06:41:19.432558794Z  at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:627)
2023-11-07T06:41:19.432562694Z  at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:71)
2023-11-07T06:41:19.432566694Z  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:173)
2023-11-07T06:41:19.432571594Z  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:751)
2023-11-07T06:41:19.432576094Z  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
2023-11-07T06:41:19.432580794Z  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
2023-11-07T06:41:19.432585594Z  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:751)
2023-11-07T06:41:19.432589794Z  at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:703)
2023-11-07T06:41:19.432601894Z  at jdk.internal.reflect.GeneratedMethodAccessor50.invoke(Unknown Source)
2023-11-07T06:41:19.432606194Z  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2023-11-07T06:41:19.432610094Z  at java.base/java.lang.reflect.Method.invoke(Unknown Source)

my RestTemplate configuration is the following

@Configuration
public class RestClientConfig {

    private static final TimeValue KEEP_ALIVE_DURATION = TimeValue.ofMilliseconds(10000);
    
    @Bean
    public RestTemplate restTemplate() {
    ConnectionKeepAliveStrategy strategy = (response, context) -> KEEP_ALIVE_DURATION;
    HttpClient httpClient = HttpClients.custom()
                       .setKeepAliveStrategy(strategy)
                       .build();
    
    HttpComponentsClientHttpRequestFactory requestFactory = new HttpComponentsClientHttpRequestFactory();
    requestFactory.setHttpClient(httpClient);
    return new RestTemplate(requestFactory);
    }
    
}

The app is deployed on Azure. Any help would be highly appreciated.

I have increased the KEEP_ALIVE_DURATION to 10 secs which solves the problem (but I don't know how it does that). So that's the reason I'm making this question so I can get better understanding on this topic.

1

There are 1 answers

1
JCompetence On

I might be mistaken, but it might be related to the code below, which decides whether a connection should stay aliv(Reused) or not.

 // The connection is in or can be brought to a re-usable state.
            if (reuseStrategy.keepAlive(request, response, context)) {
                // Set the idle duration of this connection
                final TimeValue duration = keepAliveStrategy.getKeepAliveDuration(response, context);
                if (LOG.isDebugEnabled()) {
                    final String s;
                    if (duration != null) {
                        s = "for " + duration;
                    } else {
                        s = "indefinitely";
                    }
                    LOG.debug("{} connection can be kept alive {}", exchangeId, s);
                }
                execRuntime.markConnectionReusable(userToken, duration);
            } else {
                execRuntime.markConnectionNonReusable();
            }

https://github.com/apache/httpcomponents-client/blob/180d90c84731dcfe3a3c22f2c0b9ab6525046f8d/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/MainClientExec.java#L126C1-L143C14

And at one point the following is called.

@Override
public void releaseEndpoint() {
    final ConnectionEndpoint endpoint = endpointRef.getAndSet(null);
    if (endpoint != null) {
        if (reusable) {
            if (log.isDebugEnabled()) {
                log.debug("{} releasing valid endpoint", ConnPoolSupport.getId(endpoint));
            }
            manager.release(endpoint, state, validDuration);
        } else {
            discardEndpoint(endpoint);
        }
    }
}

https://github.com/apache/httpcomponents-client/blob/180d90c84731dcfe3a3c22f2c0b9ab6525046f8d/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/MainClientExec.java#L148

which in turn depends on the implementation of the HttpClient, you can see something like:

    boolean reusable = conn != null && conn.isOpen() && conn.isConsistent();
    try {
        if (reusable) {
            entry.updateState(state);
            entry.updateExpiry(keepAlive);
            conn.passivate();
            if (LOG.isDebugEnabled()) {
                final String s;
                if (TimeValue.isPositive(keepAlive)) {
                    s = "for " + keepAlive;
                } else {
                    s = "indefinitely";
                }
                LOG.debug("{} connection {} can be kept alive {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(conn), s);
            }
        } else {
            if (LOG.isDebugEnabled()) {
                LOG.debug("{} connection is not kept alive", ConnPoolSupport.getId(endpoint));
            }
        }

https://github.com/apache/httpcomponents-client/blob/180d90c84731dcfe3a3c22f2c0b9ab6525046f8d/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/PoolingHttpClientConnectionManager.java#L382

But you know the best way to figure out the flow, is to enable DEBUG mode for the HTTPClient and you will see the stack of calls.