unexpected server shutdown with sslsocket
Hi there,
I have a problem with connections between my client and my server when using sslsocket protocol. My server unexpectedly shuts down during refresh. I looked at it for my self and this is what I found out:
It happens that somehow during a refresh in the SocketServerInvoker, the socket is not unbound correctly after a not allowed atempt to connect. So when creating a new socket and trying to bind it to the old address, a BindException occures, when calling this line:
ServerSocket newServerSocket = createServerSocket(getServerBindPort(), backlog, bindAddress);
in the refreshServerSocket() method.
My server then shuts down and my client is not able to conect anymore. Here is what my client shows:
2007-04-26 09:54:15,957 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[90c06f, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:15,957 DEBUG [main] org.jboss.remoting.MicroRemoteClientInvoker: disconnect called for: SocketClientInvoker[90c06f, sslsocket://CRICHTER:1101] 2007-04-26 09:54:15,957 DEBUG [main] org.jboss.remoting.transport.socket.SocketWrapper: ClientSocketWrapper[1829e6f[TLS_DHE_DSS_WITH_AES_128_CBC_SHA: Socket[addr=CRICHTER.emea.hpqcorp.net/16.58.6.211,port=1101,localport=1636]].1829e6f] closing successfully handled this request ***************** positive test ****************** 2007-04-26 09:54:30,971 INFO [main] client.ServerConnector: receiving remote Object from Server 2007-04-26 09:54:30,971 DEBUG [main] client.ServerConnector: setting SSL Properties 2007-04-26 09:54:30,971 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] constructed 2007-04-26 09:54:30,971 DEBUG [main] org.jboss.remoting.MicroRemoteClientInvoker: connect called for: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] 2007-04-26 09:54:30,971 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] added new pool ([]) as ServerAddress[16.58.6.211:1101, NO enableTcpNoDelay timeout 1800000 ms] 2007-04-26 09:54:31,986 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1015 ms 2007-04-26 09:54:32,002 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[90c06f, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:32,002 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[90c06f, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:33,002 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1016 ms 2007-04-26 09:54:34,001 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 999 ms 2007-04-26 09:54:35,001 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:36,017 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:37,017 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:38,032 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1015 ms 2007-04-26 09:54:39,032 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:40,032 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:41,047 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1015 ms 2007-04-26 09:54:42,047 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:43,047 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:44,062 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[2e1f1f, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[2e1f1f, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[9934d4, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[9934d4, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[16f144c, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[16f144c, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[12bcd4b, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:44,094 DEBUG [Finalizer] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[12bcd4b, sslsocket://CRICHTER:1101] disconnecting ... 2007-04-26 09:54:45,062 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:46,078 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1016 ms 2007-04-26 09:54:47,077 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 999 ms 2007-04-26 09:54:48,077 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:49,093 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1016 ms 2007-04-26 09:54:50,093 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:51,092 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 999 ms 2007-04-26 09:54:52,108 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:53,108 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:54,123 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1015 ms 2007-04-26 09:54:55,123 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:56,123 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:57,138 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1015 ms 2007-04-26 09:54:58,138 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms 2007-04-26 09:54:59,154 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1016 ms 2007-04-26 09:55:00,153 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 999 ms 2007-04-26 09:55:01,153 DEBUG [main] org.jboss.remoting.transport.socket.MicroSocketClientInvoker: SocketClientInvoker[180f96c, sslsocket://CRICHTER:1101] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [sslsocket://CRICHTER:1101/] at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525) at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:125) at org.jboss.remoting.Client.invoke(Client.java:630) at org.jboss.remoting.Client.invoke(Client.java:622) at org.jboss.remoting.Client.invoke(Client.java:607) at org.jboss.remoting.transporter.TransporterClient.invoke(TransporterClient.java:276) at $Proxy0.getHandle(Unknown Source) at client.Client.getHandle(Client.java:28) at client.ClientTest.testGetHandlePositiveMultiple(ClientTest.java:43) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at junit.framework.TestCase.runTest(TestCase.java:154) at junit.framework.TestCase.runBare(TestCase.java:127) at junit.framework.TestResult$1.protect(TestResult.java:106) at junit.framework.TestResult.runProtected(TestResult.java:124) at junit.framework.TestResult.run(TestResult.java:109) at junit.framework.TestCase.run(TestCase.java:118) at junit.framework.TestSuite.runTest(TestSuite.java:208) at junit.framework.TestSuite.run(TestSuite.java:203) at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:128) at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196) Caused by: java.net.ConnectException: Connection refused: connect at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.PlainSocketImpl.doConnect(Unknown Source) at java.net.PlainSocketImpl.connectToAddress(Unknown Source) at java.net.PlainSocketImpl.connect(Unknown Source) at java.net.SocksSocketImpl.connect(Unknown Source) at java.net.Socket.connect(Unknown Source) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.connect(Unknown Source) at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187) at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796) at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521) ... 26 more
And here is what I see on the server when the BindException occures:
2007-04-26 09:54:25,362 DEBUG [Timer-0] server.Reloader: reloading Truststore, Round 16 2007-04-26 09:54:25,362 INFO [Timer-0] org.jboss.remoting.transport.socket.SocketServerInvoker: ServerSocketFactory has been updated 2007-04-26 09:54:25,362 DEBUG [ServerSocketRefresh] org.jboss.remoting.transport.socket.SocketServerInvoker: got notice about new ServerSocketFactory 2007-04-26 09:54:25,362 DEBUG [ServerSocketRefresh] org.jboss.remoting.transport.socket.SocketServerInvoker: refreshing server socket 2007-04-26 09:54:25,362 DEBUG [Timer-0] server.Reloader: successfully reloaded truststore 2007-04-26 09:54:25,362 DEBUG [ServerSocketRefresh] org.jboss.remoting.transport.socket.SocketServerInvoker: could not refresh server socket 2007-04-26 09:54:25,362 ERROR [AcceptorThread#0:1101] org.jboss.remoting.transport.socket.SocketServerInvoker: SocketServerInvoker[UNINITIALIZED] failed to handle socket java.net.SocketException: socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.PlainSocketImpl.accept(Unknown Source) at java.net.ServerSocket.implAccept(Unknown Source) at com.sun.net.ssl.internal.ssl.SSLServerSocketImpl.accept(Unknown Source) at org.jboss.remoting.transport.socket.SocketServerInvoker.run(SocketServerInvoker.java:520) at java.lang.Thread.run(Unknown Source) 2007-04-26 09:54:25,362 DEBUG [ServerSocketRefresh] org.jboss.remoting.transport.socket.SocketServerInvoker: message is: Address already in use: JVM_Bind 2007-04-26 09:54:25,362 DEBUG [ServerSocketRefresh] org.jboss.remoting.transport.socket.SocketServerInvoker: server socket refreshed 2007-04-26 09:54:25,362 ERROR [AcceptorThread#0:1101] org.jboss.remoting.transport.socket.SocketServerInvoker: Cannot proceed without functioning server socket. Shutting down 2007-04-26 09:54:25,362 DEBUG [AcceptorThread#0:1101] org.jboss.remoting.ServerInvoker: SocketServerInvoker[UNINITIALIZED] stopped
Especially this line is interesting:
2007-04-26 09:02:09,458 ERROR [AcceptorThread#0:1101] org.jboss.remoting.transport.socket.SocketServerInvoker: Cannot proceed without functioning server socket. Shutting down
In refreshServerSocket() the serverSocket is set to null but then the Exception occures and serverSocket is not set anymore. I guess the BindException shouldn't occur. Is this is a bug? And shall I open a JIRA issue?
(btw. I use the CVS version of jboss-remoting)
Thanks for your help
Claudia
