[GEODE-10333] WANRollingUpgradeNewSenderProcessOldEvent > bothOldAndNewEventsShouldBeProcessedByOldSender[From VmConfiguration{java=8, geode=1.7.0}] fails with ForcedDisconnectException: Member isn't responding to heartbeat requests

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 1.15.0, 1.16.0
• Component/s: membership, tests
• Assignee: Unassigned
• Reporter: Kirk Lund
• Created: 25/May/22 17:57
• Updated: 25/May/22 23:32

Description

NOTE: WANRollingUpgradeNewSenderProcessOldEvent is a dunit test that runs during geode-wan:upgradeTest which is running tests in parallel. To be well-behaved all ports must come from AvailablePortHelper and be well below the range of ephemeral ports.

Precheckin run: https://concourse.apachegeode-ci.info/builds/56371948
Test results: http://files.apachegeode-ci.info/builds/apache-develop-pr/geode-pr-7571/test-results/upgradeTest/1653426563/
Failure occurred: during the upgrade from Geode 1.7.0 (value of junit test parameter)
Test job: upgrade-test-openjdk8
Gradle target: geode-wan:upgradeTest

This failure was seen during repeated precheckin runs for PR #7571. The test does not use GfshRule and we determined that the changes for VmConfiguration are not involved in this failure. Initial analysis of output suggests that some of the following test problems might be contributing:

1. Some ports are using AvailablePortHelper while others seem to be using default ports. Any use of default ports will eventually cause failures of one or more tests when they run in parallel.
2. The membership port range configured for the test is too high. It's up in the ephemeral port range which means it's eventually going to collide with ephemeral ports being used by other processes. This range needs to be much lower.
3. The assertions in WANRollingUpgradeNewSenderProcessOldEvent don't provide enough info so debugging this test will require a lot of digging through log output and studying test code in multiple class files.

To fix this failure, I would start out by fixing up all port usage by the test.

org.apache.geode.test.dunit.RMIException: While invoking org.apache.geode.cache.wan.WANRollingUpgradeDUnitTest$$Lambda$344/1994402702.run in VM 5, Host Host heavy-lifter-f7f182f0-e980-587e-9bf7-d23392538e69.c.apachegeode-ci.internal with 7 VMs, Geode 1.7.0, Java 8
	at org.apache.geode.test.dunit.VM.executeMethodOnObject(VM.java:688)
	at org.apache.geode.test.dunit.VM.invoke(VM.java:496)
	at org.apache.geode.cache.wan.WANRollingUpgradeDUnitTest.startAndConfigureServers(WANRollingUpgradeDUnitTest.java:191)
	at org.apache.geode.cache.wan.WANRollingUpgradeNewSenderProcessOldEvent.bothOldAndNewEventsShouldBeProcessedByOldSender(WANRollingUpgradeNewSenderProcessOldEvent.java:276)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.apache.geode.test.junit.rules.DescribedExternalResource$1.evaluate(DescribedExternalResource.java:45)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:61)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.junit.runners.Suite.runChild(Suite.java:128)
	at org.junit.runners.Suite.runChild(Suite.java:27)
	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
	at org.junit.vintage.engine.execution.RunnerExecutor.execute(RunnerExecutor.java:42)
	at org.junit.vintage.engine.VintageTestEngine.executeAllChildren(VintageTestEngine.java:80)
	at org.junit.vintage.engine.VintageTestEngine.execute(VintageTestEngine.java:72)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:108)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:96)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:75)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.processAllTestClasses(JUnitPlatformTestClassProcessor.java:99)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.access$000(JUnitPlatformTestClassProcessor.java:79)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor.stop(JUnitPlatformTestClassProcessor.java:75)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
	at com.sun.proxy.$Proxy2.stop(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:133)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:182)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:164)
	at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:414)
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56)
	at java.lang.Thread.run(Thread.java:750)
