JDK17 - Possible TLS issue.
Peter Firmstone
peter.firmstone at zeus.net.au
Wed Aug 11 08:13:23 UTC 2021
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