Bruce J Schuchardt created GEODE-8816:
-----------------------------------------
Summary: CI failure: SerialWanPropagationDUnitTest.
testReplicatedSerialPropagationWithRemoteRegionDestroy3
Key: GEODE-8816
URL: https://issues.apache.org/jira/browse/GEODE-8816
Project: Geode
Issue Type: Bug
Components: wan
Reporter: Bruce J Schuchardt
This test failed with a suspect string showing a functional problem with the
sender queues.
{noformat}
org.apache.geode.internal.cache.wan.serial.SerialWANPropagationDUnitTest >
testReplicatedSerialPropagationWithRemoteRegionDestroy3 FAILED
java.lang.AssertionError: Suspicious strings were written to the log during
this run.
Fix the strings or use IgnoredException.addIgnoredException to ignore.
-----------------------------------------------------------------------
Found suspect string in 'dunit_suspect-vm5.log' at line 737
[error 2021/01/07 01:06:31.894 GMT <P2P message reader for
172.17.0.18(663)<v1>:41005 unshared ordered uid=191 dom #1 local port=49013
remote port=40362> tid=1289] Exception occurred in CacheListener
java.util.concurrent.RejectedExecutionException: Task
org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderEventProcessor$2@3f0ab37b
rejected from java.util.concurrent.ThreadPoolExecutor@1a4d5355[Terminated,
pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 2071]
at
java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
at
java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
at
java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
at
org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderEventProcessor.handlePrimaryDestroy(SerialGatewaySenderEventProcessor.java:607)
at
org.apache.geode.internal.cache.wan.serial.SerialSecondaryGatewayListener.afterDestroy(SerialSecondaryGatewayListener.java:91)
at
org.apache.geode.internal.cache.EnumListenerEvent$AFTER_DESTROY.dispatchEvent(EnumListenerEvent.java:178)
at
org.apache.geode.internal.cache.LocalRegion.dispatchEvent(LocalRegion.java:8265)
at
org.apache.geode.internal.cache.LocalRegion.dispatchListenerEvent(LocalRegion.java:6974)
at
org.apache.geode.internal.cache.LocalRegion.invokeDestroyCallbacks(LocalRegion.java:6775)
at
org.apache.geode.internal.cache.EntryEventImpl.invokeCallbacks(EntryEventImpl.java:2446)
at
org.apache.geode.internal.cache.entries.AbstractRegionEntry.dispatchListenerEvents(AbstractRegionEntry.java:164)
at
org.apache.geode.internal.cache.LocalRegion.basicDestroyPart2(LocalRegion.java:6716)
at
org.apache.geode.internal.cache.map.RegionMapDestroy.destroyExistingEntry(RegionMapDestroy.java:414)
at
org.apache.geode.internal.cache.map.RegionMapDestroy.handleExistingRegionEntry(RegionMapDestroy.java:244)
at
org.apache.geode.internal.cache.map.RegionMapDestroy.destroy(RegionMapDestroy.java:152)
at
org.apache.geode.internal.cache.AbstractRegionMap.destroy(AbstractRegionMap.java:968)
at
org.apache.geode.internal.cache.LocalRegion.mapDestroy(LocalRegion.java:6505)
at
org.apache.geode.internal.cache.LocalRegion.mapDestroy(LocalRegion.java:6479)
at
org.apache.geode.internal.cache.LocalRegionDataView.destroyExistingEntry(LocalRegionDataView.java:59)
at
org.apache.geode.internal.cache.LocalRegion.basicDestroy(LocalRegion.java:6430)
at
org.apache.geode.internal.cache.DistributedRegion.basicDestroy(DistributedRegion.java:1730)
at
org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderQueue$SerialGatewaySenderQueueMetaRegion.basicDestroy(SerialGatewaySenderQueue.java:1387)
at
org.apache.geode.internal.cache.LocalRegion.localDestroy(LocalRegion.java:2230)
at
org.apache.geode.internal.cache.DistributedRegion.localDestroy(DistributedRegion.java:967)
at
org.apache.geode.internal.cache.wan.serial.BatchDestroyOperation$DestroyMessage.operateOnRegion(BatchDestroyOperation.java:121)
at
org.apache.geode.internal.cache.DistributedCacheOperation$CacheOperationMessage.basicProcess(DistributedCacheOperation.java:1208)
at
org.apache.geode.internal.cache.DistributedCacheOperation$CacheOperationMessage.process(DistributedCacheOperation.java:1110)
at
org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:376)
at
org.apache.geode.distributed.internal.DistributionMessage.schedule(DistributionMessage.java:432)
at
org.apache.geode.distributed.internal.ClusterDistributionManager.scheduleIncomingMessage(ClusterDistributionManager.java:2066)
at
org.apache.geode.distributed.internal.ClusterDistributionManager.handleIncomingDMsg(ClusterDistributionManager.java:1831)
at
org.apache.geode.distributed.internal.membership.gms.GMSMembership.dispatchMessage(GMSMembership.java:930)
at
org.apache.geode.distributed.internal.membership.gms.GMSMembership.handleOrDeferMessage(GMSMembership.java:861)
at
org.apache.geode.distributed.internal.membership.gms.GMSMembership.processMessage(GMSMembership.java:1203)
at
org.apache.geode.distributed.internal.DistributionImpl$MyDCReceiver.messageReceived(DistributionImpl.java:828)
at
org.apache.geode.distributed.internal.direct.DirectChannel.receive(DirectChannel.java:614)
at
org.apache.geode.internal.tcp.TCPConduit.messageReceived(TCPConduit.java:679)
at
org.apache.geode.internal.tcp.Connection.dispatchMessage(Connection.java:3268)
at
org.apache.geode.internal.tcp.Connection.readMessage(Connection.java:2993)
at
org.apache.geode.internal.tcp.Connection.processInputBuffer(Connection.java:2797)
at
org.apache.geode.internal.tcp.Connection.readMessages(Connection.java:1651)
at org.apache.geode.internal.tcp.Connection.run(Connection.java:1482)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
{noformat}
The cache was closing when this happened
{noformat}
[vm5] [info 2021/01/07 01:06:31.890 GMT <RMI TCP Connection(1)-172.17.0.18>
tid=0x21] GemFireCache[id = 79187125; isClosing = true; isShutDownAll = false;
created = Thu Jan 07 01:06:27 GMT 2021; server = false; copyOnRead = false;
lockLease = 120; lockTimeout = 60]: Now closing.
[vm5] [info 2021/01/07 01:06:31.890 GMT <Event Processor for GatewaySender_ln>
tid=0x4fe] The event processor is stopped, not to wait for being primary any
more.
[vm5] [error 2021/01/07 01:06:31.894 GMT <P2P message reader for
172.17.0.18(663)<v1>:41005 unshared ordered uid=191 dom #1 local port=49013
remote port=40362> tid=0x509] Exception occurred in CacheListener
[vm5] java.util.concurrent.RejectedExecutionException: Task
org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderEventProcessor$2@3f0ab37b
rejected from java.util.concurrent.ThreadPoolExecutor@1a4d5355[Terminated,
pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 2071]
{noformat}
The method that shuts down the executor does so before nulling out the variable
holding the executor:
{code:java}
private void shutdownListenerExecutor() {
synchronized (listenerObjectLock) {
if (this.executor != null) {
this.executor.shutdown();
this.executor = null;
}
}
}
{code}
The method that submits a task to the executor checks for a null before
submitting it, so there's a race condition where a thread could attempt to
submit a task but the executor has been shut down.
{code:java}
protected void handlePrimaryDestroy(final GatewaySenderEventImpl
gatewayEvent) {
Executor my_executor = this.executor;
synchronized (listenerObjectLock) {
if (my_executor == null) {
// should mean we are now primary
return;
}
my_executor.execute(new Runnable() {
@Override
public void run() {
basicHandlePrimaryDestroy(gatewayEvent.getEventId(), false);
}
});
}
}
{code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
