The driver could not establish a secure connection to SQL Server by using Secure Sockets Layer (SSL) encryption. Error: "Unexpected rethrowing".

[martinm1000]

Driver version

mssql-jdbc-7.1.2.jre11
mssql-jdbc-7.0.0.jre10 ( i think I got the problem with this one too)

Problem / Question

I've been refactoring my database connection code, and I probably have a new non-oblivious problem since but I need some pointers on what is going on in the mssql driver.

I seem to have random problems creating SQL connections that otherwise would work ok. I get the following stacktraces while connecting to a NON-ENCRYPTED sql server 2017 database.

Can someone explain the TDS Prelogin negociations vs SSL vs any other encryption scheme that might explain why I get this exception sometimes ? Or is this wrong exception message ? Is there some SSL going on to login even if we don't have encrption setup on the sql server side ?

com.microsoft.sqlserver.jdbc.SQLServerException: The driver could not establish a secure connection to SQL Server by using Secure Sockets Layer (SSL) encryption. Error: "Unexpected rethrowing".
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:2826)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.TDSChannel.enableSSL(IOBuffer.java:1829)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:2391)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:2042)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:1889)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1120)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:700)
        at java.sql/java.sql.DriverManager.getConnection(Unknown Source)

Caused by: javax.net.ssl.SSLProtocolException: Unexpected rethrowing
        at java.base/sun.security.ssl.Alert.createSSLException(Unknown Source)
        at java.base/sun.security.ssl.TransportContext.fatal(Unknown Source)
        at java.base/sun.security.ssl.TransportContext.fatal(Unknown Source)
        at java.base/sun.security.ssl.TransportContext.fatal(Unknown Source)
        at java.base/sun.security.ssl.SSLTransport.decode(Unknown Source)
        at java.base/sun.security.ssl.SSLSocketImpl.decode(Unknown Source)
        at java.base/sun.security.ssl.SSLSocketImpl.readHandshakeRecord(Unknown Source)
        at java.base/sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.TDSChannel.enableSSL(IOBuffer.java:1756)
        ... 41 more
Caused by: java.io.IOException: SQL Server returned an incomplete response. The connection has been closed. ClientConnectionId:b9ef7c65-28e5-4858-9cc1-642eaa2725d1
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.TDSChannel$SSLHandshakeInputStream.ensureSSLPayload(IOBuffer.java:786)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.TDSChannel$SSLHandshakeInputStream.readInternal(IOBuffer.java:836)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.TDSChannel$SSLHandshakeInputStream.read(IOBuffer.java:829)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.readInternal(IOBuffer.java:999)
        at com.microsoft.sqlserver.jdbc@7.1.2.jre11-preview/com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.read(IOBuffer.java:989)
        at java.base/sun.security.ssl.SSLSocketInputRecord.read(Unknown Source)
        at java.base/sun.security.ssl.SSLSocketInputRecord.decode(Unknown Source)
        ... 46 more

[peterbae]

Hi @martinm1000, could you share your connection string that you're using to produce this error?

[martinm1000]

@peterbae Its the most simple one:

jdbc:sqlserver://WKS-DEV-23;encrypt=false;user=user;password=xxxxxx;applicationName=xxx;databaseName=XXXXX

by rapidly reloading data in my app I just got the exception again (even with encrypt=false which I just added).

[martinm1000]

I can confirm I also can get this exception using mssql-jdbc-7.0.0.jre10.

[martinm1000]

I think I'll try to write a small test class that could reproduce it.

I'm having a hard time reproducing it, but right now by best way to do it is by running my app from a java 11 runtime image with everything on the module path. Not sure if this is really a factor or not. I need to quickly reload stuff in my app to trigger new sql connection in a quick succession and then I might get the exception.

[martinm1000]

ssllog.txt

I'm attaching a text log of reproducing the problem with the jvm option -Djavax.net.debug=ssl:handshake if this can be helpfull.

[martinm1000]

I believe this kind of error should have a internal retry as some other type of internal ssl errors are retried in the driver (SQLServerException.DRIVER_ERROR_INTERMITTENT_TLS_FAILED), but it doesn't looks like this one get another chance on the first fail, unless I'm mistaken. (SQLServerException.DRIVER_ERROR_SSL_FAILED)

[ulvii]

Hi @martinm1000 ,
Please post the exact java version (output of java -version). Also what Operating System is the application running on?

[martinm1000]

Hi @ulvii

Windows 10

openjdk 11.0.1 2018-10-16
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.1+13)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.1+13, mixed mode)

I'm about to post a "working" test case that sometimes reproduce the problem (a simple loop). I am currently trying to find out why I sometimes can't get it to crash... and well... its a bizarre one.

Right now I can only have it trigger when I running on a JLINKED runtime and not from the complete JDK runtime. Anyways, I'm running some more tests before posting it.

But that would match what I see since yesterday and why I havent seen that problem before my tests under Java 11.

[ulvii]

Could you use connection property sslProtocol=TLSv1 to force the driver to use TLS 1.0 and let me know if you are still seeing failures? Your connection string would become jdbc:sqlserver://WKS-DEV-23;encrypt=false;user=user;password=xxxxxx;applicationName=xxx;databaseName=XXXXX;sslProtocol=TLSv1;

[martinm1000]

So far so good with TLSv1. At least we have that ;-)

[ulvii]

Great, now we confirmed that you are seeing the failures because of intermittent TLS1.2 issues.

Please take a look at this article, which explains the cause of the issue (changes to Windows ciphers) and also possible resolution/workarounds.

