[prev in list] [next in list] [prev in thread] [next in thread] 

List:       openjdk-serviceability-dev
Subject:    Re: Potential infinite waiting at JMXConnection#createConnection
From:       KUBOTA Yuji <kubota.yuji () gmail ! com>
Date:       2015-12-16 17:05:05
Message-ID: CABU-27N-zCERq15pjaSupyZXJ9Odvm5PS+mQOAYnQOBG3LtMiw () mail ! gmail ! com
[Download RAW message or body]

Hi all,

If Shanliang cannot review, someone could review it?

I reported this issue first at the below.
http://mail.openjdk.java.net/pipermail/jdk9-dev/2015-April/002152.html
http://mail.openjdk.java.net/pipermail/serviceability-dev/2015-May/017241.html

Hope this patch helps to community.

Thanks,
Yuji

2015-12-10 22:40 GMT+09:00 KUBOTA Yuji <kubota.yuji@gmail.com>:
> Hi Shanliang and all,
> 
> Sorry my reply is too late. But, finally, I reproduced this issue by
> following test program! :)
> Could you please review test program and my patch ?
> 
> The test program includes some files, but I do not have an account of
> openjdk, so I push it on icedtea server as below.
> 
> http://icedtea.classpath.org/people/ykubota/fixLoopAtJMXConnectorFactory/file/e31044f0804f
>  
> The test program starts a simple sleep server program (JMXSSLServer)
> on external jdb process with a breakpoint at
> sun.security.ssl.ServerHandshaker.clientHello set. It then starts a
> client process (JMXSSLCient) which tries to connect the sleep/jdb
> process.
> ServerHandshaker.clientHello responds to the client hello message and
> sends SSL record back. By setting breakpont in that function, we can
> emulate this issue in which client keeps waiting SSL record from
> server.
> Now, JMXConnectorFactory.connect() ignores
> sun.rmi.transport.tcp.responseTimeout, so wait the response (SSL
> record) from server INFINITELY. Once my patch (jdk9.patch) was added,
> then the client will return 0 when the connection timeout happen by
> sun.rmi.transport.tcp.responseTimeout.
> And test program returns the client's return code.
> 
> You can reproduce infinite waiting by the below.
> * hg clone http://icedtea.classpath.org/people/ykubota/fixLoopAtJMXConnectorFactory/
>                 
> * cd fixLoopAtJMXConnectorFactory/testProgram
> * set JAVA_HOME
> * mvn package
> * setting debugcontrol.properties if you need.
> * *NOTE* This test program will stop for "debugcontroltest.stop_time" ms.
> * ${JAVA_HOME}/bin/java -cp .:target/debugcontrol-1.0-SNAPSHOT.jar
> debugcontrol.DebugController
> 
> * The result by JDK without my patch.
> The client throws java.net.ConnectException after sending quit to jdb.
> ------
> [INFO] Server process args
> args[0] /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.65-3.b17.fc23.x86_64/bin/jdb
> > 
> > 
> cli-out: [INFO] Service URL: service:jmx:rmi:///jndi/rmi://localhost:9876/jmxrmi
> ser-err: Set deferred breakpoint sun.security.ssl.ServerHandshaker.clientHello
> ser-out:
> ser-err: Breakpoint hit: "thread=RMI TCP Connection(2)-127.0.0.1",
> sun.security.ssl.ServerHandshaker.clientHello(), line=339 bci=0
> ser-out:
> [INFO] sending quit to jdb
> ser-err: RMI TCP Connection(2)-127.0.0.1[1]
> cli-err: java.rmi.ConnectException: Connection refused to host:
> 127.0.0.1; nested exception is:
> cli-err:        java.net.ConnectException: Connection refused
> cli-err:        at
> sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:619)
> cli-err:        at
> sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:216)
> cli-err:        at
> sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:202)
> cli-err:        at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:130)
> cli-err:        at
> javax.management.remote.rmi.RMIServerImpl_Stub.newClient(Unknown
> Source)
> cli-err:        at
> javax.management.remote.rmi.RMIConnector.getConnection(RMIConnector.java:2432)
> cli-err:        at
> javax.management.remote.rmi.RMIConnector.connect(RMIConnector.java:308)
> cli-err:        at
> javax.management.remote.JMXConnectorFactory.connect(JMXConnectorFactory.java:270)
> cli-err:        at
> debugcontrol.client.JMXSSLClient.execute(JMXSSLClient.java:51)
> cli-err:        at debugcontrol.client.JMXSSLClient.main(JMXSSLClient.java:34)
> cli-err: Caused by: java.net.ConnectException: Connection refused
> cli-err:        at java.net.PlainSocketImpl.socketConnect(Native Method)
> cli-err:        at
> java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
> cli-err:        at
> java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
> cli-err:        at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
> cli-err:        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> cli-err:        at java.net.Socket.connect(Socket.java:589)
> cli-err:        at
> sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:668)
> cli-err:        at sun.security.ssl.SSLSocketImpl.<init>(SSLSocketImpl.java:427)
> cli-err:        at
> sun.security.ssl.SSLSocketFactoryImpl.createSocket(SSLSocketFactoryImpl.java:88)
> cli-err:        at
> javax.rmi.ssl.SslRMIClientSocketFactory.createSocket(SslRMIClientSocketFactory.java:121)
>                 
> cli-err:        at
> sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:613)
> cli-err:        ... 9 more
> [INFO] Thu Dec 10 16:16:50 JST 2015 Client done.  Result code: 2
> [INFO] Client took 114462 msec.
> 
> * By JDK 9 with my patch.
> The client got java.net.SocketTimeoutException after the connection
> timeout happen, then return 0.
> ------
> [INFO] Server process args
> args[0] /workspace/jdk9-netdev-patch/build/linux-x86_64-normal-server-release/jdk/bin/jdb
>  args[1] -classpath
> args[2] target/classes
> args[3] -J-Duser.language=en
> args[4] -Dcom.sun.management.jmxremote.port=9876
> args[5] -Dcom.sun.management.jmxremote.password.file=jmxremote.password
> args[6] -Djavax.net.ssl.keyStore=jmx-test-cert.pkcs12
> args[7] -Djavax.net.ssl.keyStoreType=pkcs12
> args[8] -Djavax.net.ssl.keyStorePassword=changeit
> args[9] debugcontrol.server.JMXSSLServer
> ser-out: Initializing jdb ...
> ser-err: > Deferring breakpoint sun.security.ssl.ServerHandshaker.clientHello.
> ser-out: It will be set after the class is loaded.
> ser-err: > run debugcontrol.server.JMXSSLServer
> ser-err: Set uncaught java.lang.Throwable
> ser-out: Set deferred uncaught java.lang.Throwable
> ser-err: >
> ser-out: VM Started: [INFO] Server launched then sleep...
> [INFO] Client process args:
> args[0] /workspace/jdk9-netdev-patch/build/linux-x86_64-normal-server-release/jdk/bin/java
>  args[1] -classpath
> args[2] target/classes
> args[3] -Duser.language=en
> args[4] -Djavax.net.ssl.trustStore=jmx-test-cert.pkcs12
> args[5] -Djavax.net.ssl.trustStoreType=pkcs12
> args[6] -Djavax.net.ssl.trustStorePassword=changeit
> args[7] -Dsun.rmi.transport.tcp.responseTimeout=1000
> args[8] -Dsun.rmi.transport.tcp.handshakeTimeout=1000
> args[9] debugcontrol.client.JMXSSLClient
> args[10] localhost
> args[11] 9876
> cli-out: [INFO] Service URL: service:jmx:rmi:///jndi/rmi://localhost:9876/jmxrmi
> ser-err: Set deferred breakpoint sun.security.ssl.ServerHandshaker.clientHello
> ser-out:
> ser-err: Breakpoint hit: "thread=RMI TCP Connection(2)-127.0.0.1",
> sun.security.ssl.ServerHandshaker.clientHello(), line=356 bci=0
> ser-out:
> cli-out: [INFO] Conglaturation. We got a timeout.
> [INFO] Thu Dec 10 15:54:39 JST 2015 Client done.  Result code: 0
> 
> 
> * My patch (no change from the reported)
> * http://icedtea.classpath.org/people/ykubota/fixLoopAtJMXConnectorFactory/file/e31044f0804f/jdk9.patch
>                 
> ------
> diff --git a/src/java.rmi/share/classes/sun/rmi/transport/tcp/TCPChannel.java
> b/src/java.rmi/share/classes/sun/rmi/transport/tcp/TCPChannel.java
> --- a/src/java.rmi/share/classes/sun/rmi/transport/tcp/TCPChannel.java
> +++ b/src/java.rmi/share/classes/sun/rmi/transport/tcp/TCPChannel.java
> @@ -224,6 +224,22 @@
> out.writeByte(TransportConstants.SingleOpProtocol);
> } else {
> out.writeByte(TransportConstants.StreamProtocol);
> +
> +                    int usableSoTimeout = 0;
> +                    try {
> +                        /*
> +                         * If socket factory had set a non-zero timeout on its
> +                         * own, then restore it instead of using the property-
> +                         * configured value.
> +                         */
> +                        usableSoTimeout = sock.getSoTimeout();
> +                        if (usableSoTimeout == 0) {
> +                          usableSoTimeout = responseTimeout;
> +                        }
> +                        sock.setSoTimeout(usableSoTimeout);
> +                    } catch (Exception e) {
> +                        // if we fail to set this, ignore and proceed anyway
> +                    }
> out.flush();
> 
> /*
> @@ -231,9 +247,7 @@
> * connection handshake; this also serves to guard against
> * non-JRMP servers that do not respond (see 4322806).
> */
> -                    int originalSoTimeout = 0;
> try {
> -                        originalSoTimeout = sock.getSoTimeout();
> sock.setSoTimeout(handshakeTimeout);
> } catch (Exception e) {
> // if we fail to set this, ignore and proceed anyway
> @@ -281,14 +295,7 @@
> * that a remote method call is permitted to execute.
> */
> try {
> -                        /*
> -                         * If socket factory had set a non-zero timeout on its
> -                         * own, then restore it instead of using the property-
> -                         * configured value.
> -                         */
> -                        sock.setSoTimeout((originalSoTimeout != 0 ?
> -                                           originalSoTimeout :
> -                                           responseTimeout));
> +                        sock.setSoTimeout(usableSoTimeout);
> } catch (Exception e) {
> // if we fail to set this, ignore and proceed anyway
> }
> 
> Thanks,
> Yuji


[prev in list] [next in list] [prev in thread] [next in thread] 

Configure | About | News | Add a list | Sponsored by KoreLogic