first call to Zuul fails with Connection reset when executed on server

[vimal-raz]

If we run the Zuul proxy for about 15-30 min without making any calls, it will fail the first call with an HTTP 500 error (Connection reset when executed on server )zuu. After that, all subsequent calls work properly.

Config:

hystrix:
  command:
    default:
      execution:
        timeout:
          enabled: false

ribbon:
  ReadTimeout: 10000

Versions:

• Spring boot 1.5.7.Release
• <spring-cloud-services.version>1.5.0.RELEASE</spring-cloud-services.version>
• <spring-cloud.version>Dalston.SR3</spring-cloud.version>

Full log: First call fails and second works
https://gist.github.com/vimal-raz/9ddc8113e7513b5ab54d2533b1cad0cb

   2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT 2017-09-27 16:27:36.871 DEBUG 14 --- [nio-8080-exec-2] org.apache.http.wire                     : http-outgoing-30 << "[read] I/O error: Connection reset"
 
   2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT 2017-09-27 16:27:36.871 DEBUG 14 --- [nio-8080-exec-2] h.i.c.DefaultManagedHttpClientConnection : http-outgoing-30: Close connection
   2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT 2017-09-27 16:27:36.871 DEBUG 14 --- [nio-8080-exec-2] h.i.c.DefaultManagedHttpClientConnection : http-outgoing-30: Shutdown connection
   2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT 2017-09-27 16:27:36.871 DEBUG 14 --- [nio-8080-exec-2] o.a.http.impl.execchain.MainClientExec   : Connection discarded
   2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT 2017-09-27 16:27:36.871 DEBUG 14 --- [nio-8080-exec-2] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 30][route: {s}->https://mbdealerservice.apps.dev.us-east-1.nafta-ow.com:443][total kept alive: 0; route allocated: 0 of 50; total allocated: 0 of 200]

  2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT 2017-09-27 16:27:36.871 DEBUG 14 --- [nio-8080-exec-2] c.n.l.reactive.LoadBalancerCommand       : Got error java.net.SocketException: Connection reset when executed on server XXXXXXXXXXXXXX:d10d793e-8293-438d-78c4-20360c35c3a5
2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT com.netflix.client.ClientException: null
   2017-09-27T12:27:36.87-0400 [APP/PROC/WEB/0] OUT 2017-09-27 16:27:36.874 DEBUG 14 --- [nio-8080-exec-2] com.netflix.hystrix.AbstractCommand      : Error executing HystrixCommand.run(). Proceeding to fallback logic ...

[vimal-raz]

It is deployed in Pivotal Cloud Foundry

[spencergibb]

Please learn how to properly format code and logs. What version of spring cloud are you using? See #1334

[vimal-raz]

updated the formatting,. I m using the spring-cloud-services.version>1.5.0.RELEASE. Other versions details are available in ticket.

I found a related ticket
#2079

does it seems like cloud foundry issue?

[spencergibb]

I think this is the same as #2079

[vimal-raz]

I have opened a ticket with cloud foundry team. Will keep this ticket updated. thanks

[dersteve]

@vimal-raz Did you get any updates from the cloud foundry team? We are experiencing the exact same issue - also on CF.

[vimal-raz]

@dersteve , Our infra team is working closely with PCF support to find the solution. Here are findings so far: The reason for the 500 error is the NAT configuration in AWS. The AWS NAT Gateway is set to disconnect idle connections after 5 minutes.

[vimal-raz]

@dersteve PCF team suggested to use Spring retry in boot apps and zuul to handle this issue.

https://github.com/spring-projects/spring-retry
https://docs.spring.io/spring-batch/trunk/reference/html/retry.html

[AhmedRiahi]

Hello,

Im encountring the same issue with "Connection Reset" exception, any update please ?
Is it related to zuul ?

Thanks

[manuelgerstner]

We have been investigating this issue on our CloudFoundry architecture a bit more and it seems to be an issue with the Http client and the way connections are kept-alive. The issue appears when using either Apache HTTP Client (default) or OkHttp. It does not appear however, when using the deprecated restclient which was previously used as the default Http client. So this is the current fix for us (please note that the client is officially deprecated and according to some of the developers it was deprecated due to some bugs).

The following short paragraph talks about the three clients https://cloud.spring.io/spring-cloud-netflix/multi/multi__router_and_filter_zuul.html#_zuul_http_client

Another fix that could solve (cover-up) the issue would be to provide a custom Http client which disables connection keep-alive.

@spencergibb mentions that:

RestClient has limitations like not supporting PATCH and other bugs that are fixed with Apache

here: #1125

[tomaszglinski]

Is there something going on about this bug, since we have the same problems...

[manuelgerstner]

@tomaszglinski just out of curiosity, did you try to make use of the RestClient and did it fix the issue for you?

[tcanavan]

The RestClient installs a cleaner for the http connection pool. This cleaner closes connections and removes pool entries which are older than 30 seconds so they will be cleanly closed in time and never become a victim of the AWS 5 minute disconnect of idle connections rule.

The exception we are seeing is the following

	at java.net.SocketInputStream.read(SocketInputStream.java:209)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
	at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
	at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
	at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
	at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
	at org.springframework.cloud.netflix.ribbon.apache.RetryableRibbonLoadBalancingHttpClient$1.doWithRetry(RetryableRibbonLoadBalancingHttpClient.java:94)
	at org.springframework.cloud.netflix.ribbon.apache.RetryableRibbonLoadBalancingHttpClient$1.doWithRetry(RetryableRibbonLoadBalancingHttpClient.java:72)
	at org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:287)
	at org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:164)
	at org.springframework.cloud.netflix.ribbon.apache.RetryableRibbonLoadBalancingHttpClient.executeWithRetry(RetryableRibbonLoadBalancingHttpClient.java:107)
	at org.springframework.cloud.netflix.ribbon.apache.RetryableRibbonLoadBalancingHttpClient.execute(RetryableRibbonLoadBalancingHttpClient.java:72)
	at org.springframework.cloud.netflix.ribbon.apache.RetryableRibbonLoadBalancingHttpClient.execute(RetryableRibbonLoadBalancingHttpClient.java:52)
	at com.netflix.client.AbstractLoadBalancerAwareClient$1.call(AbstractLoadBalancerAwareClient.java:109)

Spring retry is been used but in this case I think it has no real affect as

1. The entry does not seem to be removed from the pool when exception is thrown.

2. If another server gets retried it will also get the same error

There use to be an option to check the validity of the connection every time but this no longer works despite the property still existing. It was deemed to be not performant. The PoolingHttpClientConnectionManager does not seem to be set up for the client thats created in RetryableRibbonLoadBalancingHttpClient which means we cannot use the ValidateAfterInactivity property.