ResourceAccessException: I/O error on POST request for : com.netflix.client.ClientException; IOException

[kmacpher67]

Intermittent in production.
What would cause this?
How best to troubleshoot this?
GIVEN versions:
com.netflix.ribbon\ribbon-core\2.2.0 - ribbon-core-2.2.0.jar
spring-web\4.3.4.RELEASE spring-web-4.3.4.RELEASE.jar
There were no errors on the target server related to this time?

org.springframework.web.client.ResourceAccessException: I/O error on POST request for \"": com.netflix.client.ClientException; nested exception is java.io.IOException: com.netflix.client.ClientException
org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:633)\n\tat 
org.springframework.web.client.RestTemplate.execute(RestTemplate.java:595)\n\tat
 org.springframework.web.client.RestTemplate.postForEntity(RestTemplate.java:423)\n\tat
...

[spencergibb]

I'm afraid you haven't provided enough detail for us to begin to look at this issue. Please provide the versions you are using. Detailed steps to reproduce the problem and, if possible, a project that recreates the problem.

[kmacpher67]

I was editing this issue to create it and it (or stupid me) automagically sent the stuff before I had a chance to clean up and put the goodies in.
This is cloud service and the connections should be pretty stable and fast between the source service to the destination.
java.net.SocketTimeoutException: Read timed out\n\tat java.net.SocketInputStream.socketRead0

rx.observables.BlockingObservable.blockForSingle(BlockingObservable.java:445)\n\tat 
rx.observables.BlockingObservable.single(BlockingObservable.java:342)\n\tat 
com.netflix.client.AbstractLoadBalancerAwareClient.executeWithLoadBalancer(AbstractLoadBalancerAwareClient.java:102)\n\t... 62 more
\nCaused by: java.net.SocketTimeoutException: Read timed out\n\tat 
java.net.SocketInputStream.socketRead0(Native Method)\n\tat 
java.net.SocketInputStream.socketRead(SocketInputStream.java:116)\n\tat 
java.net.SocketInputStream.read(SocketInputStream.java:170)\n\tat java.net.SocketInputStream.read(SocketInputStream.java:141)\n\tat sun.security.ssl.InputRecord.readFully(InputRecord.java:465)\n\tat 
sun.security.ssl.InputRecord.read(InputRecord.java:503)\n\tat 
sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)\n\tat 
sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)\n\tat 
sun.security.ssl.AppInputStream.read(AppInputStream.java:105)\n\tat 
org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:158)\n\tat org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:82)\n\tat org.apache.http.impl.io.AbstractSessionIn

[ryanjbaxter]

Could you provide more of the stack trace?

[kmacpher67]

