JDK-8208562 : Endless loop in SSLSocketImpl.waitForClose for MSSQL JDBC driver 11ea+24 onwards
  • Type: Bug
  • Component: security-libs
  • Sub-Component: javax.net.ssl
  • Affected Version: 11
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: linux
  • CPU: x86_64
  • Submitted: 2018-07-27
  • Updated: 2019-07-18
  • Resolved: 2018-08-06
Related Reports
Duplicate :  
Duplicate :  
Description
ADDITIONAL SYSTEM INFORMATION :
OS: Linux 64-bit, Java 11-ea+24, MSSQL JDBC 6.4.0

A DESCRIPTION OF THE PROBLEM :
With build 11-ea+24 a jdbc connection to a ms sqlserver can't be established anymore. The connection is stuck at SSLSocketInputRecord.decode(ByteBuffer[], int, int) line: 169.

The issue doesn't occur when using build 11-ea+17.

REGRESSION : Last worked in version 11

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Try to establish a connection to a mssql server.

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Connection is established.
ACTUAL -
Connection locks up. The stacktrace of the lock is:
Thread [main] (Suspended)	
	owns: SSLSocketImpl  (id=17)	
	owns: Object  (id=18)	
	SSLSocketInputRecord.decode(ByteBuffer[], int, int) line: 169	
	SSLTransport.decode(TransportContext, ByteBuffer[], int, int, ByteBuffer[], int, int) line: 108	
	SSLSocketImpl.decode(ByteBuffer) line: 877	
	SSLSocketImpl.waitForClose() line: 952	
	SSLSocketImpl.closeSocket(boolean) line: 929	
	SSLSocketImpl.shutdown() line: 1170	
	TransportContext.initiateOutboundClose() line: 567	
	TransportContext.closeOutbound() line: 482	
	TransportContext.close() line: 450	
	SSLSocketImpl.close() line: 447	
	TDSChannel.disableSSL() line: 711	
	TDSWriter.writePacket(int) line: 4093	
	TDSWriter.endMessage() line: 3196	
	SQLServerConnection$LogonCommand(TDSCommand).startResponse(boolean) line: 7712	
	SQLServerConnection$LogonCommand(TDSCommand).startResponse() line: 7700	
	SQLServerConnection.sendLogon(SQLServerConnection$LogonCommand, SSPIAuthentication, SQLServerConnection$FederatedAuthenticationFeatureExtensionData) line: 4547	
	SQLServerConnection.logon(SQLServerConnection$LogonCommand) line: 3409	
	SQLServerConnection.access$100(SQLServerConnection, SQLServerConnection$LogonCommand) line: 85	
	SQLServerConnection$LogonCommand.doExecute() line: 3373	
	SQLServerConnection$LogonCommand(TDSCommand).execute(TDSWriter, TDSReader) line: 7344	
	SQLServerConnection.executeCommand(TDSCommand) line: 2713	
	SQLServerConnection.connectHelper(ServerPortPlaceHolder, int, int, boolean, boolean, boolean, int) line: 2261	
	SQLServerConnection.login(String, String, int, String, FailoverInfo, int, long) line: 1921	
	SQLServerConnection.connectInternal(Properties, SQLServerPooledConnection) line: 1762	
	SQLServerConnection.connect(Properties, SQLServerPooledConnection) line: 1077	
	SQLServerDriver.connect(String, Properties) line: 623	
	DriverManager.getConnection(String, Properties, Class<?>) line: 677	
	DriverManager.getConnection(String) line: 251	
	ConnectTest.main(String[]) line: 16	


---------- BEGIN SOURCE ----------
// Add mssql-jdbc-6.4.0.jre8.jar to classpath
public class ConnectTest
{
    public static void main( String[] args ) throws ClassNotFoundException
    {
        String connectionUrl = "jdbc:sqlserver://CONNECTION_DETAILS";

        Class.forName( "com.microsoft.sqlserver.jdbc.SQLServerDriver" );
        try (Connection con = DriverManager.getConnection( connectionUrl ))
        {
            String SQL = "SELECT 1";
            Statement stmt = con.createStatement();
            ResultSet rs = stmt.executeQuery( SQL );
            System.out.println( rs );
        }
        catch( Exception e )
        {
            e.printStackTrace();
        }
    }
}
---------- END SOURCE ----------

FREQUENCY : always



Comments
This is being addressed through JDK-8207009 , tested with the build in which the issue is fixed, it resolves this issue as well.
03-08-2018