I would also like to explain why the driver is unable to retry when there is a logic implemented for this. Intermittent TLS1.2 issue is "guessed" by the driver based on the error message from the server. See this line. For some reason, your JDK version wraps the actual and expected exception message SQL Server returned an incomplete response. The connection has been closed. into Unexpected rethrowing. Below is the stack trace of my application with Oracle JDK 11.0.1+13.

com.microsoft.sqlserver.jdbc.SQLServerException: The driver could not establish a secure connection to SQL Server by using Secure Sockets Layer (SSL) encryption. Error: "SQL Server returned an incomplete response. The connection has been closed.". ClientConnectionId:f155980e-207c-48c5-a2e4-804bdeb655b9
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:2825)
	at com.microsoft.sqlserver.jdbc.TDSChannel.enableSSL(IOBuffer.java:1812)
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:2391)
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:2042)
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:1889)
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1120)
	at com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:700)
	at java.sql/java.sql.DriverManager.getConnection(DriverManager.java:677)
	at java.sql/java.sql.DriverManager.getConnection(DriverManager.java:228)
	at Issue849.main(Issue849.java:14)
Caused by: javax.net.ssl.SSLProtocolException: SQL Server returned an incomplete response. The connection has been closed.
	at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:126)
	at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:321)
	at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:264)
	at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:259)
	at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:137)
	at java.base/sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1152)
	at java.base/sun.security.ssl.SSLSocketImpl.readHandshakeRecord(SSLSocketImpl.java:1063)
	at java.base/sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:402)
	at com.microsoft.sqlserver.jdbc.TDSChannel.enableSSL(IOBuffer.java:1741)
	... 8 more
Caused by: java.io.IOException: SQL Server returned an incomplete response. The connection has been closed.
	at com.microsoft.sqlserver.jdbc.TDSChannel$SSLHandshakeInputStream.ensureSSLPayload(IOBuffer.java:772)
	at com.microsoft.sqlserver.jdbc.TDSChannel$SSLHandshakeInputStream.readInternal(IOBuffer.java:821)
	at com.microsoft.sqlserver.jdbc.TDSChannel$SSLHandshakeInputStream.read(IOBuffer.java:814)
	at com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.readInternal(IOBuffer.java:984)
	at com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.read(IOBuffer.java:974)
	at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:448)
	at java.base/sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:165)
	at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:108)
	... 12 more

Notice how Caused by: javax.net.ssl.SSLProtocolException: SQL Server returned an incomplete response. The connection has been closed. is different from yours, hence the driver throws the exception without retrying.

Please let me know if you have any other questions.

[martinm1000]

Thanks, I'll have a look at this. But I'm not sure it answer it all... Right now, I can reproduce the problem using a jlinked java runtime... which is what we're supposed to do now...

I'll do tests with Oracle's JDK tomorrow.

Here's my test case

SSLFail.zip

Directory Layout

mssql-jdbc-7.1.2.jre11-preview.jar
test
TriggerSSLFailure.java

Instructions

"c:\Program Files\Java\jdk-11.0.1+13\bin"\javac --class-path mssql-jdbc-7.1.2.jre11-preview.jar TriggerSSLFailure.java

The test file contains arguments for the program (sql url, etc)

When executing with the full JDK I never (not yet anyway) got the exception :

"c:\Program Files\Java\jdk-11.0.1+13\bin\java.exe" @test

I only might get the exception when running from a jlinked minimal java runtime. (that's what bothering me for now).

Look at used modules

"c:\Program Files\Java\jdk-11.0.1+13\bin\jdeps.exe" -s mssql-jdbc-7.1.2.jre11-preview.jar TriggerSSLFailure.class

Generate a runtime for our app

"c:\Program Files\Java\jdk-11.0.1+13\bin\jlink.exe" --no-header-files --no-man-pages --compress=2 --strip-debug --add-modules java.logging,java.naming,java.security.jgss,java.sql,java.transaction.xa,java.xml --output runtime

run the test program with this runtime. I sometimes get the exception...

runtime\bin\java.exe @test

[martinm1000]

Question: how did you get the stacktraces without it just retrying and silencing them since you do have the expected exception message (and not the Unexpected rethrowing) ?

edit: can I see your Issue849.java ?

[ulvii]

When executing with the full JDK I never (not yet anyway) got the exception
I suggest to get the JDBC logs and compare them between full JDK and minimal JRE. I suspect the intermittent TLS1.2 issue happens in both cases, but with full JDK the driver actually retries. You would need to add the following lines to your application to get the logs on console:

ConsoleHandler cs = new ConsoleHandler();
cs.setFormatter(new SimpleFormatter());
cs.setLevel(Level.FINEST);
Logger.getLogger("").addHandler(cs);
Logger logger = Logger.getLogger("com.microsoft.sqlserver.jdbc");
logger.setLevel(Level.FINEST);

If retry actually happens, you will see a line: Connection failed during SSL handshake. Retrying due to an intermittent TLS 1.2 failure issue.

Another possibility is that DHE suites are disabled for the JDK as mentioned in this article.

How did you get the stacktraces without it just retrying and silencing them since you do have the expected exception message (and not the Unexpected rethrowing) ?
I didn't reproduce the exact intermittent failure, instead I made ensureSSLPayload() to always fail with Caused by: java.io.IOException: SQL Server returned an incomplete response. The connection has been closed. Driver retries INTERMITTENT_TLS_MAX_RETRY = 5 times and gives up.