The workaround is: restart the server one by one. Then they will recognize the clients again.
On Tue, Oct 23, 2018 at 5:07 PM Xiaojian Zhou <[email protected]> wrote: > 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. >> >> >> >
