[
https://issues.apache.org/jira/browse/GEODE-7284?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16952106#comment-16952106
]
ASF subversion and git services commented on GEODE-7284:
--------------------------------------------------------
Commit 1ed68f9c5a57b84b4616d1eaf553ab5307bbf1c0 in geode's branch
refs/heads/develop from Barry Oglesby
[ https://gitbox.apache.org/repos/asf?p=geode.git;h=1ed68f9 ]
GEODE-7284: Modified CacheClientProxy remoteHostAddress to be unique
> A durable client's CacheClientProxy is sometimes not being kept on the server
> when it should be
> -----------------------------------------------------------------------------------------------
>
> Key: GEODE-7284
> URL: https://issues.apache.org/jira/browse/GEODE-7284
> Project: Geode
> Issue Type: Bug
> Components: client queues
> Reporter: Barrett Oglesby
> Priority: Major
> Time Spent: 40m
> Remaining Estimate: 0h
>
> A durable client's CacheClientProxy is sometimes not being kept on the server
> when it should be
> When a durable client is killed, logging for it on the server should look
> like:
> {noformat}
> [info 2019/10/09 16:40:42.426 PDT <ServerConnection on port 59235 Thread 190>
> tid=0x110] CacheClientNotifier: Keeping proxy for durable client named
> client-9 for 300 seconds
> CacheClientProxy[identity(192.168.1.4(client:36729:loner):59887:9507e5b2:client,connection=2,durableAttributes=DurableClientAttributes[id=client-9;
> timeout=300]); port=59892; primary=true; version=GEODE 1.11.0].
> [info 2019/10/09 16:40:42.413 PDT <Client Message Dispatcher for
> 192.168.1.4(client:36478:loner):59353:71a9e3b2:client (client-9)> tid=0x6e]
> CacheClientProxy[identity(192.168.1.4(client:36729:loner):59887:9507e5b2:client,connection=2,durableAttributes=DurableClientAttributes[id=client-9;
> timeout=300]); port=59892; primary=true; version=GEODE 1.11.0] : Pausing
> processing
> {noformat}
> Sometimes, the logging looks like: (with log-level=fine):
> {noformat}
> [info 2019/10/09 16:40:42.429 PDT <Client Message Dispatcher for
> 192.168.1.4(client:36458:loner):59317:baa2e3b2:client (client-5)> tid=0x60]
> CacheClientProxy[identity(192.168.1.4(client:36717:loner):59851:3301e5b2:client,connection=2,durableAttributes=DurableClientAttributes[id=client-5;
> timeout=300]); port=59856; primary=true; version=GEODE 1.11.0] : Pausing
> processing
> [debug 2019/10/09 16:40:42.428 PDT <ServerConnection on port 59235 Thread
> 176> tid=0x102] CacheClientNotifier: Not keeping proxy for non-durable
> client:
> CacheClientProxy[identity(192.168.1.4(client:36717:loner):59851:3301e5b2:client,connection=2,durableAttributes=DurableClientAttributes[id=client-5;
> timeout=300]); port=59856; primary=true; version=GEODE 1.11.0]
> {noformat}
> On one hand, the Client Message Dispatcher is pausing, but on the other hand,
> the CacheClientProxy is not being kept.
> Thats because of this RejectedExecutionException thrown attempting to
> asynchronously close the CacheClientProxy's socket:
> {noformat}
> java.util.concurrent.RejectedExecutionException
> at
> java.base/java.util.concurrent.ForkJoinPool.externalPush(ForkJoinPool.java:1880)
> at
> java.base/java.util.concurrent.ForkJoinPool.externalSubmit(ForkJoinPool.java:1921)
> at
> java.base/java.util.concurrent.ForkJoinPool.submit(ForkJoinPool.java:2497)
> at
> java.base/java.util.concurrent.ForkJoinPool.submit(ForkJoinPool.java:178)
> at
> org.apache.geode.internal.net.SocketCloser.asyncExecute(SocketCloser.java:163)
> at
> org.apache.geode.internal.net.SocketCloser.asyncClose(SocketCloser.java:191)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.closeSocket(CacheClientProxy.java:955)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.closeTransientFields(CacheClientProxy.java:963)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.pauseDispatching(CacheClientProxy.java:839)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.close(CacheClientProxy.java:788)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientNotifier.closeDeadProxies(CacheClientNotifier.java:1563)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientNotifier.unregisterClient(CacheClientNotifier.java:567)
> at
> org.apache.geode.internal.cache.tier.sockets.ClientHealthMonitor.unregisterClient(ClientHealthMonitor.java:255)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.handleTermination(ServerConnection.java:961)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.handleTermination(ServerConnection.java:882)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.run(ServerConnection.java:1223)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at
> org.apache.geode.internal.cache.tier.sockets.AcceptorImpl.lambda$initializeServerConnectionThreadPool$3(AcceptorImpl.java:674)
> at
> org.apache.geode.internal.logging.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:119)
> at java.base/java.lang.Thread.run(Thread.java:834)
> {noformat}
> This JDK11 stack shows the ForkJoinPool in a closed state.
> Thats because each CacheClientProxy closes its SocketCloser executor here:
> {noformat}
> [warn 2019/10/09 16:55:36.611 PDT <ServerConnection on port 60093 Thread 5>
> tid=0x46] XXX SocketCloser.releaseResourcesForAddress address=192.168.1.4;
> executorService=java.util.concurrent.ForkJoinPool@15099e74[Running,
> parallelism = 1, size = 1, active = 0, running = 0, steals = 1, tasks = 0,
> submissions = 0]
> java.lang.Exception
> at
> org.apache.geode.internal.net.SocketCloser.releaseResourcesForAddress(SocketCloser.java:135)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.closeOtherTransientFields(CacheClientProxy.java:979)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.closeTransientFields(CacheClientProxy.java:969)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.pauseDispatching(CacheClientProxy.java:839)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientProxy.close(CacheClientProxy.java:788)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientNotifier.closeDeadProxies(CacheClientNotifier.java:1563)
> at
> org.apache.geode.internal.cache.tier.sockets.CacheClientNotifier.unregisterClient(CacheClientNotifier.java:567)
> at
> org.apache.geode.internal.cache.tier.sockets.ClientHealthMonitor.unregisterClient(ClientHealthMonitor.java:255)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.handleTermination(ServerConnection.java:961)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.handleTermination(ServerConnection.java:882)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.run(ServerConnection.java:1223)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at
> org.apache.geode.internal.cache.tier.sockets.AcceptorImpl.lambda$initializeServerConnectionThreadPool$3(AcceptorImpl.java:674)
> at
> org.apache.geode.internal.logging.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:119)
> at java.base/java.lang.Thread.run(Thread.java:834)
> {noformat}
> The address in that log message is the CacheClientProxy's _remoteHostAddress.
> Currently, the _remoteHostAddress is set in
> CacheClientProxy.initializeTransientFields like:
> {noformat}
> this._remoteHostAddress = socket.getInetAddress().getHostAddress();
> {noformat}
> So, the _remoteHostAddress will be the same for all CacheClientProxies
> representing clients on the same host.
> When those clients are killed, all the CacheClientProxies are closing the
> same ForkJoinPool. This is causing the RejectedExecutionException for other
> clients closing at the same time.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