Caused by: org.apache.geode.distributed.DistributedSystemDisconnectedException: Distribution manager on 10.0.2.144(169489)<v1>:49755 started at Tue May 24 18:43:37 UTC 2022: Member isn't responding to heartbeat requests, caused by org.apache.geode.ForcedDisconnectException: Member isn't responding to heartbeat requests
	at org.apache.geode.distributed.internal.ClusterDistributionManager$Stopper.generateCancelledException(ClusterDistributionManager.java:4518)
	at org.apache.geode.distributed.internal.InternalDistributedSystem$Stopper.generateCancelledException(InternalDistributedSystem.java:963)
	at org.apache.geode.internal.cache.GemFireCacheImpl$Stopper.generateCancelledException(GemFireCacheImpl.java:1557)
	at org.apache.geode.CancelCriterion.checkCancelInProgress(CancelCriterion.java:83)
	at org.apache.geode.cache.lucene.internal.LuceneServiceImpl.init(LuceneServiceImpl.java:121)
	at org.apache.geode.internal.cache.GemFireCacheImpl.initializeServices(GemFireCacheImpl.java:1272)
	at org.apache.geode.internal.cache.GemFireCacheImpl.initialize(GemFireCacheImpl.java:1220)
	at org.apache.geode.internal.cache.GemFireCacheImpl.basicCreate(GemFireCacheImpl.java:793)
	at org.apache.geode.internal.cache.GemFireCacheImpl.create(GemFireCacheImpl.java:779)
	at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:177)
	at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:170)
	at org.apache.geode.test.dunit.cache.internal.JUnit4CacheTestCase.createCache(JUnit4CacheTestCase.java:121)
	at org.apache.geode.test.dunit.cache.internal.JUnit4CacheTestCase.getCache(JUnit4CacheTestCase.java:223)
	at org.apache.geode.test.dunit.cache.internal.JUnit4CacheTestCase.getCache(JUnit4CacheTestCase.java:210)
	at org.apache.geode.test.dunit.cache.internal.JUnit4CacheTestCase.getCache(JUnit4CacheTestCase.java:197)
	at org.apache.geode.test.dunit.cache.internal.JUnit4CacheTestCase.getCache(JUnit4CacheTestCase.java:206)
	at org.apache.geode.cache.wan.WANRollingUpgradeDUnitTest.createCache(WANRollingUpgradeDUnitTest.java:276)
	at org.apache.geode.cache.wan.WANRollingUpgradeDUnitTest.createCache(WANRollingUpgradeDUnitTest.java:265)
	at org.apache.geode.cache.wan.WANRollingUpgradeDUnitTest.lambda$startAndConfigureServers$c9407b8f$1(WANRollingUpgradeDUnitTest.java:191)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.geode.test.dunit.internal.MethodInvoker.executeObject(MethodInvoker.java:123)
	at org.apache.geode.test.dunit.internal.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:78)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
	at sun.rmi.transport.Transport$1.run(Transport.java:200)
	at sun.rmi.transport.Transport$1.run(Transport.java:197)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:196)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:573)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:834)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	... 1 more
Caused by: org.apache.geode.ForcedDisconnectException: Member isn't responding to heartbeat requests
	at org.apache.geode.distributed.internal.membership.gms.mgr.GMSMembershipManager.forceDisconnect(GMSMembershipManager.java:2534)
	at org.apache.geode.distributed.internal.membership.gms.membership.GMSJoinLeave.forceDisconnect(GMSJoinLeave.java:1054)
	at org.apache.geode.distributed.internal.membership.gms.membership.GMSJoinLeave.processRemoveRequest(GMSJoinLeave.java:658)
	at org.apache.geode.distributed.internal.membership.gms.membership.GMSJoinLeave.processMessage(GMSJoinLeave.java:1811)
	at org.apache.geode.distributed.internal.membership.gms.messenger.JGroupsMessenger$JGroupsReceiver.receive(JGroupsMessenger.java:1305)
	at org.jgroups.JChannel.invokeCallback(JChannel.java:816)
	at org.jgroups.JChannel.up(JChannel.java:741)
	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1030)
	at org.jgroups.protocols.FRAG2.up(FRAG2.java:165)
	at org.jgroups.protocols.FlowControl.up(FlowControl.java:390)
	at org.jgroups.protocols.UNICAST3.deliverMessage(UNICAST3.java:1077)
	at org.jgroups.protocols.UNICAST3.handleDataReceived(UNICAST3.java:792)
	at org.jgroups.protocols.UNICAST3.up(UNICAST3.java:433)
	at org.apache.geode.distributed.internal.membership.gms.messenger.StatRecorder.up(StatRecorder.java:73)
	at org.apache.geode.distributed.internal.membership.gms.messenger.AddressManager.up(AddressManager.java:72)
	at org.jgroups.protocols.TP.passMessageUp(TP.java:1658)
	at org.jgroups.protocols.TP$SingleMessageHandler.run(TP.java:1876)
	at org.jgroups.util.DirectExecutor.execute(DirectExecutor.java:10)
	at org.jgroups.protocols.TP.handleSingleMessage(TP.java:1789)
	at org.jgroups.protocols.TP.receive(TP.java:1714)
	at org.apache.geode.distributed.internal.membership.gms.messenger.Transport.receive(Transport.java:152)
	at org.jgroups.protocols.UDP$PacketReceiver.run(UDP.java:701)
	... 1 more