We are noticing a number of random failures on the spring cloud services that we created trying to connect to the discovery server. They seem to happen every now and then and so far have not caused discovery to fail.
However, our operations group is reporting this to us as a possible issue and we are trying to investigate. Is there any condition that we should be concerned about?
I was able to replicate the same issue running on my laptop with the service and discovery server (eureka) on the same machine, so networking as a cause seems to be not the issue.
We are running with spring boot 1.2.5 as the parent and using Angel.SR3 for the version of spring cloud.
015-08-10 10:41:51.592 INFO 9897 --- [pool-8-thread-1] o.a.http.impl.client.DefaultHttpClient : I/O exception (org.apache.http.NoHttpResponseException) caught when processing request to {}->http://localhost:8761: The target server failed to respond 2015-08-10 10:41:51.593 INFO 9897 --- [pool-8-thread-1] o.a.http.impl.client.DefaultHttpClient : Retrying request to {}->http://localhost:8761
Comment From: ljramones
Anything? I have thousands of these log messages showing up in the logs each week. We run 30+ services and there are errors from each with this.
I noticed that someone else is seeing this as well on stack overflow: http://stackoverflow.com/questions/31503610/spring-cloud-enabling-ssl-for-zuul-and-eureka I am not using SSL but see the same error on connecting to eureka. Its spurious but annoying because of the logging it creates
Comment From: spencergibb
is eureka running on localhost:8761?
Comment From: ljramones
in my local test to try repeats it it was running on local host. In our production instances, the caught while processing request to {} was point in to the remote instance of eureka. When I run it long enough i see this error on my laptop running everything on my laptop
Comment From: spencergibb
So these are logged as INFO. In other cases I've turned httpclients logging up to WARN. Thoughts?
Comment From: ljramones
Sorry to be so late in responding. I lost track of this. Warn would probably be fine since it seems like there is no real fix for this. We came to the reasoning that it was spurious and annoying but other than filling our logs, not a real issue.
When we did some more analysis on this we discovered that the socket close after 30 seconds of inactivity and then there is an attempt to send a request to discovery and that fails because the socket has closed
Here is some more info based on some tcpdumps
I did a tcpdump of traffic to/from 192.168.20.38 on ppvservice02-x1-core-qa. The log shows these errors:
2015-11-09 15:28:06.476 INFO 26714 --- [pool-11-thread-1] o.a.http.impl.client.DefaultHttpClient : I/O exception (org.apache.http.NoHttpResponseException) caught when processing request to {}->http://192.168.20.38:8761: The target server failed to respond
2015-11-09 15:28:06.476 INFO 26714 --- [pool-11-thread-1] o.a.http.impl.client.DefaultHttpClient : Retrying request to {}->http://192.168.20.38:8761
2015-11-09 15:31:36.515 INFO 26714 --- [pool-11-thread-1] o.a.http.impl.client.DefaultHttpClient : I/O exception (org.apache.http.NoHttpResponseException) caught when processing request to {}->http://192.168.20.38:8761: The target server failed to respond
2015-11-09 15:31:36.515 INFO 26714 --- [pool-11-thread-1] o.a.http.impl.client.DefaultHttpClient : Retrying request to {}->http://192.168.20.38:8761
The tcpdump is interesting for that timeframe. For 15:28:06, you see traffic to 192.168.20.38 on two ports, but the connections are closed by 192.168.20.38 immediately after (without responding).
15:28:06.47609`2 IP ppvservice02-x1-core-qa.40615 > host-192-168-20-38.cisco.com.8761: Flags [P.], seq 291:636, ack 732, win 126, options [nop,nop,TS val 3308937327 ecr 3308643723], length 345
PUT /eureka/apps/PPVSERVICE/192.168.20.15?status=UP&lastDirtyTimestamp=1446831737639 HTTP/1.1
DiscoveryIdentity-Name: DefaultClient
DiscoveryIdentity-Version: 1.0
DiscoveryIdentity-Id: 192.168.20.15
Accept-Encoding: gzip
Content-Length: 0
Host: 192.168.20.38:8761
Connection: Keep-Alive
User-Agent: Apache-HttpClient/4.3.6 (java 1.5)
15:28:06.476322 IP host-192-168-20-38.cisco.com.8761 > ppvservice02-x1-core-qa.40615: Flags [F.], seq 732, ack 291, win 122, options [nop,nop,TS val 3308673726 ecr 3308907324], length 0
15:28:06.476999 IP ppvservice02-x1-core-qa.40615 > host-192-168-20-38.cisco.com.8761: Flags [F.], seq 636, ack 733, win 126, options [nop,nop,TS val 3308937328 ecr 3308673726], length 0
15:28:06.477336 IP host-192-168-20-38.cisco.com.8761 > ppvservice02-x1-core-qa.40615: Flags [.], ack 637, win 130, options [nop,nop,TS val 3308673728 ecr 3308937327], length 0
AND
15:28:06.476075 IP ppvservice02-x1-core-qa.40614 > host-192-168-20-38.cisco.com.8761: Flags [P.], seq 346:636, ack 155, win 123, options [nop,nop,TS val 3308937327 ecr 3308643724], length 290
E..V.d@.@..........&.."9;.{..#.....{.......
.:`o.5..GET /eureka/apps/delta HTTP/1.1
Accept: application/json
DiscoveryIdentity-Name: DefaultClient
DiscoveryIdentity-Version: 1.0
DiscoveryIdentity-Id: 192.168.20.15
Accept-Encoding: gzip
Host: 192.168.20.38:8761
Connection: Keep-Alive
User-Agent: Apache-HttpClient/4.3.6 (java 1.5)
15:28:06.476579 IP host-192-168-20-38.cisco.com.8761 > ppvservice02-x1-core-qa.40614: Flags [F.], seq 155, ack 346, win 122, options [nop,nop,TS val 3308673727 ecr 3308907325], length 0
15:28:06.476643 IP ppvservice02-x1-core-qa.40614 > host-192-168-20-38.cisco.com.8761: Flags [F.], seq 636, ack 156, win 123, options [nop,nop,TS val 3308937328 ecr 3308673727], length 0
15:28:06.477258 IP host-192-168-20-38.cisco.com.8761 > ppvservice02-x1-core-qa.40614: Flags [.], ack 637, win 130, options [nop,nop,TS val 3308673728 ecr 3308937327], length 0
For 15:31:36, you see 192.168.20.38 closing the connection simultaneously with ppvservice02-x1-core-qa trying to send traffic to the same port:
15:31:36.515241 IP host-192-168-20-38.cisco.com.8761 > ppvservice02-x1-core-qa.40722: Flags [F.], seq 155, ack 346, win 122, options [nop,nop,TS val 3308883765 ecr 3309117366], length 0
15:31:36.515241 IP ppvservice02-x1-core-qa.40722 > host-192-168-20-38.cisco.com.8761: Flags [P.], seq 346:636, ack 155, win 123, options [nop,nop,TS val 3309147366 ecr 3308853765], length 290
GET /eureka/apps/delta HTTP/1.1
Accept: application/json
DiscoveryIdentity-Name: DefaultClient
DiscoveryIdentity-Version: 1.0
DiscoveryIdentity-Id: 192.168.20.15
Accept-Encoding: gzip
Host: 192.168.20.38:8761
Connection: Keep-Alive
User-Agent: Apache-HttpClient/4.3.6 (java 1.5)
15:31:36.515332 IP ppvservice02-x1-core-qa.40722 > host-192-168-20-38.cisco.com.8761: Flags [F.], seq 636, ack 156, win 123, options [nop,nop,TS val 3309147367 ecr 3308883765], length 0
15:31:36.515835 IP host-192-168-20-38.cisco.com.8761 > ppvservice02-x1-core-qa.40722: Flags [.], ack 637, win 130, options [nop,nop,TS val 3308883766 ecr 3309147366], length 0
Comment From: bakomchik
Hi, @EvilJinious1 . I'm facing with same problem, Did you found any solutions?
Comment From: n0rtan
The same problem in 2020, guys
Comment From: menelaosbgr
Same problem in 2022... seems to not really be breaking anything. Just random errors...and funny thing is that it's on localhost.
Comment From: navinharee
Facing the same issue in 2024. Did anyone find any solution/workaround for this ?