+ 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 > > >
