Michel Jung
Michel Jung

Reputation: 3276

How can I debug "Software caused connection abort: recv failed" on Windows and Java 11?

I have a Spring application that communicates with an HTTP endpoint. Since we updated from Java 8 to Java 11 (jdk-11.0.10+9-jre, running on Windows Server 2016), we get the following exception 2-3 times a week:

org.springframework.web.client.ResourceAccessException: I/O error on GET request for "https://.../api/v1/...": Software caused connection abort: recv failed; nested exception is javax.net.ssl.SSLException: Software caused connection abort: recv failed
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:743) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:669) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:578) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at com.example.http.SpringRequestExecutor.tryRequest(SpringRequestExecutor.java:72) ~[Tm1Rest-6.9.0.jar:6.9.0]
    at [...]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(Unknown Source) [?:?]
    at java.util.concurrent.CompletableFuture$AsyncSupply.exec(Unknown Source) [?:?]
    at java.util.concurrent.ForkJoinTask.doExec(Unknown Source) [?:?]
    at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(Unknown Source) [?:?]
    at java.util.concurrent.ForkJoinPool.scan(Unknown Source) [?:?]
    at java.util.concurrent.ForkJoinPool.runWorker(Unknown Source) [?:?]
    at java.util.concurrent.ForkJoinWorkerThread.run(Unknown Source) [?:?]
Caused by: javax.net.ssl.SSLException: Software caused connection abort: recv failed
    at sun.security.ssl.Alert.createSSLException(Unknown Source) ~[?:?]
    at sun.security.ssl.TransportContext.fatal(Unknown Source) ~[?:?]
    at sun.security.ssl.TransportContext.fatal(Unknown Source) ~[?:?]
    at sun.security.ssl.TransportContext.fatal(Unknown Source) ~[?:?]
    at sun.security.ssl.SSLSocketImpl.handleException(Unknown Source) ~[?:?]
    at sun.security.ssl.SSLSocketImpl$AppInputStream.read(Unknown Source) ~[?:?]
    at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.6.jar:4.5.6]
    at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:87) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:108) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at [...]
    at org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:92) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.InterceptingClientHttpRequest.executeInternal(InterceptingClientHttpRequest.java:76) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:734) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    ... 21 more
    Suppressed: java.net.SocketException: Software caused connection abort: socket write error
        at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:?]
        at java.net.SocketOutputStream.socketWrite(Unknown Source) ~[?:?]
        at java.net.SocketOutputStream.write(Unknown Source) ~[?:?]
        at sun.security.ssl.SSLSocketOutputRecord.encodeAlert(Unknown Source) ~[?:?]
        at sun.security.ssl.TransportContext.fatal(Unknown Source) ~[?:?]
        at sun.security.ssl.TransportContext.fatal(Unknown Source) ~[?:?]
        at sun.security.ssl.TransportContext.fatal(Unknown Source) ~[?:?]
        at sun.security.ssl.SSLSocketImpl.handleException(Unknown Source) ~[?:?]
        at sun.security.ssl.SSLSocketImpl$AppInputStream.read(Unknown Source) ~[?:?]
        at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137) ~[httpcore-4.4.10.jar:4.4.10]
        at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153) ~[httpcore-4.4.10.jar:4.4.10]
        at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282) ~[httpcore-4.4.10.jar:4.4.10]
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259) ~[httpcore-4.4.10.jar:4.4.10]
        at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163) ~[httpcore-4.4.10.jar:4.4.10]
        at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273) ~[httpcore-4.4.10.jar:4.4.10]
        at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125) ~[httpcore-4.4.10.jar:4.4.10]
        at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.6.jar:4.5.6]
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.6.jar:4.5.6]
        at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:87) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:108) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at [...]
        at org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:92) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.http.client.InterceptingClientHttpRequest.executeInternal(InterceptingClientHttpRequest.java:76) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:734) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:669) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:578) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
        at [...]
        at java.util.concurrent.CompletableFuture$AsyncSupply.run(Unknown Source) [?:?]
        at java.util.concurrent.CompletableFuture$AsyncSupply.exec(Unknown Source) [?:?]
        at java.util.concurrent.ForkJoinTask.doExec(Unknown Source) [?:?]
        at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(Unknown Source) [?:?]
        at java.util.concurrent.ForkJoinPool.scan(Unknown Source) [?:?]
        at java.util.concurrent.ForkJoinPool.runWorker(Unknown Source) [?:?]
        at java.util.concurrent.ForkJoinWorkerThread.run(Unknown Source) [?:?]