I tested this on MS SQL Server , and could reproduce the issue on JDK 11-ea+24 . Here is the output (last few lines before doing Ctrl+C ) on JDK 11-ea+24: javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.461 IST|SSLSocketInputRecord.java:467|Raw read: EOF javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.462 IST|SSLSocketImpl.java:1161|close the underlying socket javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.464 IST|SSLSocketImpl.java:921|close the ssl connection (passive) javax.net.ssl|ALL|01|main|2018-08-03 18:43:24.466 IST|SSLSocketImpl.java:955|discard plaintext while waiting for close ( contentType: 0/majorVersion: 0/minorVersion: 0/recordEpoch: -1/recordSN: 0xffffffffffffffff/fragment: null ) javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.470 IST|SSLSocketInputRecord.java:467|Raw read: EOF javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.472 IST|SSLSocketImpl.java:1161|close the underlying socket javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.474 IST|SSLSocketImpl.java:921|close the ssl connection (passive) javax.net.ssl|ALL|01|main|2018-08-03 18:43:24.476 IST|SSLSocketImpl.java:955|discard plaintext while waiting for close ( contentType: 0/majorVersion: 0/minorVersion: 0/recordEpoch: -1/recordSN: 0xffffffffffffffff/fragment: null ) javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.481 IST|SSLSocketInputRecord.java:467|Raw read: EOF javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.483 IST|SSLSocketImpl.java:1161|close the underlying socket javax.net.ssl|DEBUG|01|main|2018-08-03 18:43:24.484 IST|SSLSocketImpl.java:921|close the ssl connection (passive) javax.net.ssl|ALL|01|main|2018-08-03 18:43:24.486 IST|SSLSocketImpl.java:955|discard plaintext while waiting for close ( contentType: 0/majorVersion: 0/minorVersion: 0/recordEpoch: -1/recordSN: 0xffffffffffffffff/fragment: null ) ............................ ...........................
03-08-2018

Posting the output of jstack from the duplicate bug id JDK-8208657 jstack.exe shows: "main" #1 prio=5 os_prio=0 cpu=73328.13ms elapsed=75.83s tid=0x0000015602def000 nid=0x214c runnable [0x000000425f0fe000] java.lang.Thread.State: RUNNABLE at java.lang.Throwable.fillInStackTrace(java.base@11-ea/Native Method) at java.lang.Throwable.fillInStackTrace(java.base@11-ea/Throwable.java:787) - locked <0x0000000767a73f80> (a java.io.EOFException) at java.lang.Throwable.<init>(java.base@11-ea/Throwable.java:270) at java.lang.Exception.<init>(java.base@11-ea/Exception.java:66) at java.io.IOException.<init>(java.base@11-ea/IOException.java:58) at java.io.EOFException.<init>(java.base@11-ea/EOFException.java:62) at sun.security.ssl.SSLSocketInputRecord.decode(java.base@11-ea/SSLSocketInputRecord.java:169) at sun.security.ssl.SSLTransport.decode(java.base@11-ea/SSLTransport.java:108) at sun.security.ssl.SSLSocketImpl.decode(java.base@11-ea/SSLSocketImpl.java:877) at sun.security.ssl.SSLSocketImpl.waitForClose(java.base@11-ea/SSLSocketImpl.java:952) at sun.security.ssl.SSLSocketImpl.closeSocket(java.base@11-ea/SSLSocketImpl.java:929) at sun.security.ssl.SSLSocketImpl.shutdown(java.base@11-ea/SSLSocketImpl.java:1170) at sun.security.ssl.TransportContext.initiateOutboundClose(java.base@11-ea/TransportContext.java:567) at sun.security.ssl.TransportContext.closeOutbound(java.base@11-ea/TransportContext.java:482) at sun.security.ssl.TransportContext.close(java.base@11-ea/TransportContext.java:450) at sun.security.ssl.SSLSocketImpl.close(java.base@11-ea/SSLSocketImpl.java:447) - locked <0x0000000760000b70> (a sun.security.ssl.SSLSocketImpl) at com.microsoft.sqlserver.jdbc.TDSChannel.disableSSL(IOBuffer.java:711) at com.microsoft.sqlserver.jdbc.TDSWriter.writePacket(IOBuffer.java:4093) at com.microsoft.sqlserver.jdbc.TDSWriter.endMessage(IOBuffer.java:3196) at com.microsoft.sqlserver.jdbc.TDSCommand.startResponse(IOBuffer.java:7712) at com.microsoft.sqlserver.jdbc.TDSCommand.startResponse(IOBuffer.java:7700) at com.microsoft.sqlserver.jdbc.SQLServerConnection.sendLogon(SQLServerConnection.java:4547) at com.microsoft.sqlserver.jdbc.SQLServerConnection.logon(SQLServerConnection.java:3409) at com.microsoft.sqlserver.jdbc.SQLServerConnection.access$100(SQLServerConnection.java:85) at com.microsoft.sqlserver.jdbc.SQLServerConnection$LogonCommand.doExecute(SQLServerConnection.java:3373) at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7344) at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:2713) - locked <0x0000000760006228> (a java.lang.Object) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:2261) at com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:1921) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:1762) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1077) at com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:623) at java.sql.DriverManager.getConnection(java.sql@11-ea/DriverManager.java:677) at java.sql.DriverManager.getConnection(java.sql@11-ea/DriverManager.java:189) at SSLCloseHangsInJDBCDriver.main(SSLCloseHangsInJDBCDriver.java:18)
02-08-2018

Communication with submitter: The issue occurs only with MS SQL Server. I'm able to connect to MySQL and H2 database. Am 31.07.2018 um 10:55 schrieb Pallavi Sonal: I am unable to reproduce the issue with MySQL server on Windows 7, is > the issue only reproducible with MSSQLServer ? Can you try with any > other DB and let us know if you experience the same issue ?
31-07-2018