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.
