JDK17 - Possible TLS issue.

johnsjiang(江莎) johnsjiang at tencent.com
Wed Aug 11 09:22:40 UTC 2021


+ security-dev

Hi Peter,
It looks both of file 1 and 5 contain that close_notify warning alert.
This point may be related to JDK-8208526: TLS 1.3 half-close and synchronization issues [1].

[1] https://bugs.openjdk.java.net/browse/JDK-8208526

Best regards,
John Jiang

At 2021/8/11 PM 4:14, Peter Firmstone wrote:
> I'm testing on JDK17, having some issues communicating using TLS between 
> processes.
>
> With TLS disabled, the test passes on JDK17.
>
> The test passes using TLS on JDK 16 and earlier JDK versions.
>
> I've enabled TLS handshake debug on the output
>
>  1. https://github.com/pfirmstone/JGDMS/blob/trunk/qa/LookupNegMatches-jdk16-tls-handshake-debug.txt
>  2. https://github.com/pfirmstone/JGDMS/blob/trunk/qa/LookupNegMatches-jdk16.txt
>  3. https://github.com/pfirmstone/JGDMS/blob/trunk/qa/LookupNegMatches-jdk17-TLS-disabled.txt
>  4. https://github.com/pfirmstone/JGDMS/blob/trunk/qa/LookupNegMatches-jdk17-tls-handshake-debug.txt
>  5. https://github.com/pfirmstone/JGDMS/blob/trunk/qa/LookupNegMatches-jdk17-TLS-handshake-debug2.txt
>
> There are 5 JVM instances created during this integration test and these 
> JVM's are communicating using network connections.  I have checked that 
> all JVM processes are running, it seems to be a communication issue.
>
> Using diff to compare files 1 and 5 above, it appears to be related to a 
> close notify in JDK17, on the (JSK) connection .
>
> Any suggestions?
>
> Thanks,
>
> Peter.
>
>       [java] ActSys-err: javax.net.ssl|DEBUG|D2|(JSK) mux reader|2021-08-11 14:56:20.606 AEST|SSLSocketImpl.java:1775|close the SSL connection (passive)
>       [java] ActSys-err: javax.net.ssl|DEBUG|C2|(JSK) mux writer|2021-08-11 14:56:20.606 AEST|SSLSocketImpl.java:572|duplex close of SSLSocket
>       [java] ActSys-err: javax.net.ssl|ALL|D2|(JSK) mux reader|2021-08-11 14:56:20.606 AEST|SSLSocketImpl.java:1129|Closing input stream
>       [java] ActSys-err: javax.net.ssl|WARNING|B2|(JSK) mux reader|2021-08-11 14:56:20.607 AEST|SSLSocketImpl.java:1666|handling exception (
>       [java] ActSys-err: "throwable" : {
>       [java] ActSys-err:   java.net.SocketException: Socket closed
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl.endRead(NioSocketImpl.java:248)
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:327)
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350)
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803)
>       [java] ActSys-err:   	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:478)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:472)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:70)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1455)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1059)
>       [java] ActSys-err:   	at org.apache.river.jeri.internal.mux.StreamConnectionIO$1.read(StreamConnectionIO.java:372)
>       [java] ActSys-err:   	at org.apache.river.jeri.internal.mux.StreamConnectionIO$Reader.run(StreamConnectionIO.java:277)
>       [java] ActSys-err:   	at org.apache.river.thread.ThreadPool$Task.run(ThreadPool.java:172)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
>       [java] ActSys-err:   	at java.base/java.lang.Thread.run(Thread.java:833)}
>       [java] ActSys-err:
>       [java] ActSys-err: )
>       [java] ActSys-err: javax.net.ssl|ERROR|B2|(JSK) mux reader|2021-08-11 14:56:20.607 AEST|TransportContext.java:363|Fatal (UNEXPECTED_MESSAGE): Socket closed (
>       [java] ActSys-err: "throwable" : {
>       [java] ActSys-err:   java.net.SocketException: Socket closed
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl.endRead(NioSocketImpl.java:248)
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:327)
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350)
>       [java] ActSys-err:   	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803)
>       [java] ActSys-err:   	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:478)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:472)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:70)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1455)
>       [java] ActSys-err:   	at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1059)
>       [java] ActSys-err:   	at org.apache.river.jeri.internal.mux.StreamConnectionIO$1.read(StreamConnectionIO.java:372)
>       [java] ActSys-err:   	at org.apache.river.jeri.internal.mux.StreamConnectionIO$Reader.run(StreamConnectionIO.java:277)
>       [java] ActSys-err:   	at org.apache.river.thread.ThreadPool$Task.run(ThreadPool.java:172)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
>       [java] ActSys-err:   	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
>       [java] ActSys-err:   	at java.base/java.lang.Thread.run(Thread.java:833)}
>       [java] ActSys-err:
>       [java] ActSys-err: )
>       [java] ActSys-err: javax.net.ssl|ALL|B2|(JSK) mux reader|2021-08-11 14:56:20.609 AEST|SSLSocketImpl.java:1129|Closing input stream
>       [java] ActSys-err: 11 Aug 2021 2:57:02 pm:Group-0:err:WARNING: A terminally deprecated method in java.lang.System has been called
>       [java] ActSys-err: WARNING: System::setSecurityManager has been called by org.apache.river.phoenix.init.ActivationGroupInit (file:/C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT/lib/phoenix-init-3.1.1-SNAPSHOT.jar)
>       [java] ActSys-err: WARNING: Please consider reporting this to the maintainers of org.apache.river.phoenix.init.ActivationGroupInit
>       [java] ActSys-err: WARNING: System::setSecurityManager will be removed in a future release
>       [java] ActSys-err:
>       [java] ActSys-err: Aug 11, 2021 2:57:02 PM org.apache.river.phoenix.Activation$GroupEntry getInstantiator
>       [java] ActSys-err: FINE: Group-1 exec [C:\Program Files\Zulu\jdk-17\bin\java, -ea, -esa, -server, -Dorg.apache.river.qa.harness.harnessJar=C:\Users\peter\Documents\NetBeansProjects\JGDMS\qa\lib\jiniharness.jar, -Djsk.iiop.jar=jgdms-iiop-3.1.1-SNAPSHOT.jar, -Doutrigger-snaplogstore.jar=outrigger-snaplogstore-3.1.1-SNAPSHOT.jar, -Dorg.apache.river.jsk.port=9080, -Dcollections.jar=jgdms-collections-3.1.1-SNAPSHOT.jar, -Dsharedvm.jar=service-starter-3.1.1-SNAPSHOT.jar, -Djgdms-rmi-tls.jar=jgdms-rmi-tls-3.1.1-SNAPSHOT.jar, -Djava.protocol.handler.pkgs=net.jini.url, -Dphoenix.jar=phoenix-3.1.1-SNAPSHOT.jar, -Dplatform.jar=jgdms-platform-3.1.1-SNAPSHOT.jar, -Dnorm-dl.jar=norm-dl-3.1.1-SNAPSHOT.jar, -Dorg.apache.river.qa.harness.testJar=C:\Users\peter\Documents\NetBeansProjects\JGDMS\qa\lib\jinitests.jar, -Djava.util.logging.config.file=C:\Users\peter\Documents\NetBeansProjects\JGDMS\qa\src\org\apache\river\test\resources\qa1.logging, -Djsk.pref.jar=jgdms-pref-class-loader-3.1.1-SNAPSHOT.jar, -Dstart.jar=service-starter-3.1.1-SNAPSHOT.jar, -Dphoenix-common.jar=phoenix-common-3.1.1-SNAPSHOT.jar, -Djava.security.properties=file:/C:/Users/peter/Documents/NetBeansProjects/JGDMS/qa/harness/trust/dynamic-policy.properties, -Dmercury-dl.jar=mercury-dl-3.1.1-SNAPSHOT.jar, -Dreggie-dl.jar=reggie-dl-3.1.1-SNAPSHOT.jar, -Dloader.jar=jgdms-pref-class-loader-3.1.1-SNAPSHOT.jar, -Dclassserver.jar=classserver-3.1.1-SNAPSHOT.jar, -Djsk-dl.jar=jgdms-lib-dl-3.1.1-SNAPSHOT.jar, -Dorg.apache.river.test.home=C:\Users\peter\Documents\NetBeansProjects\JGDMS\qa, -Dreggie.jar=reggie-service-3.1.1-SNAPSHOT.jar, -Djdk.io.permissionsUseCanonicalPath=true, -Dphoenix-dl.jar=phoenix-dl-3.1.1-SNAPSHOT.jar, -Djsk.home=C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT, -Djeri.jar=jgdms-jeri-3.1.1-SNAPSHOT.jar, -Dhigh-scale-lib.jar=high-scale-lib-1.0.6.jar, -Djava.net.preferIPv6Addresses=true, -DHOST=DESKTOP-R0ORPA2, -Dorg.apache.river.qa.harness.testhosts=, -Dmahalo.jar=mahalo-service-3.1.1-SNAPSHOT.jar, -Djavax.net.ssl.trustStore=harness\trust\truststore, -Dbouncy-jce.jar=bcprov-jdk15on-1.59.jar, -Dorg.apache.river.discovery.x500.trustStore=file:/C:/Users/peter/Documents/NetBeansProjects/JGDMS/qa/harness/trust/truststore, -Doutrigger-dl.jar=outrigger-dl-3.1.1-SNAPSHOT.jar, -Ddisco.jar=jgdms-discovery-providers-3.1.1-SNAPSHOT.jar, -Djgdms.version=3.1.1-SNAPSHOT, -Dgroup.jar=group-service-3.1.1-SNAPSHOT.jar, -Djava.security.policy=file:/C:/Users/peter/Documents/NetBeansProjects/JGDMS/qa/harness/policy/defaultsecuresharedvm.policy, -Dorg.apache.river.qa.harness.runjiniserver=true, -Dactivation-param.jar=jgdms-activation-parameters-3.1.1-SNAPSHOT.jar, -Dactivation.jar=jgdms-activation-3.1.1-SNAPSHOT.jar, -Dorg.apache.river.qa.harness.policies=file:/C:/Users/peter/Documents/NetBeansProjects/JGDMS/qa/src/org/apache/river/test/resources/jinitest.policy, -Dsun.net.maxDatagramSockets=1024, -Dnorm.jar=norm-service-3.1.1-SNAPSHOT.jar, -Dmercury.jar=mercury-service-3.1.1-SNAPSHOT.jar, -Djsk.url.jar=jgdms-url-integrity-3.1.1-SNAPSHOT.jar, -Djsk-lib.jar=jgdms-lib-3.1.1-SNAPSHOT.jar, -Dfiddler.jar=fiddler-service-3.1.1-SNAPSHOT.jar, -Dbouncy-jsse.jar=bctls-jdk15on-1.59.jar, -Dnet.jini.core.lookup.ServiceRegistrar.portAbitraryIfInUse=true, -Djavax.net.debug=ssl:handshake, -Dorg.apache.river.discovery.x500.trustStorePassword=trustpw, -Dphoenix-group.jar=phoenix-group-3.1.1-SNAPSHOT.jar, -Dnet.jini.security.allowInsecureConnections=true, -Dorg.apache.river.test.port=9082, -Dorg.apache.river.qa.harness.runkitserver=true, -Djava.security.auth.login.config=file:/C:/Users/peter/Documents/NetBeansProjects/JGDMS/qa/harness/trust/jsselogins, -Dfiddler-dl.jar=fiddler-dl-3.1.1-SNAPSHOT.jar, -Dmahalo-dl.jar=mahalo-dl-3.1.1-SNAPSHOT.jar, -Dorg.apache.river.qa.port=9081, -Dphoenix-init.jar=phoenix-init-3.1.1-SNAPSHOT.jar, -Doutrigger.jar=outrigger-service-3.1.1-SNAPSHOT.jar, -Djavax.net.ssl.trustStorePassword=trustpw, -Ddestroy.jar=jgdms-destroy-3.1.1-SNAPSHOT.jar, -Dqa.home=C:\Users\peter\Documents\NetBeansProjects\JGDMS\qa, -cp, C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\service-starter-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-collections-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\high-scale-lib-1.0.6.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\phoenix-init-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-platform-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib-dl\jgdms-lib-dl-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-lib-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-discovery-providers-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-pref-class-loader-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-jeri-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\phoenix-group-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib-dl\phoenix-dl-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\phoenix-common-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-rmi-tls-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-activation-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-activation-parameters-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\jgdms-url-integrity-3.1.1-SNAPSHOT.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\bcprov-jdk15on-1.59.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\bctls-jdk15on-1.59.jar;C:/Users/peter/Documents/NetBeansProjects/JGDMS/JGDMS/dist/target/JGDMS-3.1.1-SNAPSHOT\lib\security-policy-debug-3.1.1-SNAPSHOT.jar, org.apache.river.phoenix.init.ActivationGroupInit]
>       [java] ActSys-err: javax.net.ssl|WARNING|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.067 AEST|ServerNameExtension.java:266|Unable to indicate server name
>       [java] ActSys-err: javax.net.ssl|DEBUG|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.067 AEST|SSLExtensions.java:272|Ignore, context unavailable extension: server_name
>       [java] ActSys-err: javax.net.ssl|INFO|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.068 AEST|AlpnExtension.java:182|No available application protocols
>       [java] ActSys-err: javax.net.ssl|DEBUG|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.068 AEST|SSLExtensions.java:272|Ignore, context unavailable extension: application_layer_protocol_negotiation
>       [java] ActSys-err: javax.net.ssl|DEBUG|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.068 AEST|SessionTicketExtension.java:408|Stateless resumption supported
>       [java] ActSys-err: javax.net.ssl|DEBUG|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.070 AEST|SSLExtensions.java:272|Ignore, context unavailable extension: cookie
>       [java] ActSys-err: javax.net.ssl|DEBUG|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.075 AEST|PreSharedKeyExtension.java:662|No session to resume.
>       [java] ActSys-err: javax.net.ssl|DEBUG|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.075 AEST|SSLExtensions.java:272|Ignore, context unavailable extension: pre_shared_key
>       [java] ActSys-err: javax.net.ssl|DEBUG|F1|(JSK) mux request dispatch|2021-08-11 14:57:03.077 AEST|ClientHello
>
>
>



More information about the jdk-dev mailing list