Here's the entire stack trace:

          "exception": {
            "stackTrace": "org.springframework.web.client.ResourceAccessException: I/O error on POST request for \"https://Prescription-v1-0-Server/api/v1/prescriptions/vent\": com.netflix.client.ClientException; nested exception is java.io.IOException: com.netflix.client.ClientException\n\
 org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:633)\n\
 org.springframework.web.client.RestTemplate.execute(RestTemplate.java:595)\n\
 org.springframework.web.client.RestTemplate.postForEntity(RestTemplate.java:423)\n\
 org.springframework.web.client.RestTemplate$$FastClassBySpringCGLIB$$aa4e9ed0.invoke(<generated>)\n\
 org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)\n\
 org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)\n\
 org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)\n\
 org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)\n\
 org.springframework.web.client.RestTemplate$$EnhancerBySpringCGLIB$$105273c9.postForEntity(<generated>)\n\
 com.company.processdatadomain.persist.rest.IoTPrescriptionDomainClient.send(IoTPrescriptionDomainClient.java:70)\n\
 com.company.processdatadomain.persist.IoTPrescriptionDataPersistor.persistData(IoTPrescriptionDataPersistor.java:53)\n\
 com.company.processdatadomain.persist.IoTPersistor.persist(IoTPersistor.java:36)\n\
 com.company.processdatadomain.route.IOTRoute.run(IOTRoute.java:120)\n\
 com.company.processdatadomain.logic.IoTDataProcessingManager.runRoute(IoTDataProcessingManager.java:137)\n\
 com.company.processdatadomain.logic.IoTDataProcessingManager.process(IoTDataProcessingManager.java:96)\n\
 com.company.processmessaging.UploadMessageHandlerStrategy.handle(IoTCardUploadMessageHandlerStrategy.java:55)\n\
 sun.reflect.GeneratedMethodAccessor470.invoke(Unknown Source)\n\
 sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\
 java.lang.reflect.Method.invoke(Method.java:498)\n\
 org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:269)\n\
 org.springframework.amqp.rabbit.listener.adapter.MessageListenerAdapter.invokeListenerMethod(MessageListenerAdapter.java:387)\n\
 org.springframework.amqp.rabbit.listener.adapter.MessageListenerAdapter.onMessage(MessageListenerAdapter.java:298)\n\
 org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:778)\n\
 org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:701)\n\
 org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.access$001(SimpleMessageListenerContainer.java:99)\n\
 org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$1.invokeListener(SimpleMessageListenerContainer.java:191)\n\
 sun.reflect.GeneratedMethodAccessor130.invoke(Unknown Source)\n\
 sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\
 java.lang.reflect.Method.invoke(Method.java:498)\n\
 org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)\n\
 org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:52)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)\n\
 org.springframework.aop.framework.adapter.ThrowsAdviceInterceptor.invoke(ThrowsAdviceInterceptor.java:125)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)\n\
 org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:52)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)\n\
 org.springframework.retry.interceptor.RetryOperationsInterceptor$1.doWithRetry(RetryOperationsInterceptor.java:74)\n\
 org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:276)\n\
 org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:172)\n\
 org.springframework.retry.interceptor.RetryOperationsInterceptor.invoke(RetryOperationsInterceptor.java:98)\n\
 org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)\n\
 org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)\n\
 com.sun.proxy.$Proxy184.invokeListener(Unknown Source)\n\
 org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.invokeListener(SimpleMessageListenerContainer.java:1213)\n\
 org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.executeListener(AbstractMessageListenerContainer.java:682)\n\
 org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.doReceiveAndExecute(SimpleMessageListenerContainer.java:1191)\n\
 org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.receiveAndExecute(SimpleMessageListenerContainer.java:1175)\n\
 org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.access$1200(SimpleMessageListenerContainer.java:99)\n\
 org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer.run(SimpleMessageListenerContainer.java:1338)\n\
 java.lang.Thread.run(Thread.java:745)\nCaused by: java.io.IOException: com.netflix.client.ClientException\n\
 org.springframework.cloud.netflix.ribbon.RibbonHttpRequest.executeInternal(RibbonHttpRequest.java:88)\n\
 org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)\n\
 org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:93)\n\
 com.company.process.infrastructure.trace.RestTemplateRequestTraceStorageForwardInterceptor.intercept(RestTemplateRequestTraceStorageForwardInterceptor.java:37)\n\
 org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:85)\n\
 org.springframework.http.client.InterceptingClientHttpRequest.executeInternal(InterceptingClientHttpRequest.java:69)\n\
 org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)\n\
 org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)\n\
 org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:619)\n\t... 53 more\nCaused by: com.netflix.client.ClientException\n\
 com.netflix.client.AbstractLoadBalancerAwareClient.executeWithLoadBalancer(AbstractLoadBalancerAwareClient.java:123)\n\
 org.springframework.cloud.netflix.ribbon.RibbonHttpRequest.executeInternal(RibbonHttpRequest.java:85)\n\t... 61 more\nCaused by: com.sun.jersey.api.client.ClientHandlerException: java.net.SocketTimeoutException: Read timed out\n\
 com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:187)\n\
 com.sun.jersey.api.client.Client.handle(Client.java:652)\n\
 com.sun.jersey.api.client.WebResource.handle(WebResource.java:682)\n\
 com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)\n\
 com.sun.jersey.api.client.WebResource$Builder.post(WebResource.java:570)\n\
 com.netflix.niws.client.http.RestClient.execute(RestClient.java:621)\n\
 com.netflix.niws.client.http.RestClient.execute(RestClient.java:527)\n\
 com.netflix.niws.client.http.RestClient.execute(RestClient.java:92)\n\
 com.netflix.client.AbstractLoadBalancerAwareClient$1.call(AbstractLoadBalancerAwareClient.java:109)\n\
 com.netflix.loadbalancer.reactive.LoadBalancerCommand$3$1.call(LoadBalancerCommand.java:303)\n\
 com.netflix.loadbalancer.reactive.LoadBalancerCommand$3$1.call(LoadBalancerCommand.java:287)\n\
 rx.internal.util.ScalarSynchronousObservable$3.call(ScalarSynchronousObservable.java:231)\n\
 rx.internal.util.ScalarSynchronousObservable$3.call(ScalarSynchronousObservable.java:228)\n\
 rx.Observable.unsafeSubscribe(Observable.java:10211)\n\
 rx.internal.operators.OnSubscribeConcatMap$ConcatMapSubscriber.drain(OnSubscribeConcatMap.java:286)\n\
 rx.internal.operators.OnSubscribeConcatMap$ConcatMapSubscriber.onNext(OnSubscribeConcatMap.java:144)\n\
 com.netflix.loadbalancer.reactive.LoadBalancerCommand$1.call(LoadBalancerCommand.java:185)\n\
 com.netflix.loadbalancer.reactive.LoadBalancerCommand$1.call(LoadBalancerCommand.java:180)\n\
 rx.Observable.unsafeSubscribe(Observable.java:10211)\n\
 rx.internal.operators.OnSubscribeConcatMap.call(OnSubscribeConcatMap.java:94)\n\
 rx.internal.operators.OnSubscribeConcatMap.call(OnSubscribeConcatMap.java:42)\n\
 rx.Observable.unsafeSubscribe(Observable.java:10211)\n\
 rx.internal.operators.OperatorRetryWithPredicate$SourceSubscriber$1.call(OperatorRetryWithPredicate.java:127)\n\
 rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.enqueue(TrampolineScheduler.java:73)\n\
 rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.schedule(TrampolineScheduler.java:52)\n\
 rx.internal.operators.OperatorRetryWithPredicate$SourceSubscriber.onNext(OperatorRetryWithPredicate.java:79)\n\
 rx.internal.operators.OperatorRetryWithPredicate$SourceSubscriber.onNext(OperatorRetryWithPredicate.java:45)\n\
 rx.internal.util.ScalarSynchronousObservable$WeakSingleProducer.request(ScalarSynchronousObservable.java:276)\n\
 rx.Subscriber.setProducer(Subscriber.java:209)\n\
 rx.internal.util.ScalarSynchronousObservable$JustOnSubscribe.call(ScalarSynchronousObservable.java:138)\n\
 rx.internal.util.ScalarSynchronousObservable$JustOnSubscribe.call(ScalarSynchronousObservable.java:129)\n\
 rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)\n\
 rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)\n\
 rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)\n\
 rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)\n\
 rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)\n\
 rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)\n\
 rx.Observable.subscribe(Observable.java:10307)\n\
 rx.Observable.subscribe(Observable.java:10274)\n\
 rx.observables.BlockingObservable.blockForSingle(BlockingObservable.java:445)\n\
 rx.observables.BlockingObservable.single(BlockingObservable.java:342)\n\
 com.netflix.client.AbstractLoadBalancerAwareClient.executeWithLoadBalancer(AbstractLoadBalancerAwareClient.java:102)\n\t... 62 more\nCaused by: java.net.SocketTimeoutException: Read timed out\n\
 java.net.SocketInputStream.socketRead0(Native Method)\n\
 java.net.SocketInputStream.socketRead(SocketInputStream.java:116)\n\
 java.net.SocketInputStream.read(SocketInputStream.java:170)\n\
 java.net.SocketInputStream.read(SocketInputStream.java:141)\n\
 sun.security.ssl.InputRecord.readFully(InputRecord.java:465)\n\
 sun.security.ssl.InputRecord.read(InputRecord.java:503)\n\
 sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)\n\
 sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)\n\
 sun.security.ssl.AppInputStream.read(AppInputStream.java:105)\n\
 org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:158)\n\
 org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:82)\n\
 org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:271)\n\
 org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)\n\
 org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)\n\
 org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)\n\
 org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:281)\n\
 org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:259)\n\
 org.apache.http.impl.conn.AbstractClientConnAdapter.receiveResponseHeader(AbstractClientConnAdapter.java:232)\n\
 org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)\n\
 org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)\n\
 org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:686)\n\
 org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:488)\n\
 org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:884)\n\
 org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:117)\n\
 org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)\n\
 com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:173)\n\t... 103 more\n",
            "exceptionMessage": "I/O error on POST request for \"https://Prescription-v1-0-Server/api/v1/prescriptions/vent\": com.netflix.client.ClientException; nested exception is java.io.IOException: com.netflix.client.ClientException"
          }```

[kmacpher67]

A RestTemplate.doExecute() on Source Service A --POSTS--> Dest Service B
the application key = Dest-Service-B is stored in Eureka which should respond with a valid service URL.
I believe the lookup to the Eureka Service is a via another RestTemplate.doExecute()...
Could this be the Eureka Service call that's failing instead of the target Dest Service B?
This fact is getting lost in the magical cross cut/aop/ interceptor abstraction?
Is there a way to tell from the full stack trace what is causing this?
The exception seems to be originating from:
https://github.com/Netflix/ribbon/blob/v2.2.0/ribbon-loadbalancer/src/main/java/com/netflix/loadbalancer/reactive/LoadBalancerCommand.java

We are using:
spring-cloud-netflix-core-1.2.1.RELEASE.jar
Here's where the exception is being thrown: Line 88
https://github.com/spring-cloud/spring-cloud-netflix/blob/v1.2.1.RELEASE/spring-cloud-netflix-core/src/main/java/org/springframework/cloud/netflix/ribbon/RibbonHttpRequest.java#L88

spring-boot 1.4.2.RELEASE
spring-cloud-starter-1.1.4.RELEASE.jar

[kmacpher67]

Searching all the logs for the last 30 days shows 12 events for "java.io.IOException" one of the microservices caught it as "EurekaClientException" I need to investigate this more.
it would be helpful if from the stack trace above, somebody could confirm that this is the Internal call of Netflix client to Eureka to find the local URL of the target Destination host key.

[kmacpher67]

I think I Found it. It was NOT EUREKA and NOT an error on the target, just long response duration.
The TargetServiceB was taking more than 5 seconds to respond.
What is the default value, this doc https://github.com/Netflix/ribbon/wiki/Getting-Started suggests that it's 3 seconds for connection plus read, mine failed closer to 5secs.
Now the new question, what to set it to? What's the experience?

Too long will cause other headaches.

# Connect timeout used by Apache HttpClient
sample-client.ribbon.ConnectTimeout=3000

# Read timeout used by Apache HttpClient
sample-client.ribbon.ReadTimeout=3000

Asked and answered my own question.
Ahh ... the default values are found in: com.netflix.client.config.DefaultClientConfigImpl

    public static final int DEFAULT_CONNECTION_MANAGER_TIMEOUT = 2000;

    public static final int DEFAULT_CONNECT_TIMEOUT = 2000;

When the duration was > 5.03 seconds, these failed.

Duration
-----------
18.51411 ***<<< yeah yeah, fix this crap. 
8.236684
7.36841
7.192015
6.187874
5.836101
5.538787
5.308778 - threw exception on client serviceA
5.289811 - threw exception on client serviceA
5.033251 - worked. ??? close enough for govt work? lol.
4.812843 - worked.

Think there is any significant problem setting this to 9secs? Thinking out loud, socket connects starts reading ... ... wait ... the remote destination server service is dead or dying, next thing you know you got these sockets hanging out there...
This means only 1 failed transaction in the last 30 days.
_(ツ)_/¯
Thanks for listening, if you don't want to answer the empirical questions that's ok, you can close this.
Answer is likely NOT to blame Eureka, that's cached for so many seconds, and it's stupid simple service get key/value pairs?
BTW, whilst I'm thinking about it, Is that this setting here?

# Interval to refresh the server list from the source
sample-client.ribbon.ServerListRefreshInterval=2000

[spencergibb]

That looks right. Can we close this?

[teeeestyle]

How can I enable http2 flow control logs in spring boot proxy with okHttp3client and undertow serverlet? Is it possible? I need to print it like this.

https://medium.com/coderscorner/http-2-flow-control-77e54f7fd518 (figure1 and 2)

[spencergibb]

@teeeestyle commenting on a closed somewhat related issue is not the way to go. That said, zuul 1 will not support http2

[teeeestyle]

@teeeestyle commenting on a closed somewhat related issue is not the way to go. That said, zuul 1 will not support http2

Sorry. But it was urgent. What's zuul?

[spencergibb]

you said

spring boot proxy

There is no such project, only spring-cloud-netflix via zuul which is no longer supported and spring cloud gateway which doesn't use okhttp.

[teeeestyle]

you said

spring boot proxy

There is no such project, only spring-cloud-netflix via zuul which is no longer supported and spring cloud gateway which doesn't use okhttp.

But Is there any way in spring boot application to print http2 flow control logs?

[spencergibb]

Not sure. The boot team requests that questions for spring boot be asked here https://stackoverflow.com/questions/tagged/spring-boot

[teeeestyle]

Not sure. The boot team requests that questions for spring boot be asked here https://stackoverflow.com/questions/tagged/spring-boot

Thank you

[13249789071]

@kmacpher67 Excuse me, has the problem been solved?

[svpmirashi]

I recently resolved "I/O error on POST..." error in my project.

This issue I received was due to CORS configuration on the target REST API project.
I could resolve it by adding the allowed origin in the target project.

configuration.addAllowedOriginPattern("/**");
OR
you can add a specific source origin from which you are making the REST API call.