Caused by: java.net.SocketException: Software caused connection abort: recv failed
    at java.net.SocketInputStream.socketRead0(Native Method) ~[?:?]
    at java.net.SocketInputStream.socketRead(Unknown Source) ~[?:?]
    at java.net.SocketInputStream.read(Unknown Source) ~[?:?]
    at java.net.SocketInputStream.read(Unknown Source) ~[?:?]
    at sun.security.ssl.SSLSocketInputRecord.read(Unknown Source) ~[?:?]
    at sun.security.ssl.SSLSocketInputRecord.readHeader(Unknown Source) ~[?:?]
    at sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(Unknown Source) ~[?:?]
    at sun.security.ssl.SSLSocketImpl.readApplicationRecord(Unknown Source) ~[?:?]
    at sun.security.ssl.SSLSocketImpl$AppInputStream.read(Unknown Source) ~[?:?]
    at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125) ~[httpcore-4.4.10.jar:4.4.10]
    at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.6.jar:4.5.6]
    at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.6.jar:4.5.6]
    at org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:87) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:108) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at [...]
    at org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:92) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.InterceptingClientHttpRequest.executeInternal(InterceptingClientHttpRequest.java:76) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:734) ~[spring-web-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    ... 21 more

Sometimes, the exception occurs during a few seconds and then everything is back to normal.

I am familiar with this exception and know (I hope) that it occurs when a TCP connection is closed unexpectedly. So the question I need to answer is: Who closed the connection and why?

We tried:

How would you go about debugging this? The only idea I have is using Wireshark to analyze the TCP stream but since it happens so rarely and unpredictably I'd have to capture a huge amount of traffic which would probably crash the system.

Also it needs to be noted that client and server run on the same server.

Upvotes: 3

Views: 2963

Answers (1)

JohannesB
JohannesB

Reputation: 2288

As the question is:

How would you go about debugging this?

I'd probably make sure that the logging for the exact error message was added, as currently only the most frequently have been implemented, but in all other cases you do not get the native cause:

https://github.com/openjdk/jdk/blob/jdk-11%2B28/src/java.base/windows/native/libnet/SocketInputStream.c#L152

See the Microsoft documentation for an example that includes the error number (In my opinion at least the Java fastdebug builds should have an option to print or log this, though it makes the code more complex):

https://learn.microsoft.com/en-us/windows/win32/api/winsock2/nf-winsock2-recv

Maybe there was not enough memory or any of the other possible error causes, but without Java logging / throwing it, it is impossible to tell which one:

https://learn.microsoft.com/en-us/windows/win32/winsock/windows-sockets-error-codes-2

Getting this right seems quite hard, given the number of bug reports, e.g.:

https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8249590

Why this would occur on Java 11 instead of 8 is another interesting question, I'd start guessing that it might have to do with using a different TLS version (1.2 / 1.3, or different parameters), as I take it from the stacktrace you use the exact same http library that does not yet support HTTP/2.

Given that everyone's time is limited I would probably try to work around this by using some retry-mechanism, or switching to plain http instead of https if this traffic is between 2 processes running inside the same machine, though I (too?) sometimes have a hard time to say: "No" to an interesting puzzle.

P.S.: Make sure you do not use different threads to read / write concurrently to the same socket, like here: Got "Unrecognized Windows Sockets error: 0: recv failed" while posting message

P.P.S.: For the sake of argument Wireshark ( npcap ) allows (through the jitting of BPF VM code) efficient capture of just relevant network traffic for TCP packets flags like: fin or rst and maybe: syn if you really want it, see: https://serverfault.com/questions/217605/how-to-capture-ack-or-syn-packets-by-tcpdump#217618 though it cannot tell you what happened immediately before, that would indeed require capturing all traffic and auto switching capture files regularly, which it also can, to remove old capture files that are no longer relevant, e.g. when no incident has occurred.

Upvotes: 1

Related Questions