ADDITIONAL SYSTEM INFORMATION :
Reproduced from Windows 7
but also occurs on linux servers
Reproduced with :
- Oracle JDK 1.8.0_172
- OpenJDK 10.0.2
A DESCRIPTION OF THE PROBLEM :
When a HttpsURLConnection reuses a sun.net.www.protocol.https.HttpsClient that client may be associated to a close TCP connection (from a server timeout probably) :
If the server just closes the TCP Connection, writing to HttpsURLConnection.getOutputStream correctly detects that the httpsclient is unusable (there is "java.net.SocketException: Software caused connection abort: socket write error" reported by JDK debug logs) and the JDK recreates a client to effectively send the request
But if the server first sends a "close_notify" TLS Alert before it closes the TCP Connection : writing to HttpsURLConnection.getOutputStream actually results in network packets sent on the network.
The JDK only finds that the connection is closed when the inputstream is retrieved and it reads the "close_notify" TLS Record (in sun.net.www.http.HttpClient#parseHTTPHeader specifically)
( After that sun.net.www.http.HttpClient#parseHTTPHeader DO try to recreate and resend the request : but there is another bug here, that I will fill just after this one )
The JDK should be able to detect this case and not trying to use a close connection
Note : In my case, the connection is made through a proxy : that why the HttpsClient is keep in cache during 60s (and not the default 5s otherwise) before the KeepAliveCache can clean it.
And the service I call close the TLS connection after 30s
STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
- Set up a server which timeouts TLS connection after 30s, by sending a close_notify alert
(Unfortunately, I don't know how to do that. For example, NGINX timeouts directly with a FIN,ACK TCP packet in my tests )
- Set up a forward proxy usable for calling the previous server
(Or make the previous server respond with a header "Keep-Alive: max=60")
- enable TLS debug mode (-Djavax.net.debug=all) AND jdk logs on sun.net.www.*
- make a call with HttpsURLConnection that do cache the connection (enabling keep-alive and consuming all the inputstream)
- wait 35 seconds
- make the same call again
EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
During the second http call :
see in the log, that the JDK get an error early when writing the request to the SSLSocket
like this :
main, WRITE: TLSv1.2 Application Data, length = 180
main, handling exception: java.net.SocketException: Software caused connection abort: socket write error
%% Invalidated: [Session-1, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384]
main, SEND TLSv1.2 ALERT: fatal, description = unexpected_message
Padded plaintext before ENCRYPTION: len = 2
0000: 02 0A ..
main, WRITE: TLSv1.2 Alert, length = 26
main, Exception sending alert: java.net.SocketException: Software caused connection abort: socket write error
main, called closeSocket()
main, called close()
main, called closeInternal(true)
The JDK should then recreate a new HttpsClient to actually make the request
ACTUAL -
During the second http call :
see in the log, that the JDK get an error only after it read the close_notify alert :
main, WRITE: TLSv1.2 Application Data, length = 89
[Raw write]: length = 94
0000: 17 03 03 00 59 00 00 00 00 00 00 00 04 C4 05 CD ....Y...........
0010: 81 C3 E2 75 91 E3 71 C4 50 42 CD 45 D9 37 DC 7C ...u..q.PB.E.7..
0020: 1C 1A 55 71 47 EC 25 C2 C0 37 6E 60 0F 65 F1 45 ..UqG.%..7n`.e.E
0030: D9 92 A3 77 8B 18 4C 7D 19 22 94 96 A9 93 F5 4D ...w..L..".....M
0040: 76 E8 7E A7 BB E4 02 DA A8 E1 E5 B8 18 4B 21 F0 v............K!.
0050: BF 6B BF 54 18 EC 92 8C F7 AA 3F CF 67 88 .k.T......?.g.
[Raw read]: length = 5
0000: 15 03 03 00 1A .....
[Raw read]: length = 26
0000: 59 72 16 49 DD 18 CF 0C 82 BC 1D 55 94 83 B6 3A Yr.I.......U...:
0010: 5C FB 63 47 00 F1 4B 8D 76 62 \.cG..K.vb
main, READ: TLSv1.2 Alert, length = 26
Padded plaintext after DECRYPTION: len = 2
0000: 01 00 ..
main, RECV TLSv1.2 ALERT: warning, close_notify
main, called closeInternal(false)
main, SEND TLSv1.2 ALERT: warning, description = close_notify
Padded plaintext before ENCRYPTION: len = 2
0000: 01 00 ..
main, WRITE: TLSv1.2 Alert, length = 26
[Raw write]: length = 31
0000: 15 03 03 00 1A 00 00 00 00 00 00 00 05 A4 F4 22 ..............."
0010: 32 9E 3C 9E 74 62 3F 71 AF 9F 61 AC 55 9C A0 2.<.tb?q..a.U..
main, called closeSocket(false)
main, called close()
main, called closeInternal(true)
août 03, 2018 6:49:26 PM sun.net.www.protocol.http.HttpURLConnection sendCONNECTRequest
PRÃCIS: sun.net.www.MessageHeader@14fc5f045 pairs: {CONNECT xxxxx:443 HTTP/1.1: null}{User-Agent: Java/1.8.0_172}{Host: api.orange.com}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Proxy-Connection: keep-alive}
août 03, 2018 6:49:26 PM sun.net.www.protocol.http.HttpURLConnection doTunneling
PRÃCIS: sun.net.www.MessageHeader@6e2829c71 pairs: {null: HTTP/1.1 200 Connection established}
Allow unsafe renegotiation: false
Allow legacy hello messages: true
Is initial handshake: true
Is secure renegotiation: false
We saw above, that the JDK is trying to make a retry by opening a new connection to the proxy (sendCONNECTRequest and doTunneling)
---------- BEGIN SOURCE ----------
package testcase;
import org.apache.commons.io.IOUtils;
import org.junit.Test;
import javax.net.ssl.HttpsURLConnection;
import java.io.InputStream;
import java.io.OutputStream;
import java.net.InetSocketAddress;
import java.net.Proxy;
import java.net.SocketAddress;
import java.net.URL;
import java.nio.charset.StandardCharsets;
public class TestCaseHttpsURLConnection {
@Test
public void testCaseMethod() throws Exception {
URL url = new URL( "https://some.tls.server/xxx/yyy");
SocketAddress sa = new InetSocketAddress("some.corporate.proxy",8080);
Proxy proxy = new Proxy(Proxy.Type.HTTP,sa);
int nb = 0;
while(++nb <= 2) {
try {
System.out.println("*********** REQUEST n° " + nb + " ******************");
HttpsURLConnection urlConnection = (HttpsURLConnection) url.openConnection(proxy);
urlConnection.setConnectTimeout(1000);
urlConnection.setReadTimeout(15000);
urlConnection.setDoInput(true);
urlConnection.setDoOutput(true);
urlConnection.setRequestMethod("POST");
urlConnection.setUseCaches(false);
urlConnection.setRequestProperty( "Content-Type", "application/x-www-form-urlencoded");
urlConnection.setRequestProperty( "charset", "utf-8");
urlConnection.setRequestProperty("Authorization", "Basic xxxxxxxxxx==");
urlConnection.setRequestProperty("Connection", "keep-alive");
String urlParameters = "param1=a¶m2=b¶m3=c";
byte[] postData = urlParameters.getBytes( StandardCharsets.UTF_8 );
OutputStream outputStream = urlConnection.getOutputStream();
outputStream.write(postData);
outputStream.close();
int responseCode = urlConnection.getResponseCode();
System.out.printf("UrlConnection - ResponseCode : %s%n",responseCode);
String output;
InputStream inputStream;
if(responseCode < 400) {
inputStream = urlConnection.getInputStream();
} else {
inputStream = urlConnection.getErrorStream();
}
output = IOUtils.toString(inputStream); // consumint the inputstream is also important to make the httpsclient cacheable
inputStream.close(); // Important to make the client httpscacheable
// urlConnection.disconnect(); // NO ...
System.out.printf("Response body : %s%n",output);
} finally {
try {
Thread.sleep(35000);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
}
}
---------- END SOURCE ----------
CUSTOMER SUBMITTED WORKAROUND :
Disable keep alive...
FREQUENCY : always