Hi, Bruce and Vahram, The difference between the versions is:
In old version's server, if the new connection request comes, it will close current one and create a new one. But the new version (with fix of GEODE-1183), it will check if the current one is alive. If yes, then reject the incoming request. That's the root cause of the error msg. What I wonder is: after the 9.0.0 client restarted, why the server still treats the connection (proxy) alive. The client shutdown should trigger the connection (proxy) to be closed. I am still looking at the code. Regards Gester Zhou On Tue, Oct 23, 2018 at 8:43 AM Vahram Aharonyan <[email protected]> wrote: > Hi Bruce, > > > > Thanks for your feedback. > > > > Actually yes, on client restart we are ensuring that old process does not > exist anymore and only after that start the new one. > > > > Could it be that something has changed in 1.6.0 from 1.1.0 in client cache > or pool creation flows that I need to consider (Newly added or deprecated > configuration parameters, etc.)? Or this does not seem to be a > configuration mismatch? > > > > Thanks, > > Vahram. > > > > *From:* Bruce Schuchardt <[email protected]> > *Sent:* Tuesday, October 23, 2018 12:34 AM > *To:* [email protected] > *Subject:* Re: Register Interest fails after clientCache creation > > > > Hi Vahram, > > Are you sure your old client process is gone when you try to connect the > new one? It looks like the server should be doing a liveness check on the > old "proxy" for the client and disallows the new connection if the old one > is still around and its socket is still connected to the old client process. > > The work for JIRA ticket GEODE-1183 introduced the server-side behavior > you're seeing. > > https://issues.apache.org/jira/browse/GEODE-1183 > <https://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fissues.apache.org%2Fjira%2Fbrowse%2FGEODE-1183&data=02%7C01%7Cvaharonyan%40vmware.com%7Ce9ebe69de97f41d855cd08d6385db279%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C1%7C0%7C636758372417799246&sdata=2GQEbITUxYznsNe5cLkvOgDw77hQxlAev7SesU9BuJ0%3D&reserved=0> > > > > On 10/22/18 8:09 AM, Vahram Aharonyan wrote: > > Hi All, > > > > We are trying to move from Geode 1.1.0 to 1.6.0 and examining problems > with registering interest on regions after client restart. Please note that > issue occurs only if server nodes and locator of the cluster are powered on > client is been restarted. On the first boot of servers, client is > successful in registering interest without any problem. > > > > Snippet from client log: > > > > [warning 2018/10/22 19:01:21.299 AMT > Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <queueTimer-ControllerPool> > tid=0x34] Cache Client Updater Thread on > localhost(Server-b90ea8f2-8864-4c19-b4fb-b93f8499c674:22375)<ec><v3>:10002 > port 10000 (10.27.72.245:10000): Caught following exception while > attempting to create a server-to-client communication socket and will exit: > org.apache.geode.cache.client.ServerRefusedConnectionException: <null > inet_addr hostname><ec>:10000 refused connection: A previous connection > attempt from this client is still being processed: > identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1 > > > > [warning 2018/10/22 19:01:21.520 AMT > Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <queueTimer-ControllerPool> > tid=0x34] Cache Client Updater Thread on > localhost(Server-17488aac-6fbd-43d1-8f91-c6d06c3947c0:30157)<ec><v1>:10002 > port 10000 (10.27.72.247:10000): Caught following exception while > attempting to create a server-to-client communication socket and will exit: > org.apache.geode.cache.client.ServerRefusedConnectionException: <null > inet_addr hostname><ec>:10000 refused connection: A previous connection > attempt from this client is still being processed: > identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1 > > > > [warning 2018/10/22 19:01:41.134 AMT > Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <queueTimer-ControllerPool> > tid=0x34] Cache Client Updater Thread on > localhost(Server-0145f530-79a8-449e-9ca9-e0487cfe2934:31321)<ec><v2>:10002 > port 10000 (10.27.72.252:10000): Caught following exception while > attempting to create a server-to-client communication socket and will exit: > org.apache.geode.cache.client.ServerRefusedConnectionException: <null > inet_addr hostname><ec>:10000 refused connection: A previous connection > attempt from this client is still being processed: > identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1 > > > > [warning 2018/10/22 19:01:41.350 AMT > Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <queueTimer-ControllerPool> > tid=0x34] Cache Client Updater Thread on > localhost(Server-b90ea8f2-8864-4c19-b4fb-b93f8499c674:22375)<ec><v3>:10002 > port 10000 (10.27.72.245:10000): Caught following exception while > attempting to create a server-to-client communication socket and will exit: > org.apache.geode.cache.client.ServerRefusedConnectionException: <null > inet_addr hostname><ec>:10000 refused connection: A previous connection > attempt from this client is still being processed: > identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1 > > > > And on the server side: > > > > [warning 2018/10/22 19:04:41.992 AMT > Server-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <ServerConnection on port 10000 > Thread 80> tid=0x5e0] Server connection from > [identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1; > port=50484]: Unexpected IOException: > > java.net.SocketException: Socket Closed > > at > java.net.AbstractPlainSocketImpl.setOption(AbstractPlainSocketImpl.java:212) > > at java.net.Socket.setSoTimeout(Socket.java:1141) > > at > sun.security.ssl.BaseSSLSocketImpl.setSoTimeout(BaseSSLSocketImpl.java:631) > > at > sun.security.ssl.SSLSocketImpl.setSoTimeout(SSLSocketImpl.java:2565) > > at > org.apache.geode.internal.cache.tier.sockets.Message.readHeaderAndBody(Message.java:661) > > at > org.apache.geode.internal.cache.tier.sockets.Message.receiveWithHeaderReadTimeout(Message.java:1125) > > at > org.apache.geode.internal.cache.tier.sockets.Message.receive(Message.java:1136) > > at > org.apache.geode.internal.cache.tier.sockets.Message.receive(Message.java:1145) > > at > org.apache.geode.internal.cache.tier.sockets.BaseCommand.readRequest(BaseCommand.java:851) > > at > org.apache.geode.internal.cache.tier.sockets.ServerConnection.doNormalMsg(ServerConnection.java:792) > > at > org.apache.geode.internal.cache.tier.sockets.OriginalServerConnection.doOneMessage(OriginalServerConnection.java:85) > > at > org.apache.geode.internal.cache.tier.sockets.ServerConnection.run(ServerConnection.java:1248) > > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) > > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) > > at > org.apache.geode.internal.cache.tier.sockets.AcceptorImpl$4$1.run(AcceptorImpl.java:644) > > at java.lang.Thread.run(Thread.java:748) > > > > [warning 2018/10/22 19:04:41.992 AMT > Server-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <ServerConnection on port 10000 > Thread 80> tid=0x5e0] ClientHealthMonitor: Unregistering client with member > id > identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1 > due to: Socket Closed > > > > [info 2018/10/22 19:05:02.034 AMT > Server-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <Client Queue Initialization > Thread 1> tid=0x4b8] :Cache server: Initializing primary server-to-client > communication socket: 62ca4c8d[TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256: > Socket[addr=/10.27.72.247,port=50516,localport=10000]] > > > > [warning 2018/10/22 19:05:02.034 AMT > Server-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <Client Queue Initialization > Thread 1> tid=0x4b8] A previous connection attempt from this client is > still being processed: > identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1 > > > > [warning 2018/10/22 19:05:02.034 AMT > Server-17488aac-6fbd-43d1-8f91-c6d06c3947c0 <Client Queue Initialization > Thread 1> tid=0x4b8] CacheClientNotifier: Unsuccessfully registered client > with identifier > identity(localhost(Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0:21127:loner):57327:6cb13d9c:Client-17488aac-6fbd-43d1-8f91-c6d06c3947c0,connection=1 > and response code 60 > > > > Could it be we are missing something on PoolCreation or client/server > configuration for Geode 1.6.0? Things were working fine with 1.1.0 version. > > > > Thanks, > > Vahram. > > >
