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:10:00 UTC

[jira] [Updated] (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:all-tabpanel ]

Barrett Oglesby updated GEODE-7286:
-----------------------------------
    Description: 
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.


  was:
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 nees to be reset when the durable client rejoins.



> 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)