Closed AndrzejHeller closed 1 year ago
Hi @AndrzejHeller,
We're changing the title to help us find the issue later.
I see you've added TLS1.2 to the connection string, can you try with TLS1 (sslProtocol=TLSv1
)? Additionally, can you try enabling logging on FINER level and pasting those logs here? You can find the information for that here. Finally, what version of Java are you using (8,11,17, or 19) and what vendor (Oracle, Zulu, etc.)?
Hello @Jeffery-Wasty , Thank you for your prompt response. Intermittent test failures are experienced in our test environments when running automated tests on Linux VM in AWS infrastructure. I reviewed all the stacks and can confirm that failures were experienced for the following Java versions:
openjdk version "11.0.9.1" 2020-11-04 LTS OpenJDK Runtime Environment Corretto-11.0.9.12.1 (build 11.0.9.1+12-LTS) OpenJDK 64-Bit Server VM Corretto-11.0.9.12.1 (build 11.0.9.1+12-LTS, mixed mode)
and
openjdk version "11.0.9" 2020-10-20 OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.9+11) OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.9+11, mixed mode)
We use Adopt, Corretto and Oracle Java in our test environments, I think it’s a coincidence that I didn’t find any failures for Oracle Java. I followed your suggestion, changed TLS version to TLSv1 and run the tests again. It didn’t make any difference, as I experienced the same problem again. Enabling additional logging requires more work on our side, I’ll supply those logs once they become available – hopefully later today or tomorrow.
Thanks for testing TLSv1, and the versions for your JDK. I see why you added to the connection string but adding encrypt=true
can cause additional issues. Can you try the following connection string - jdbc:sqlserver://:1433;databaseName=;trustServerCertificate=true
?
Has the problem been the same throughout the connection string changes? That is, do you have the error with jdbc:sqlserver://:1433;encrypt=true;trustServerCertificate=false;sslProtocol=TLSv1.2;databaseName=
as you did with jdbc:sqlserver://:1433;databaseName=;trustServerCertificate=false
?
Are you using the trustStorePassword
connection property (I don't see it in your example)? This looks like a problem with our password obfuscation code rather. I know that the Tag mismatch!
error happens when the secret used to encrypt the password is different during decryption.
@Jeffery-Wasty ,
When I observed the issue for the very first time, my connection string was like this:
jdbc:sqlserver://<host name>:1433;databaseName=<database name>;trustServerCertificate=false
I didn’t provide ‘encrypt’ parameter, as I assumed it’s not necessary if we want ‘encrypt=true’. Later, I checked it with such connection string:
jdbc:sqlserver://<host name>:1433;encrypt=true;trustServerCertificate=false;databaseName=<database name>
then provided TLS version explicitly:
jdbc:sqlserver://<host name>:1433;encrypt=true;trustServerCertificate=false;sslProtocol=TLSv1.2;databaseName=<database name>
and (following your suggestion) with TLSv1 instead of TLSv1.2.
I’m now running my tests again with connection string like below:
jdbc:sqlserver://<host name>:1433;trustServerCertificate=false;databaseName=<database name>
It’s very similar to the first, the only difference is order of parameters. I’m capturing logs you requested, hopefully they will contain something useful.
@tkyc
I've never tried providing trustStorePassword
property in my connection string. Is there any other property that could be missing in my connection string?
@Jeffery-Wasty , Two example logs created the way you had suggested can be downloaded from here: https://drive.google.com/drive/folders/1t8OQqyLcB-vED2HlDtkPyKbyufcGRzCG?usp=sharing
@AndrzejHeller So the trustStorePassword
is used to check the data in the truststore
(the path to certificate truststore file). If you aren't using truststore
then trustStorePassword
isn't needed. By default, if truststore
and trustStorePassword
isn't set, the driver defaults to use javax.net.ssl.trustStore
and javax.net.ssl.trustStorePassword
.
Please try trustServerCertificate=true
. In the examples you gave it is set to false
each time.
@Jeffery-Wasty
I can run tests with trustServerCertificate
set to TRUE, no problem with that. We set it to FALSE because server certificate DN is not provided. We only set trustServerCertificate
to TRUE if server certificate DN is provided.
But if my configuration is not right, why is it not failing for each connection attempt? Multiple connections are created during each execution of our tests and only very few of those attempts fail.
Hey @AndrzejHeller, I believe there is a race condition in our password obfuscation code. I've attached a driver jar with the fix. Could you test it out and see if it corrects your problem? Thanks. mssql-jdbc.zip
Hello @tkyc , Of course I can test the driver you've attached. I'll run my tests and let you know if the problem is still present or not.
@tkyc , I’ve executed our tests three times and received the same errors for each run, something like this is visible in log:
[2022-11-01 16:45:43,225 | FINE | container | com.microsoft.sqlserver.jdbc.SQLServerConnection prelogin] ConnectionID:30 ClientConnectionId: bda318c6-406b-4835-998b-0de696f78e05 Server returned major version:15
[2022-11-01 16:45:43,225 | FINER | container | com.microsoft.sqlserver.jdbc.SQLServerConnection prelogin] ConnectionID:30 ClientConnectionId: bda318c6-406b-4835-998b-0de696f78e05 Negotiated encryption level:ON
[2022-11-01 16:45:43,225 | FINER | container | com.microsoft.sqlserver.jdbc.SQLServerConnection prelogin] ConnectionID:30 ClientConnectionId: bda318c6-406b-4835-998b-0de696f78e05 Ignoring prelogin response option:5
[2022-11-01 16:45:43,225 | FINER | container | com.microsoft.sqlserver.jdbc.TDSChannel enableSSL] TDSChannel (ConnectionID:30) Enabling SSL...
[2022-11-01 16:45:43,225 | FINER | container | com.microsoft.sqlserver.jdbc.TDSChannel enableSSL] TDSChannel (ConnectionID:30) SSL handshake will validate server certificate
[2022-11-01 16:45:43,225 | FINEST | container | com.microsoft.sqlserver.jdbc.TDSChannel enableSSL] TDSChannel (ConnectionID:30) Finding key store interface
[2022-11-01 16:45:43,225 | FINEST | container | com.microsoft.sqlserver.jdbc.TDSChannel loadTrustStore] TDSChannel (ConnectionID:30) Opening specified trust store: /mnt/active-drive/_tls/pbeo_net_truststore.pfx
[2022-11-01 16:45:43,225 | FINEST | container | com.microsoft.sqlserver.jdbc.TDSChannel enableSSL] TDSChannel (ConnectionID:30) Loading key store
[2022-11-01 16:45:43,226 | FINEST | container | com.microsoft.sqlserver.jdbc.TDSChannel enableSSL] TDSChannel (ConnectionID:29) Loading key store
[2022-11-01 16:45:43,231 | FINE | container | com.microsoft.sqlserver.jdbc.SQLServerException logException] *** SQLException:com.microsoft.sqlserver.jdbc.SecureStringUtil@31376c83 com.microsoft.sqlserver.jdbc.SQLServerException: Internal error during decryption: Tag mismatch! Internal error during decryption: Tag mismatch!
[2022-11-01 16:45:43,231 | FINER | container | com.microsoft.sqlserver.jdbc.TDSChannel enableSSL] Internal error during decryption: Tag mismatch!
[2022-11-01 16:45:43,244 | FINER | container | com.microsoft.sqlserver.jdbc.TDSChannel enableSSL] java.security path: /usr/java/javaEO/lib/security
Security providers: [SUN version 11, SunRsaSign version 11, SunEC version 11, SunJSSE version 11, SunJCE version 11, SunJGSS version 11, SunSASL version 11, XMLDSig version 11, SunPCSC version 11, JdkLDAP version 11, JdkSASL version 11, SunPKCS11 version 11, BC version 1.61]
KeyStore provider info: SUN (DSA key/parameter generation; DSA signing; SHA-1, MD5 digests; SecureRandom; X.509 certificates; PKCS12, JKS & DKS keystores; PKIX CertPathValidator; PKIX CertPathBuilder; LDAP, Collection CertStores, JavaPolicy Policy; JavaLoginConfig Configuration)
java.ext.dirs: null
[2022-11-01 16:45:43,245 | FINE | container | com.microsoft.sqlserver.jdbc.SQLServerException logException] *** SQLException:ConnectionID:30 ClientConnectionId: bda318c6-406b-4835-998b-0de696f78e05 com.microsoft.sqlserver.jdbc.SQLServerException: The driver could not establish a secure connection to SQL Server by using Secure Sockets Layer (SSL) encryption. Error: "Internal error during decryption: Tag mismatch! ". ClientConnectionId:bda318c6-406b-4835-998b-0de696f78e05 The driver could not establish a secure connection to SQL Server by using Secure Sockets Layer (SSL) encryption. Error: "Internal error during decryption: Tag mismatch! ". ClientConnectionId:bda318c6-406b-4835-998b-0de696f78e05
[2022-11-01 16:45:43,245 | FINE | container | com.microsoft.sqlserver.jdbc.SQLServerException logException] com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:3889)com.microsoft.sqlserver.jdbc.TDSChannel.enableSSL(IOBuffer.java:1937)com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:3412)com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:3033)com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:2873)com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1759)com.microsoft.sqlserver.jdbc.SQLServerDataSource.getConnectionInternal(SQLServerDataSource.java:1410)com.microsoft.sqlserver.jdbc.SQLServerDataSource.getConnection(SQLServerDataSource.java:97)com.pb.engageone.server.batch.na.gather.processor.BatchItemPreProcessor.isGraphicResourceMissing(BatchItemPreProcessor.java:188)com.pb.engageone.server.batch.na.gather.processor.BatchItemPreProcessor.isMissingResource(BatchItemPreProcessor.java:131)com.pb.engageone.server.batch.na.gather.processor.BatchItemPreProcessor.process(BatchItemPreProcessor.java:292)com.pb.engageone.server.batch.na.gather.processor.CompositeBatchItemProcessor.process(CompositeBatchItemProcessor.java:28)com.pb.engageone.server.batch.na.gather.processor.BatchItemProcessorWorker.work(BatchItemProcessorWorker.java:79)com.pb.engageone.server.batch.na.ThreadManager$WorkerThread.run(ThreadManager.java:214)
[2022-11-01 16:45:43,245 | FINER | container | com.microsoft.sqlserver.jdbc.SQLServerConnection:30 close] ENTRY
I can provide a full log if necessary.
@AndrzejHeller that'd be great if you can provide the logs. If possible, could you also provide a standalone reproduction app? I'll need to investigate again. For sure there was a race condition. Interesting that it doesn't seem to be the cause of your problem. Whatever the case, there is definitely something suspect in our password obfuscation code.
@tkyc , Attaching all the logs gathered during last execution of our automated test procedures: SQL_JDBC_1.zip SQL_JDBC_2.zip Errors can be found in SQL_JDBC.log.38 and SQL_JDBC.log.66. All logs were gathered with logging level set to FINEST.
Unfortunately, I can't provide any application that may help you reproducing the problem.
@AndrzejHeller no worries. I'll see what I can figure out. I'll keep you posted.
Hey @AndrzejHeller, I've attached another driver jar with an attempted fix. Please let me know if it resolves your problem. mssql-jdbc.zip
Hello @tkyc , I'm currently running our tests and it's looking good. All tests have already been executed a few times and we didn't experience problems like we had seen previously. As the issue was intermittent, I'll run all our tests few more times and let you know the outcome.
@AndrzejHeller sounds good, thanks for the help on testing. The fix will be included in a hotfix release for version 11.2.2. I don't have a date for the hotfix release yet as the team is still discussing other things that will be included in the hotfix. I'll update this thread with the date when we have a definite schedule.
We just released a hotfix with this fix. It can be found in v11.2.2 of the driver.
Question
I randomly experience connection failures when trying to establish secure connection to MS SQL Server instance running in AWS environment. Initially, my connection string was like this:
jdbc:sqlserver://:1433;databaseName=;trustServerCertificate=false
In my first attempt to resolve the problem, I’ve changed it to be like this:
jdbc:sqlserver://:1433;encrypt=true;trustServerCertificate=false;databaseName=
I’m not sure if parameter order makes any difference or it is necessary to set ‘encrypt’ explicitly. I did my changes to make the connection string to be as similar as possible to examples that can be found in Microsoft’s online documentation. Additionally, I’ve found this issue: It’s marked as resolved, but I still implemented my changes to be on the safe side. Unfortunately, all connection string modifications didn’t make any difference. Following that, I made further changes to my connection string to make it like this:
jdbc:sqlserver://:1433;encrypt=true;trustServerCertificate=false;sslProtocol=TLSv1.2;databaseName=
Unfortunately, the problem is still there. The following exception is thrown each time connection attempt fails:
com.microsoft.sqlserver.jdbc.SQLServerException: The driver could not establish a secure connection to SQL Server by using Secure Sockets Layer (SSL) encryption. Error: "Internal error during decryption: Tag mismatch! ". ClientConnectionId:8e8c7663-6299-4a05-8168-e67b1588444d at com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:3806) at com.microsoft.sqlserver.jdbc.TDSChannel.enableSSL(IOBuffer.java:1906) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:3329) at com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:2950) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:2790) at com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1663) at com.microsoft.sqlserver.jdbc.SQLServerDataSource.getConnectionInternal(SQLServerDataSource.java:1385) at com.microsoft.sqlserver.jdbc.SQLServerDataSource.getConnection(SQLServerDataSource.java:97) at asi.utility.DbMgr.makeConnection(DbMgr.java:58) at asi.edms.data.DataDocSearch.getPhysicalPath(DataDocSearch.java:768) at asi.edms.data.DataMgr.getPhysicalName(DataMgr.java:1889) at asi.edmsapi.EdmsFileManager.getPhysicalName(EdmsFileManager.java:1532) at com.pb.engageone.server.batch.na.tdsextract.core.repository.oe.RepositoryImpl.getFilePath(RepositoryImpl.java:61) at com.pb.engageone.server.batch.na.tdsextract.api.RepositoryApi.getTemplateInformation(RepositoryApi.java:90) at com.pb.engageone.server.batch.na.tdsextract.api.RepositoryApi.getTemplateInformation(RepositoryApi.java:199) at com.pb.engageone.server.batch.na.dao.CachingTemplateDaoEjb.retrieveTemplate(CachingTemplateDaoEjb.java:46) at com.pb.engageone.server.batch.na.dao.CachingTemplateDaoEjb.retrieveTemplate(CachingTemplateDaoEjb.java:32) at com.pb.engageone.server.batch.na.gather.processor.BatchItemPreProcessor.process(BatchItemPreProcessor.java:305) at com.pb.engageone.server.batch.na.gather.processor.CompositeBatchItemProcessor.process(CompositeBatchItemProcessor.java:28) at com.pb.engageone.server.batch.na.gather.processor.BatchItemProcessorWorker.work(BatchItemProcessorWorker.java:79) at com.pb.engageone.server.batch.na.ThreadManager$WorkerThread.run(ThreadManager.java:214) Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Internal error during decryption: Tag mismatch! at com.microsoft.sqlserver.jdbc.SecureStringUtil.getDecryptedChars(SecureStringUtil.java:146) at com.microsoft.sqlserver.jdbc.TDSChannel.enableSSL(IOBuffer.java:1695) ... 19 common frames omitted
All my tests have been performed using the latest mssql-jdbc-11.2.1.jre11.jar file. Similar problem is observed with mssql-jdbc-11.2.0.jre11.jar, but it looks the problem is gone if I downgrade to mssql-jdbc-10.2.1.jre11.jar. I’m now wondering if my connection string is wrong (something is missing?) or maybe I’m suffering from a bug that’s only present from version 11.2.0 onwards. Can someone help with that?
Regards, Andrzej
Relevant Issues and Pull Requests
https://github.com/microsoft/mssql-jdbc/issues/1853 https://github.com/Microsoft/mssql-jdbc/issues/879