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

Question

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:

Going back to Java 8: this makes the problem disappear
Considering it's a security-software issue: Makes little sense
Checking the Windows Event Log: Nothing conspicuous
Considering it's a timeout issue: that should trigger a SocketTimeoutException, and if it's server-side, it should happen with Java 8 as well, I assume.
Checking the server logs: Nothing
Googling for any known Java 11 related issues that could cause this: I found JDK-8224829 AsyncSSLSocketClose.java has timing issue but this doesn't seem to apply in any way
Considering that the host ran out of available TCP ports or so, but nothing conspicuous:

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.

From the stacktrace it seams you are using Spring RestTemplate to call to your server. Since both Client/Server runs in the same machine, loopback is used. Check if you set some read timeouts in Rest Template. This can help in this point: https://stackoverflow.com/questions/11537591/resttemplate-default-timeout-value. You affirm that you have updated from java 8 to java 11. I think there were some changes related with http be related to the behaviour. Did you update any dependency also? Also is the server taking too long to process requests? Is the system under high load in these occasions? — pringi, Mar 16 '22 at 09:43
Have you tried using the system property `javax.net.debug=all` when running your client? As the connection is secure, it may be help. Your problem may be related with [this issue](https://bugs.openjdk.java.net/browse/JDK-8241216) as well, although it seems fixed in JDK 11.0.8, and you are using a newer version, so probably it won't apply to your problem. — jccampanero, Mar 16 '22 at 23:04
Seems hard to debug. If the error occurs multiple times in a short period of time, maybe you could start Wireshark programmatically when detecting the first failure and shutting down after a second failure or a fixed time window. — Santiago Medina, Mar 18 '22 at 03:57

JohannesB · Answer 1 · 2022-03-19T20:51:24.740

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.

From my reading of the code you linked, it'll go to NET_ThrowCurrent, which will eventually log `Software caused connection abort` which corresponds to `WSAECONNABORTED` — phant0m, Mar 19 '22 at 21:49
Ah yes, you are right, the error is looked up again later, I totally missed that before. — JohannesB, Mar 20 '22 at 07:36
By default the GC Algorithm is changed if you upgrade from Java 8 to 11, based on https://superuser.com/questions/923688/data-retransmission-and-wsaeconnaborted-10053-socket-error#924956 your software may have hit a retry timeout, please make sure that GC performance is adequate by enabling logging and analyzing it with http://gceasy.io - refer to their guidance under: "How to enable Java GC Logging?" — JohannesB, Mar 20 '22 at 08:52

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

1 Answers1