Gester, GEODE-1183 seems to be present in 1.0.0.M3 like Vahram pointed out.
Anthony > On Oct 25, 2018, at 10:06 AM, Xiaojian Zhou <[email protected]> wrote: > > I have checked, the fix GEM-1183 exists since 9.0 (i.e. some time in geode > 1.1.0, your 1.1.0 might not contain this fix). If you send me your revision > number, I will confirm for you. But I'm pretty sure it's due to that behavior > changes. > > I discussed with Bruce. There's chance that if client did not shutdown > gracefully, it might cause the server still have the proxy. There should be a > timeout for server to recognize the client's gone, then close the proxy. If > in that case, you shutdown your client, then wait for a while, Then restart > the client, it should be ok. If you restart immediately, then it was > rejected. This is my guess for your scenario. You can try this workaround. > > Again, restart servers one by one, then restart clients. This will be another > workaround. > > I think we can improve the product to handle your case in more elegant way. > > Regards > Xiaojian Zhou > > > On Thu, Oct 25, 2018 at 7:10 AM Vahram Aharonyan <[email protected] > <mailto:[email protected]>> wrote: > Hi Xiaojian, > > > > Thank you for your response. > > > > Is this only about changes done in scope of GEODE-1183? Because it seems that > they are performed in 1.0.0-incubating.M3. Currently we reside on Geode 1.1.0 > and everything works fine. Problem occurs if we try to move to Geode 1.6.0. > Moreover, we have not examined this issue neither with 1.2.0 version of > Geode. If behavior change was introduced in GEODE-1183, then it should be > visible in 1.1.0 and onwards, is not it ? > > > > Another thing to understand for me is whether this is expected behavior and > is by design or it is a missing in the code flow that should be fixed, could > you please comment on this as well? > > > > Thanks, > > Vahram. > > > > > > From: Xiaojian Zhou <[email protected] <mailto:[email protected]>> > Sent: Wednesday, October 24, 2018 8:07 PM > To: [email protected] <mailto:[email protected]> > Subject: Re: Register Interest fails after clientCache creation > > > > 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] > <mailto:[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] > <mailto:[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] > <mailto:[email protected]>> > Sent: Tuesday, October 23, 2018 12:34 AM > To: [email protected] <mailto:[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%7C3312049973d9427add1008d639cac742%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C1%7C0%7C636759940439474921&sdata=awP32tUDdUR1qQmB9OUoQniwFYNfsujkPs%2B%2B3SC2xCk%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 > <https://na01.safelinks.protection.outlook.com/?url=http%3A%2F%2F10.27.72.245%3A10000&data=02%7C01%7Cvaharonyan%40vmware.com%7C3312049973d9427add1008d639cac742%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C1%7C0%7C636759940439484935&sdata=sLxD3mQ8I9%2FvihPI6iBRRJ2fGOZTE%2FbSycib5I2OL2A%3D&reserved=0>): > 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 > <https://na01.safelinks.protection.outlook.com/?url=http%3A%2F%2F10.27.72.247%3A10000&data=02%7C01%7Cvaharonyan%40vmware.com%7C3312049973d9427add1008d639cac742%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C1%7C0%7C636759940439494954&sdata=TinfLgPZCNGmAgBFMM9riVwtR1w9mKZbplKcvys%2BLtM%3D&reserved=0>): > 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 > <https://na01.safelinks.protection.outlook.com/?url=http%3A%2F%2F10.27.72.252%3A10000&data=02%7C01%7Cvaharonyan%40vmware.com%7C3312049973d9427add1008d639cac742%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C1%7C0%7C636759940439504951&sdata=5UryzIkbBDl6D8%2BbXJYLbpW5xDSGwuKcRco4WeEZwvc%3D&reserved=0>): > 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 > <https://na01.safelinks.protection.outlook.com/?url=http%3A%2F%2F10.27.72.245%3A10000&data=02%7C01%7Cvaharonyan%40vmware.com%7C3312049973d9427add1008d639cac742%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C1%7C0%7C636759940439514970&sdata=qjgNMmYKr%2Frt4ezpEBHlq9nrsOrd1fDQZ4%2Fvflx%2FIGY%3D&reserved=0>): > 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 > <https://na01.safelinks.protection.outlook.com/?url=http%3A%2F%2F10.27.72.247&data=02%7C01%7Cvaharonyan%40vmware.com%7C3312049973d9427add1008d639cac742%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C1%7C0%7C636759940439524978&sdata=1qFyS%2BHWd7g4b7cDJ71Tbls6H5%2B8LxSip8tVRqPmyVU%3D&reserved=0>,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. > > >
