You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@geode.apache.org by "Barrett Oglesby (Jira)" <ji...@apache.org> on 2019/10/10 20:19:00 UTC

[jira] [Commented] (GEODE-7286) When a durable client is killed for the second time, its socket is not closed properly

    [ https://issues.apache.org/jira/browse/GEODE-7286?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16948923#comment-16948923 ] 

Barrett Oglesby commented on GEODE-7286:
----------------------------------------

CacheClientProxy.reinitialize is called when the durable client reconnects:
{noformat}
java.lang.Exception: Stack trace
	at java.lang.Thread.dumpStack(Thread.java:1333)
	at org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.reinitialize(CacheClientProxy.java:1830)
	at org.apache.geode.internal.cache.tier.sockets.CacheClientNotifier.registerClientInternal(CacheClientNotifier.java:323)
	at org.apache.geode.internal.cache.tier.sockets.CacheClientNotifier.registerClient(CacheClientNotifier.java:192)
	at org.apache.geode.internal.cache.tier.sockets.AcceptorImpl$ClientQueueInitializerTask.run(AcceptorImpl.java:1895)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.geode.internal.cache.tier.sockets.AcceptorImpl.lambda$initializeClientQueueInitializerThreadPool$1(AcceptorImpl.java:663)
	at org.apache.geode.internal.logging.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:119)
	at java.lang.Thread.run(Thread.java:745)
{noformat}
The _socketClosed AtomicBoolean can be reset in CacheClientProxy.reinitialize like:
{noformat}
this._socketClosed.compareAndSet(true, false);
{noformat}
Then when the durable client is killed the second time, its socket is closed:
{noformat}
[warn 2019/10/10 13:17:11.920 PDT <ServerConnection on port 49882 Thread 11> tid=0x4b] ClientHealthMonitor: Unregistering client with member id identity(192.168.1.4(client:21693:loner):49908:ef6751b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]) due to: The connection has been reset while reading the header

[warn 2019/10/10 13:17:11.921 PDT <ServerConnection on port 49882 Thread 11> tid=0x4b] XXX CacheClientProxy.closeSocket socket=Socket[addr=/192.168.1.4,port=49913,localport=49882]; socketIsClosed=false; _socketClosed=false

[warn 2019/10/10 13:17:11.921 PDT <ServerConnection on port 49882 Thread 11> tid=0x4b] XXX SocketCloser.asyncClose socket=Socket[addr=/192.168.1.4,port=49913,localport=49882]; socketIsClosed=false

[warn 2019/10/10 13:17:11.922 PDT <AsyncSocketCloser for 192.168.1.4> tid=0x4d] XXX SocketCloser.inlineClose closed socket=Socket[addr=/192.168.1.4,port=49913,localport=49882]; socketIsClosed=true

[info 2019/10/10 13:17:11.922 PDT <ServerConnection on port 49882 Thread 11> tid=0x4b] CacheClientNotifier: Keeping proxy for durable client named client-1 for 120 seconds CacheClientProxy[identity(192.168.1.4(client:21693:loner):49908:ef6751b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]); port=49913; primary=true; version=GEODE 1.11.0].
{noformat}


> When a durable client is killed for the second time, its socket is not closed properly
> --------------------------------------------------------------------------------------
>
>                 Key: GEODE-7286
>                 URL: https://issues.apache.org/jira/browse/GEODE-7286
>             Project: Geode
>          Issue Type: Bug
>          Components: client queues
>            Reporter: Barrett Oglesby
>            Priority: Major
>
> The first time the durable client is killed, the socket is closed by SocketCloser.inlineClose:
> {noformat}
> [warn 2019/10/10 12:26:07.025 PDT <ServerConnection on port 49494 Thread 4> tid=0x41] ClientHealthMonitor: Unregistering client with member id identity(192.168.1.4(client:17910:loner):49501:cf8f22b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]) due to: The connection has been reset while reading the header
> [warn 2019/10/10 12:26:07.026 PDT <ServerConnection on port 49494 Thread 4> tid=0x41] XXX CacheClientProxy.closeSocket socket=Socket[addr=/192.168.1.4,port=49506,localport=49494]; socketIsClosed=false; _socketClosed=false
> [warn 2019/10/10 12:26:07.026 PDT <ServerConnection on port 49494 Thread 4> tid=0x41] XXX SocketCloser.asyncClose socket=Socket[addr=/192.168.1.4,port=49506,localport=49494]; socketIsClosed=false
> [info 2019/10/10 12:26:07.028 PDT <Client Message Dispatcher for 192.168.1.4(client:17910:loner):49501:cf8f22b7:client (client-1)> tid=0x42] CacheClientProxy[identity(192.168.1.4(client:17910:loner):49501:cf8f22b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]); port=49506; primary=true; version=GEODE 1.11.0] : Pausing processing
> [warn 2019/10/10 12:26:07.031 PDT <AsyncSocketCloser for 192.168.1.4> tid=0x46] XXX SocketCloser.inlineClose closed socket=Socket[addr=/192.168.1.4,port=49506,localport=49494]; socketIsClosed=true
> [info 2019/10/10 12:26:07.031 PDT <ServerConnection on port 49494 Thread 4> tid=0x41] CacheClientNotifier: Keeping proxy for durable client named client-1 for 120 seconds CacheClientProxy[identity(192.168.1.4(client:17910:loner):49501:cf8f22b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]); port=49506; primary=true; version=GEODE 1.11.0].
> {noformat}
> If the client rejoins and is killed again, the socket is not closed because the _socketClosed AtomicBoolean is true from the last time the client closed, so SocketCloser.asyncClose is not called:
> {noformat}
> [warn 2019/10/10 12:26:27.706 PDT <ServerConnection on port 49494 Thread 10> tid=0x4a] ClientHealthMonitor: Unregistering client with member id identity(192.168.1.4(client:17939:loner):49519:62f822b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]) due to: The connection has been reset while reading the header
> [warn 2019/10/10 12:26:27.706 PDT <ServerConnection on port 49494 Thread 10> tid=0x4a] XXX CacheClientProxy.closeSocket socket=Socket[addr=/192.168.1.4,port=49524,localport=49494]; socketIsClosed=false; _socketClosed=true
> [info 2019/10/10 12:26:27.706 PDT <ServerConnection on port 49494 Thread 10> tid=0x4a] CacheClientNotifier: Keeping proxy for durable client named client-1 for 120 seconds CacheClientProxy[identity(192.168.1.4(client:17939:loner):49519:62f822b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]); port=49524; primary=true; version=GEODE 1.11.0].
> {noformat}
> Even when the durable client's expiration task fires, the socket is not closed:
> {noformat}
> [warn 2019/10/10 12:28:27.708 PDT <Timer-2> tid=0x29] CacheClientProxy[identity(192.168.1.4(client:17939:loner):49519:62f822b7:client,connection=2,durableAttributes=DurableClientAttributes[id=client-1; timeout=120]); port=49524; primary=true; version=GEODE 1.11.0] : The expiration task has fired, so this proxy is being terminated.
> [warn 2019/10/10 12:28:27.710 PDT <Timer-2> tid=0x29] XXX CacheClientProxy.closeSocket socket=Socket[addr=/192.168.1.4,port=49524,localport=49494]; socketIsClosed=false; _socketClosed=true
> [warn 2019/10/10 12:28:27.712 PDT <Timer-2> tid=0x29] XXX CacheClientProxy.closeSocket socket=Socket[addr=/192.168.1.4,port=49524,localport=49494]; socketIsClosed=false; _socketClosed=true
> {noformat}
> The AtomicBoolean needs to be reset when the durable client rejoins.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)