JDK-8277970 : Test jdk/sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java fails with "tag mismatch"
  • Type: Bug
  • Component: security-libs
  • Sub-Component: javax.crypto
  • Affected Version: 17,18,20
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2021-11-30
  • Updated: 2023-01-09
  • Resolved: 2022-10-12
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11 JDK 17 JDK 19 JDK 20
11.0.18Fixed 17.0.6Fixed 19.0.2Fixed 20 b20Fixed
Related Reports
Duplicate :  
JDK-8279649 - sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java failing intermittently in loom repo
Relates :  
JDK-8274736 - Concurrent read/close of SSLSockets causes SSLSessions to be invalidated unnecessarily
Relates :  
JDK-8280158 - New test from JDK-8274736 failed with/without patch in JDK11u
Relates :  
JDK-8287739 - [11u] ProblemList sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java
Sub Tasks
JDK-8279532 :  
ProblemList sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java - Resolved
Description
Test:

jdk/sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java

is failing with "tag mismatch":

Caused by: javax.crypto.AEADBadTagException: Tag mismatch
at java.base/com.sun.crypto.provider.GaloisCounterMode$GCMDecrypt.doFinal(GaloisCounterMode.java:1591)
at java.base/com.sun.crypto.provider.GaloisCounterMode.engineDoFinal(GaloisCounterMode.java:454)
at java.base/javax.crypto.Cipher.doFinal(Cipher.java:2501)
at java.base/sun.security.ssl.SSLCipher$T13GcmReadCipherGenerator$GcmReadCipher.decrypt(SSLCipher.java:1933)
at java.base/sun.security.ssl.SSLSocketInputRecord.decodeInputRecord(SSLSocketInputRecord.java:260)
at java.base/sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:181)
at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:111)
Comments
A pull request was submitted for review. URL: https://git.openjdk.org/jdk11u-dev/pull/1499 Date: 2022-11-03 20:17:35 +0000
03-11-2022
Fix request (19u, 17u, 11u) Bugfix that is valid/helpful in backport releases as well. Applied clean (at least the bot recognizes this), successfully ran through nightly testing at SAP.
03-11-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/855 Date: 2022-11-03 19:21:06 +0000
03-11-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk19u/pull/48 Date: 2022-10-19 09:53:31 +0000
19-10-2022
Changeset: d1252653 Author: Daniel Jeliński <djelinski@openjdk.org> Date: 2022-10-12 15:32:36 +0000 URL: https://git.openjdk.org/jdk/commit/d1252653b07ee3d0347b39b96f734e45772b5b36
12-10-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/10657 Date: 2022-10-11 14:38:35 +0000
11-10-2022
Adding additional synchronization would need to be done carefully, to be sure. This read/close logic seems to be delicate code. The test that is failing was there to exercise a fix to not invalidate sessions where the read/close thread collision happens. But the removal of some synchronization in reads/closes goes back to JDK-8274524, which resolved deadlocks that happened when reads and closes collided. This test itself was iterative, since it isn't always easy from running SSLSocket based tests to land on the read/close timing that went into the codepath that now keeps the session in the cache. This is a admittedly a very blunt instrument to use for a test like this because there's always the possibility that none of the iterations would land on the proper window of time. That said, I ran it thousands of times both before and after this test failure bug happened and I'd always hit the desired timing at least once, and I've never been able to reproduce the AEAD tag failure, though clearly the nightly regressions can. What I've been working on is a JDI-based version of the test that can artificially create the conditions that exercise specifically the fix in JDK-8274736. While that would remove the need for this iterative try-until-you-get-it approach, even that wouldn't directly address the tag mismatch exceptions we see here, as it would be targeted specifically to the read/close timing seen in JDK-8274736. My main concern is that whichever way we go on this, we don't end up returning to code that led to JDK-8274524.
05-10-2022
Ok, my previous comment didn't capture the entire picture... When one thread calls close at the same time when other thread is reading from the socket, there are more things that can go wrong: - both threads read from the socket; the thread doing 'read' may receive incomplete data - the thread doing 'close' may dispose the read cipher at any time, and the thread doing 'read' does not check if the read cipher is still valid at the time when it's used The fix is not that easy either; the threads are not synchronized at all. The idea was that 'read' should not block 'close'. However, some sort of synchronization is required if we want to make sure that 'read' does not receive incorrect data.
05-10-2022
So here's what's happening: - Main Client Thread calls close... - While Client Reader Thread is decoding "new session ticket message" from the server... - close calls GCMReadCipher.dispose(), which calls cipher.doFinal() - and it happens between GCMReadCipher.decrypt's call to cipher.updateAAD(aad) and call to cipher.doFinal(bb, pt) To reproduce, put a Thread.sleep(6) between updateAAD and doFinal For an easy fix, remove GCMReadCipher.dispose(); it does not serve any real purpose anyway.
03-10-2022
Here's a log file snippet for the jdk-20+6-297-tier2 sighting: sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java 399947860245050: Main Client Thread: Closed SSLSocket@2a0f1e34 399947861492940: Client Reader Thread: Exception reading from SSLSocket@2a0f1e34: javax.net.ssl.SSLException: Tag mismatch javax.net.ssl.SSLException: Tag mismatch at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:132) at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:371) at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:314) at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:309) at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:123) at java.base/sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1513) at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1484) at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1069) at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:976) at NoInvalidateSocketException.readFromSSLSocket(NoInvalidateSocketException.java:249) at NoInvalidateSocketException$ReaderThread.run(NoInvalidateSocketException.java:180) Caused by: javax.crypto.AEADBadTagException: Tag mismatch at java.base/com.sun.crypto.provider.GaloisCounterMode$GCMDecrypt.doFinal(GaloisCounterMode.java:1591) at java.base/com.sun.crypto.provider.GaloisCounterMode.engineDoFinal(GaloisCounterMode.java:454) at java.base/javax.crypto.Cipher.doFinal(Cipher.java:2525) at java.base/sun.security.ssl.SSLCipher$T12GcmReadCipherGenerator$GcmReadCipher.decrypt(SSLCipher.java:1693) at java.base/sun.security.ssl.SSLSocketInputRecord.decodeInputRecord(SSLSocketInputRecord.java:260) at java.base/sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:181) at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:111) ... 6 more 399948372405860: Main Client Thread: *** Session(1657693008111|TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384) IS INVALID *** <snip> ----------System.err:(18/1967)---------- javax.net.ssl|ALL|A1|Server Reader Thread|2022-07-13 06:16:48.063 UTC|SSLSessionImpl.java:219|Session initialized: Session(1657693008040|SSL_NULL_WITH_NULL_NULL) javax.net.ssl|ALL|A1|Server Reader Thread|2022-07-13 06:16:48.109 UTC|SSLSessionImpl.java:947|Negotiating session: Session(1657693008040|TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384) javax.net.ssl|ALL|71|Main Client Thread|2022-07-13 06:16:48.112 UTC|SSLSessionImpl.java:219|Session initialized: Session(1657693008111|TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384) javax.net.ssl|ALL|91|Client Reader Thread|2022-07-13 06:16:58.947 UTC|SSLSessionImpl.java:1221|Invalidated session: Session(1657693008111|TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384) javax.net.ssl|ALL|22|Server Reader Thread|2022-07-13 06:17:00.463 UTC|SSLSessionImpl.java:219|Session initialized: Session(1657693020463|SSL_NULL_WITH_NULL_NULL) javax.net.ssl|ALL|22|Server Reader Thread|2022-07-13 06:17:00.465 UTC|SSLSessionImpl.java:947|Negotiating session: Session(1657693020463|TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384) javax.net.ssl|ALL|71|Main Client Thread|2022-07-13 06:17:00.467 UTC|SSLSessionImpl.java:219|Session initialized: Session(1657693020467|TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384) java.lang.RuntimeException: One or more sessions were improperly invalidated. at NoInvalidateSocketException.main(NoInvalidateSocketException.java:88) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) at java.base/java.lang.reflect.Method.invoke(Method.java:578) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:1589) JavaTest Message: Test threw exception: java.lang.RuntimeException: One or more sessions were improperly invalidated. JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: One or more sessions were improperly invalidated. ----------rerun:(40/5624)*----------
13-07-2022
[~jnimeh], can you check whether JDK-8280158 is a duplicate of this?
02-06-2022
There are 11 failure sightings for sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java in the Mach5 history. 5 of those are JDK18 and JDK19 failures on linux-aarch64, linux-x64 and macosx-x64. 6 of those are JDK18 SBR runs on linux-x64. I'm looking into a limited ProblemListing for this test.
05-01-2022
Here's a log file snippet for the jdk-18+30-2015-tier2 sighting: sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java ----------System.err:(39/5264)---------- javax.net.ssl|ALL|11|Server Reader Thread|2021-12-23 18:33:59.226 GMT|SSLSessionImpl.java:219|Session initialized: Session(1640284439220|SSL_NULL_WITH_NULL_NULL) javax.net.ssl|ALL|11|Server Reader Thread|2021-12-23 18:33:59.263 GMT|SSLSessionImpl.java:947|Negotiating session: Session(1640284439220|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|E0|Main Client Thread|2021-12-23 18:33:59.275 GMT|SSLSessionImpl.java:219|Session initialized: Session(1640284439274|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|11|Server Reader Thread|2021-12-23 18:33:59.365 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284439220|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:33:59.370 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284439274|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|21|Server Reader Thread|2021-12-23 18:34:01.302 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284439220|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:01.324 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284439274|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|31|Server Reader Thread|2021-12-23 18:34:03.194 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284439220|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:03.211 GMT|SSLSessionImpl.java:1221|Invalidated session: Session(1640284439274|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|41|Server Reader Thread|2021-12-23 18:34:05.027 GMT|SSLSessionImpl.java:219|Session initialized: Session(1640284445026|SSL_NULL_WITH_NULL_NULL) javax.net.ssl|ALL|41|Server Reader Thread|2021-12-23 18:34:05.030 GMT|SSLSessionImpl.java:947|Negotiating session: Session(1640284445026|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|E0|Main Client Thread|2021-12-23 18:34:05.047 GMT|SSLSessionImpl.java:219|Session initialized: Session(1640284445047|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|41|Server Reader Thread|2021-12-23 18:34:05.073 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284445026|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:05.080 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284445047|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|51|Server Reader Thread|2021-12-23 18:34:06.910 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284445026|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:06.933 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284445047|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|61|Server Reader Thread|2021-12-23 18:34:08.749 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284445026|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|71|Server Reader Thread|2021-12-23 18:34:10.589 GMT|SSLSessionImpl.java:219|Session initialized: Session(1640284450588|SSL_NULL_WITH_NULL_NULL) javax.net.ssl|ALL|71|Server Reader Thread|2021-12-23 18:34:10.597 GMT|SSLSessionImpl.java:947|Negotiating session: Session(1640284450588|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|E0|Main Client Thread|2021-12-23 18:34:10.608 GMT|SSLSessionImpl.java:219|Session initialized: Session(1640284450608|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|71|Server Reader Thread|2021-12-23 18:34:10.629 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450588|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:10.638 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450608|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|81|Server Reader Thread|2021-12-23 18:34:12.487 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450588|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:12.489 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450608|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|91|Server Reader Thread|2021-12-23 18:34:14.258 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450588|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:14.262 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450608|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|A1|Server Reader Thread|2021-12-23 18:34:16.177 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450588|TLS_AES_256_GCM_SHA384) javax.net.ssl|ALL|01|Client Reader Thread|2021-12-23 18:34:16.179 GMT|SSLSessionImpl.java:252|Session initialized: Session(1640284450608|TLS_AES_256_GCM_SHA384) java.lang.RuntimeException: One or more sessions were improperly invalidated. at NoInvalidateSocketException.main(NoInvalidateSocketException.java:88) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) at java.base/java.lang.reflect.Method.invoke(Method.java:577) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:833) JavaTest Message: Test threw exception: java.lang.RuntimeException: One or more sessions were improperly invalidated. JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: One or more sessions were improperly invalidated. ----------rerun:(35/7242)*---------- And the above error message match the following bug: JDK-8278388 Test sun/security/ssl/SSLSessionImpl/NoInvalidateSocketException.java fails with java.lang.RuntimeException: One or more sessions were improperly invalidated. However, this sighting also contains: 5542886558336815: Client Reader Thread: Exception reading from SSLSocket@1a158622: javax.net.ssl.SSLException: Tag mismatch javax.net.ssl.SSLException: Tag mismatch at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:133) at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:371) at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:314) at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:309) at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:123) at java.base/sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1503) at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1474) at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1059) at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:966) at NoInvalidateSocketException.readFromSSLSocket(NoInvalidateSocketException.java:249) at NoInvalidateSocketException$ReaderThread.run(NoInvalidateSocketException.java:180) Caused by: javax.crypto.AEADBadTagException: Tag mismatch at java.base/com.sun.crypto.provider.GaloisCounterMode$GCMDecrypt.doFinal(GaloisCounterMode.java:1591) at java.base/com.sun.crypto.provider.GaloisCounterMode.engineDoFinal(GaloisCounterMode.java:454) at java.base/javax.crypto.Cipher.doFinal(Cipher.java:2501) at java.base/sun.security.ssl.SSLCipher$T13GcmReadCipherGenerator$GcmReadCipher.decrypt(SSLCipher.java:1933) at java.base/sun.security.ssl.SSLSocketInputRecord.decodeInputRecord(SSLSocketInputRecord.java:260) at java.base/sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:181) at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:111) ... 6 more 5542887199043311: Main Client Thread: *** Session(1640284439274|TLS_AES_256_GCM_SHA384) IS INVALID *** Which matches this bug.
23-12-2021
My suspicion here is that we have a truncated/partial read happening on the reader thread which causes the AEADBadTagException to occur rather than a socket exception (trying to read on an already closed socket). Normally this kind of exception would rightfully cause the session to be invalidated since the cipher's own integrity protection mechanisms are being tripped. In this case though it's really a lower-layer socket/timing issue underneath the protocol. We may be able to bypass the session invalidation check in these cases since we run multiple iterations of the test. What isn't clear to me at this point is how frequent this truncated read happens. I ran hundreds of iterations of this test in Mach5 on Linux x64, Windows x64 and MacOS before committing the fix and test and never saw this, but the timing on this is delicate so on a different machine with slightly different characteristics could uncover something that I didn't see in all the places I ran the test.
08-12-2021