[
https://issues.apache.org/jira/browse/IGNITE-14227?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Pavel Pereslegin updated IGNITE-14227:
--------------------------------------
Description:
Partition map exchange may hang if the cluster is deactivated after processing
DynamicCacheChangeBatch but before sending DynamicCacheChangeFailureMessage.
The hang occurs because the current exchange (dynamic cache start) cannot be
completed when the state changed to inactive and exchange future is not
completed (see usage of
{{GridCachePartitionExchangeManager#processEventInactive}} in
{{DiscoveryEventListener}} and
{{GridDhtPartitionsExchangeFuture#onDynamicCacheChangeFail}}).
Reproducer:
{code:java}
public class DynamicCacheStartFailTest extends GridCommonAbstractTest {
@Override protected IgniteConfiguration getConfiguration(String
igniteInstanceName) throws Exception {
IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName);
TcpDiscoverySpi discoSpi = new BlockingDiscoverySpi();
discoSpi.setIpFinder(((TcpDiscoverySpi)cfg.getDiscoverySpi()).getIpFinder());
return cfg.setDiscoverySpi(new BlockingDiscoverySpi())
.setDataStorageConfiguration(new DataStorageConfiguration()
.setDefaultDataRegionConfiguration(new DataRegionConfiguration()
.setMaxSize(100 * 1024 * 1024L)
.setPersistenceEnabled(true)));
}
@Test
public void testRollbackCacheStartOnDeactivate() throws Exception {
IgniteEx crd = startGrids(2);
CacheConfiguration<Object, Object> cfg = new
CacheConfiguration<>("cache1").setDataRegionName("absent");
crd.cluster().state(ACTIVE);
BlockingDiscoverySpi spi =
(BlockingDiscoverySpi)crd.context().discovery().getInjectedDiscoverySpi();
spi.block(msg -> msg instanceof DynamicCacheChangeFailureMessage);
IgniteInternalFuture<IgniteCache<Object, Object>> fut =
GridTestUtils.runAsync(() -> crd.createCache(cfg));
spi.waitBlocked(5_000);
IgniteInternalFuture<?> stateChangeFut = runAsync(() ->
grid(1).cluster().state(ClusterState.INACTIVE));
spi.unblock();
assertThrowsAnyCause(log,
() -> fut.get(getTestTimeout()),
IgniteCheckedException.class, null);
stateChangeFut.get(getTestTimeout());
}
/** */
private static class BlockingDiscoverySpi extends TcpDiscoverySpi {
private final List<DiscoverySpiCustomMessage> blocked = new
CopyOnWriteArrayList<>();
private volatile IgnitePredicate<DiscoveryCustomMessage> blockPred;
@Override public void sendCustomEvent(DiscoverySpiCustomMessage msg)
throws IgniteException {
if (msg instanceof CustomMessageWrapper) {
DiscoveryCustomMessage msg0 =
((CustomMessageWrapper)msg).delegate();
if (blockPred != null && blockPred.apply(msg0)) {
blocked.add(msg);
return;
}
}
super.sendCustomEvent(msg);
}
public synchronized void block(IgnitePredicate<DiscoveryCustomMessage>
pred) {
blockPred = pred;
}
public synchronized void unblock() {
blockPred = null;
for (DiscoverySpiCustomMessage msg : blocked)
sendCustomEvent(msg);
blocked.clear();
}
public void waitBlocked(long timeout) throws
IgniteInterruptedCheckedException {
GridTestUtils.waitForCondition(() -> !blocked.isEmpty(), timeout);
}
}
}
{code}
Typical output:
{noformat}
[2021-02-24 13:37:11,944][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCacheProcessor]
Cache can not be started : cache=cache1
[2021-02-24 13:37:11,944][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCacheProcessor]
Cache can not be started : cache=cache1
[2021-02-24
13:37:11,945][ERROR][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Failed to initialize cache(s) (will try to rollback)
[exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=DiscoveryCustomEvent
[customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=02c46b75, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT],
caches=[o.a.i.i.processors.cache.ExchangeActions$CacheGroupActionData@50838b34]]
class org.apache.ignite.IgniteCheckedException: Requested DataRegion is not
configured: absent
at
org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager.dataRegion(IgniteCacheDatabaseSharedManager.java:911)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.startCacheGroup(GridCacheProcessor.java:2467)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.getOrCreateCacheGroupContext(GridCacheProcessor.java:2205)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheContext(GridCacheProcessor.java:2012)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheStart(GridCacheProcessor.java:1946)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCaches$55a0e703$1(GridCacheProcessor.java:1821)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCachesIfPossible$14(GridCacheProcessor.java:1791)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCaches(GridCacheProcessor.java:1818)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCachesIfPossible(GridCacheProcessor.java:1789)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.processCacheStartRequests(CacheAffinitySharedManager.java:996)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:882)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:1450)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:948)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body0(GridCachePartitionExchangeManager.java:3387)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:3209)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
[2021-02-24
13:37:11,945][ERROR][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Failed to initialize cache(s) (will try to rollback)
[exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=DiscoveryCustomEvent
[customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031926, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=b05182d2, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT],
caches=[o.a.i.i.processors.cache.ExchangeActions$CacheGroupActionData@cc19771]]
class org.apache.ignite.IgniteCheckedException: Requested DataRegion is not
configured: absent
at
org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager.dataRegion(IgniteCacheDatabaseSharedManager.java:911)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.startCacheGroup(GridCacheProcessor.java:2467)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.getOrCreateCacheGroupContext(GridCacheProcessor.java:2205)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheContext(GridCacheProcessor.java:2012)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheStart(GridCacheProcessor.java:1946)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCaches$55a0e703$1(GridCacheProcessor.java:1821)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCachesIfPossible$14(GridCacheProcessor.java:1791)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCaches(GridCacheProcessor.java:1818)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCachesIfPossible(GridCacheProcessor.java:1789)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.processCacheStartRequests(CacheAffinitySharedManager.java:996)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:882)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:1450)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:948)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body0(GridCachePartitionExchangeManager.java:3387)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:3209)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
[2021-02-24 13:37:11,949][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]
[2021-02-24 13:37:11,950][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]
[2021-02-24 13:37:11,952][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ServerLatch [permits=0,
pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid
[id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
[2021-02-24 13:37:11,952][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], ackSent=true, super=CompletableLatch [id=CompletableLatchUid
[id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
[2021-02-24 13:37:11,953][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=LOCAL]
[2021-02-24 13:37:11,953][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=LOCAL]
[2021-02-24 13:37:11,953][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][time] Finished
exchange init [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
crd=true]
[2021-02-24 13:37:11,954][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][time] Finished
exchange init [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
crd=false]
[2021-02-24 13:37:11,955][INFO
][sys-#53%cache.DynamicCacheStartFailTest0%][GridDeploymentLocalStore] Class
locally deployed: class org.apache.ignite.IgniteCheckedException
[2021-02-24 13:37:11,955][INFO
][sys-#53%cache.DynamicCacheStartFailTest0%][GridDeploymentLocalStore] Class
locally deployed: class [Ljava.lang.StackTraceElement;
[2021-02-24 13:37:11,955][INFO
][sys-#53%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Coordinator received single message [ver=AffinityTopologyVersion [topVer=2,
minorTopVer=2], node=02c46b75-6648-4796-88b0-7ce6df700001, allReceived=true]
[2021-02-24 13:37:12,133][INFO
][async-runnable-runner-1][GridClusterStateProcessor] Sending deactivate
cluster request with BaselineTopology null
[2021-02-24 13:37:12,137][INFO
][disco-notifier-worker-#54%cache.DynamicCacheStartFailTest0%][GridClusterStateProcessor]
Received deactivate cluster request with BaselineTopology: null initiator node
ID: 02c46b75-6648-4796-88b0-7ce6df700001
[2021-02-24 13:37:12,138][INFO
][disco-notifier-worker-#54%cache.DynamicCacheStartFailTest0%][GridClusterStateProcessor]
Started state transition: deactivate cluster
[2021-02-24 13:37:12,139][INFO
][disco-notifier-worker-#116%cache.DynamicCacheStartFailTest1%][GridClusterStateProcessor]
Received deactivate cluster request with BaselineTopology: null initiator node
ID: 02c46b75-6648-4796-88b0-7ce6df700001
[2021-02-24 13:37:12,140][INFO
][disco-notifier-worker-#116%cache.DynamicCacheStartFailTest1%][GridClusterStateProcessor]
Started state transition: deactivate cluster
[2021-02-24 13:37:12,156][INFO
][disco-event-worker-#125%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
Ignore event, cluster is inactive: DiscoveryCustomEvent
[customMsg=DynamicCacheChangeFailureMessage [cacheNames=ArrayList [cache1],
id=b062d93d771-b05182d2-c6e8-4b5b-bde2-576e1e700000,
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=null, nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
cause=class org.apache.ignite.IgniteCheckedException: Failed to complete
exchange process., exchangeActions=ExchangeActions [startCaches=null,
stopCaches=[cache1], startGrps=[], stopGrps=[cache1, destroy=true],
resetParts=null, stateChangeRequest=null]], affTopVer=AffinityTopologyVersion
[topVer=2, minorTopVer=3], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
nodeId8=02c46b75, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163032148]]
[2021-02-24 13:37:12,157][INFO
][disco-event-worker-#59%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
Ignore event, cluster is inactive: DiscoveryCustomEvent
[customMsg=DynamicCacheChangeFailureMessage [cacheNames=ArrayList [cache1],
id=b062d93d771-b05182d2-c6e8-4b5b-bde2-576e1e700000,
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=DiscoveryCustomEvent
[customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163032148, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]],
nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT], cause=class
org.apache.ignite.IgniteCheckedException: Failed to complete exchange process.,
exchangeActions=ExchangeActions [startCaches=null, stopCaches=[cache1],
startGrps=[], stopGrps=[cache1, destroy=true], resetParts=null,
stateChangeRequest=null]], affTopVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163032148, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163032148]]
[2021-02-24 13:37:13,453][INFO
][sys-#176%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
Delay process full message without exchange id (there is exchange in progress)
[nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000]
[2021-02-24 13:37:31,954][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Failed to
wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], node=b05182d2-c6e8-4b5b-bde2-576e1e700000]. Dumping pending
objects that might be the cause:
[2021-02-24 13:37:31,955][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Failed to
wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], node=02c46b75-6648-4796-88b0-7ce6df700001]. Dumping pending
objects that might be the cause:
[2021-02-24 13:37:31,956][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Ready
affinity version: AffinityTopologyVersion [topVer=2, minorTopVer=1]
[2021-02-24 13:37:31,956][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Ready
affinity version: AffinityTopologyVersion [topVer=2, minorTopVer=1]
[2021-02-24 13:37:31,964][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Last
exchange future: GridDhtPartitionsExchangeFuture
[firstDiscoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=02c46b75, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], crd=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
discoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=02c46b75, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT], added=true, exchangeType=ALL,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=425645765], init=true, lastVer=null, partReleaseFut=PartitionReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[ExplicitLockReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], AtomicUpdateReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
DataStreamerReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], LocalTxReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
AllTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[RemoteTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]]]]]], exchActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], affChangeMsg=null,
centralizedAff=false, forceAffReassignment=false, exchangeLocE=class
o.a.i.IgniteCheckedException: Failed to initialize exchange locally
[locNodeId=02c46b75-6648-4796-88b0-7ce6df700001],
cacheChangeFailureMsgSent=false, done=false, state=SRV,
registerCachesFuture=null, startTime=1614163031933, initTime=1614163031938,
rebalancedInfo=null, affinityReassign=false,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, evtLatch=0,
remaining=HashSet [b05182d2-c6e8-4b5b-bde2-576e1e700000],
mergedJoinExchMsgs=null, awaitMergedMsgs=0, super=GridFutureAdapter
[ignoreInterrupts=false, state=INIT, res=null, hash=1833752790]]
[2021-02-24 13:37:31,964][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
First 10 pending exchange futures [total=1]
[2021-02-24 13:37:31,964][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Last
exchange future: GridDhtPartitionsExchangeFuture
[firstDiscoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=b05182d2, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], crd=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
discoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=b05182d2, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT], added=true, exchangeType=ALL,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1191663263], init=true, lastVer=GridCacheVersion [topVer=0,
order=1614163030229, nodeOrder=0], partReleaseFut=PartitionReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[ExplicitLockReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], AtomicUpdateReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
DataStreamerReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], LocalTxReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
AllTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[RemoteTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]]]]]], exchActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], affChangeMsg=null,
centralizedAff=false, forceAffReassignment=false, exchangeLocE=class
o.a.i.IgniteCheckedException: Failed to initialize exchange locally
[locNodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000],
cacheChangeFailureMsgSent=true, done=false, state=CRD,
registerCachesFuture=null, startTime=1614163031932, initTime=1614163031938,
rebalancedInfo=null, affinityReassign=false,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, evtLatch=0,
remaining=HashSet [], mergedJoinExchMsgs=null, awaitMergedMsgs=0,
super=GridFutureAdapter [ignoreInterrupts=false, state=INIT, res=null,
hash=2101726312]]
[2021-02-24 13:37:31,966][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
First 10 pending exchange futures [total=1]
[2021-02-24 13:37:31,966][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
>>> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,968][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
>>> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163031715, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,972][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Last 10
exchange futures (total: 3):
[2021-02-24 13:37:31,972][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163031715, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,973][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,973][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163031715, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=true, done=true, newCrdFut=null]
{noformat}
was:
Partition map exchange may hang if the cluster is deactivated after processing
DynamicCacheChangeBatch but before sending DynamicCacheChangeFailureMessage.
The hang occurs because the current exchange (dynamic cache start) cannot be
completed when the state changed to inactive and exchange future is not
completed (see usage of GridCachePartitionExchangeManager#processEventInactive
in DiscoveryEventListener and
GridDhtPartitionsExchangeFuture#onDynamicCacheChangeFail).
Reproducer:
{code:java}
public class DynamicCacheStartFailTest extends GridCommonAbstractTest {
@Override protected IgniteConfiguration getConfiguration(String
igniteInstanceName) throws Exception {
IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName);
TcpDiscoverySpi discoSpi = new BlockingDiscoverySpi();
discoSpi.setIpFinder(((TcpDiscoverySpi)cfg.getDiscoverySpi()).getIpFinder());
return cfg.setDiscoverySpi(new BlockingDiscoverySpi())
.setDataStorageConfiguration(new DataStorageConfiguration()
.setDefaultDataRegionConfiguration(new DataRegionConfiguration()
.setMaxSize(100 * 1024 * 1024L)
.setPersistenceEnabled(true)));
}
@Test
public void testRollbackCacheStartOnDeactivate() throws Exception {
IgniteEx crd = startGrids(2);
CacheConfiguration<Object, Object> cfg = new
CacheConfiguration<>("cache1").setDataRegionName("absent");
crd.cluster().state(ACTIVE);
BlockingDiscoverySpi spi =
(BlockingDiscoverySpi)crd.context().discovery().getInjectedDiscoverySpi();
spi.block(msg -> msg instanceof DynamicCacheChangeFailureMessage);
IgniteInternalFuture<IgniteCache<Object, Object>> fut =
GridTestUtils.runAsync(() -> crd.createCache(cfg));
spi.waitBlocked(5_000);
IgniteInternalFuture<?> stateChangeFut = runAsync(() ->
grid(1).cluster().state(ClusterState.INACTIVE));
spi.unblock();
assertThrowsAnyCause(log,
() -> fut.get(getTestTimeout()),
IgniteCheckedException.class, null);
stateChangeFut.get(getTestTimeout());
}
/** */
private static class BlockingDiscoverySpi extends TcpDiscoverySpi {
private final List<DiscoverySpiCustomMessage> blocked = new
CopyOnWriteArrayList<>();
private volatile IgnitePredicate<DiscoveryCustomMessage> blockPred;
@Override public void sendCustomEvent(DiscoverySpiCustomMessage msg)
throws IgniteException {
if (msg instanceof CustomMessageWrapper) {
DiscoveryCustomMessage msg0 =
((CustomMessageWrapper)msg).delegate();
if (blockPred != null && blockPred.apply(msg0)) {
blocked.add(msg);
return;
}
}
super.sendCustomEvent(msg);
}
public synchronized void block(IgnitePredicate<DiscoveryCustomMessage>
pred) {
blockPred = pred;
}
public synchronized void unblock() {
blockPred = null;
for (DiscoverySpiCustomMessage msg : blocked)
sendCustomEvent(msg);
blocked.clear();
}
public void waitBlocked(long timeout) throws
IgniteInterruptedCheckedException {
GridTestUtils.waitForCondition(() -> !blocked.isEmpty(), timeout);
}
}
}
{code}
Typical output:
{noformat}
[2021-02-24 13:37:11,944][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCacheProcessor]
Cache can not be started : cache=cache1
[2021-02-24 13:37:11,944][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCacheProcessor]
Cache can not be started : cache=cache1
[2021-02-24
13:37:11,945][ERROR][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Failed to initialize cache(s) (will try to rollback)
[exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=DiscoveryCustomEvent
[customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=02c46b75, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT],
caches=[o.a.i.i.processors.cache.ExchangeActions$CacheGroupActionData@50838b34]]
class org.apache.ignite.IgniteCheckedException: Requested DataRegion is not
configured: absent
at
org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager.dataRegion(IgniteCacheDatabaseSharedManager.java:911)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.startCacheGroup(GridCacheProcessor.java:2467)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.getOrCreateCacheGroupContext(GridCacheProcessor.java:2205)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheContext(GridCacheProcessor.java:2012)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheStart(GridCacheProcessor.java:1946)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCaches$55a0e703$1(GridCacheProcessor.java:1821)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCachesIfPossible$14(GridCacheProcessor.java:1791)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCaches(GridCacheProcessor.java:1818)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCachesIfPossible(GridCacheProcessor.java:1789)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.processCacheStartRequests(CacheAffinitySharedManager.java:996)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:882)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:1450)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:948)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body0(GridCachePartitionExchangeManager.java:3387)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:3209)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
[2021-02-24
13:37:11,945][ERROR][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Failed to initialize cache(s) (will try to rollback)
[exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=DiscoveryCustomEvent
[customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031926, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=b05182d2, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT],
caches=[o.a.i.i.processors.cache.ExchangeActions$CacheGroupActionData@cc19771]]
class org.apache.ignite.IgniteCheckedException: Requested DataRegion is not
configured: absent
at
org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager.dataRegion(IgniteCacheDatabaseSharedManager.java:911)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.startCacheGroup(GridCacheProcessor.java:2467)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.getOrCreateCacheGroupContext(GridCacheProcessor.java:2205)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheContext(GridCacheProcessor.java:2012)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheStart(GridCacheProcessor.java:1946)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCaches$55a0e703$1(GridCacheProcessor.java:1821)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCachesIfPossible$14(GridCacheProcessor.java:1791)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCaches(GridCacheProcessor.java:1818)
at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCachesIfPossible(GridCacheProcessor.java:1789)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.processCacheStartRequests(CacheAffinitySharedManager.java:996)
at
org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:882)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:1450)
at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:948)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body0(GridCachePartitionExchangeManager.java:3387)
at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:3209)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
[2021-02-24 13:37:11,949][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]
[2021-02-24 13:37:11,950][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]
[2021-02-24 13:37:11,952][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ServerLatch [permits=0,
pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid
[id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
[2021-02-24 13:37:11,952][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], ackSent=true, super=CompletableLatch [id=CompletableLatchUid
[id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
[2021-02-24 13:37:11,953][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=LOCAL]
[2021-02-24 13:37:11,953][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=LOCAL]
[2021-02-24 13:37:11,953][INFO
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][time] Finished
exchange init [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
crd=true]
[2021-02-24 13:37:11,954][INFO
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][time] Finished
exchange init [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
crd=false]
[2021-02-24 13:37:11,955][INFO
][sys-#53%cache.DynamicCacheStartFailTest0%][GridDeploymentLocalStore] Class
locally deployed: class org.apache.ignite.IgniteCheckedException
[2021-02-24 13:37:11,955][INFO
][sys-#53%cache.DynamicCacheStartFailTest0%][GridDeploymentLocalStore] Class
locally deployed: class [Ljava.lang.StackTraceElement;
[2021-02-24 13:37:11,955][INFO
][sys-#53%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
Coordinator received single message [ver=AffinityTopologyVersion [topVer=2,
minorTopVer=2], node=02c46b75-6648-4796-88b0-7ce6df700001, allReceived=true]
[2021-02-24 13:37:12,133][INFO
][async-runnable-runner-1][GridClusterStateProcessor] Sending deactivate
cluster request with BaselineTopology null
[2021-02-24 13:37:12,137][INFO
][disco-notifier-worker-#54%cache.DynamicCacheStartFailTest0%][GridClusterStateProcessor]
Received deactivate cluster request with BaselineTopology: null initiator node
ID: 02c46b75-6648-4796-88b0-7ce6df700001
[2021-02-24 13:37:12,138][INFO
][disco-notifier-worker-#54%cache.DynamicCacheStartFailTest0%][GridClusterStateProcessor]
Started state transition: deactivate cluster
[2021-02-24 13:37:12,139][INFO
][disco-notifier-worker-#116%cache.DynamicCacheStartFailTest1%][GridClusterStateProcessor]
Received deactivate cluster request with BaselineTopology: null initiator node
ID: 02c46b75-6648-4796-88b0-7ce6df700001
[2021-02-24 13:37:12,140][INFO
][disco-notifier-worker-#116%cache.DynamicCacheStartFailTest1%][GridClusterStateProcessor]
Started state transition: deactivate cluster
[2021-02-24 13:37:12,156][INFO
][disco-event-worker-#125%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
Ignore event, cluster is inactive: DiscoveryCustomEvent
[customMsg=DynamicCacheChangeFailureMessage [cacheNames=ArrayList [cache1],
id=b062d93d771-b05182d2-c6e8-4b5b-bde2-576e1e700000,
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=null, nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
cause=class org.apache.ignite.IgniteCheckedException: Failed to complete
exchange process., exchangeActions=ExchangeActions [startCaches=null,
stopCaches=[cache1], startGrps=[], stopGrps=[cache1, destroy=true],
resetParts=null, stateChangeRequest=null]], affTopVer=AffinityTopologyVersion
[topVer=2, minorTopVer=3], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
nodeId8=02c46b75, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163032148]]
[2021-02-24 13:37:12,157][INFO
][disco-event-worker-#59%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
Ignore event, cluster is inactive: DiscoveryCustomEvent
[customMsg=DynamicCacheChangeFailureMessage [cacheNames=ArrayList [cache1],
id=b062d93d771-b05182d2-c6e8-4b5b-bde2-576e1e700000,
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], discoEvt=DiscoveryCustomEvent
[customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163032148, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]],
nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT], cause=class
org.apache.ignite.IgniteCheckedException: Failed to complete exchange process.,
exchangeActions=ExchangeActions [startCaches=null, stopCaches=[cache1],
startGrps=[], stopGrps=[cache1, destroy=true], resetParts=null,
stateChangeRequest=null]], affTopVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163032148, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163032148]]
[2021-02-24 13:37:13,453][INFO
][sys-#176%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
Delay process full message without exchange id (there is exchange in progress)
[nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000]
[2021-02-24 13:37:31,954][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Failed to
wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], node=b05182d2-c6e8-4b5b-bde2-576e1e700000]. Dumping pending
objects that might be the cause:
[2021-02-24 13:37:31,955][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Failed to
wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], node=02c46b75-6648-4796-88b0-7ce6df700001]. Dumping pending
objects that might be the cause:
[2021-02-24 13:37:31,956][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Ready
affinity version: AffinityTopologyVersion [topVer=2, minorTopVer=1]
[2021-02-24 13:37:31,956][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Ready
affinity version: AffinityTopologyVersion [topVer=2, minorTopVer=1]
[2021-02-24 13:37:31,964][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Last
exchange future: GridDhtPartitionsExchangeFuture
[firstDiscoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=02c46b75, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], crd=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
discoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163031766, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=02c46b75, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT], added=true, exchangeType=ALL,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=425645765], init=true, lastVer=null, partReleaseFut=PartitionReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[ExplicitLockReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], AtomicUpdateReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
DataStreamerReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], LocalTxReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
AllTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[RemoteTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]]]]]], exchActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], affChangeMsg=null,
centralizedAff=false, forceAffReassignment=false, exchangeLocE=class
o.a.i.IgniteCheckedException: Failed to initialize exchange locally
[locNodeId=02c46b75-6648-4796-88b0-7ce6df700001],
cacheChangeFailureMsgSent=false, done=false, state=SRV,
registerCachesFuture=null, startTime=1614163031933, initTime=1614163031938,
rebalancedInfo=null, affinityReassign=false,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, evtLatch=0,
remaining=HashSet [b05182d2-c6e8-4b5b-bde2-576e1e700000],
mergedJoinExchMsgs=null, awaitMergedMsgs=0, super=GridFutureAdapter
[ignoreInterrupts=false, state=INIT, res=null, hash=1833752790]]
[2021-02-24 13:37:31,964][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
First 10 pending exchange futures [total=1]
[2021-02-24 13:37:31,964][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Last
exchange future: GridDhtPartitionsExchangeFuture
[firstDiscoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=b05182d2, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], crd=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
discoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
[id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false, stop=false,
destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], startCaches=false],
affTopVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
super=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], topVer=2, msgTemplate=null,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, nodeId8=b05182d2, msg=null,
type=DISCOVERY_CUSTOM_EVT, tstamp=1614163031926]], nodeId=b05182d2,
evt=DISCOVERY_CUSTOM_EVT], added=true, exchangeType=ALL,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1191663263], init=true, lastVer=GridCacheVersion [topVer=0,
order=1614163030229, nodeOrder=0], partReleaseFut=PartitionReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[ExplicitLockReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], AtomicUpdateReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
DataStreamerReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]], LocalTxReleaseFuture
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
AllTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
futures=[RemoteTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], futures=[]]]]]], exchActions=ExchangeActions
[startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
resetParts=null, stateChangeRequest=null], affChangeMsg=null,
centralizedAff=false, forceAffReassignment=false, exchangeLocE=class
o.a.i.IgniteCheckedException: Failed to initialize exchange locally
[locNodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000],
cacheChangeFailureMsgSent=true, done=false, state=CRD,
registerCachesFuture=null, startTime=1614163031932, initTime=1614163031938,
rebalancedInfo=null, affinityReassign=false,
span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, evtLatch=0,
remaining=HashSet [], mergedJoinExchMsgs=null, awaitMergedMsgs=0,
super=GridFutureAdapter [ignoreInterrupts=false, state=INIT, res=null,
hash=2101726312]]
[2021-02-24 13:37:31,966][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
First 10 pending exchange futures [total=1]
[2021-02-24 13:37:31,966][WARN
][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
>>> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,968][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
>>> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163031715, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,972][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Last 10
exchange futures (total: 3):
[2021-02-24 13:37:31,972][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163031715, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,973][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
lastExchangeTime=1614163051747, loc=true, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=false, done=false, newCrdFut=null]
[2021-02-24 13:37:31,973][WARN
][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
[id=02c46b75-6648-4796-88b0-7ce6df700001,
consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2, intOrder=2,
lastExchangeTime=1614163031715, loc=false, ver=2.11.0#20210224-sha1:00000000,
isClient=false], rebalanced=true, done=true, newCrdFut=null]
{noformat}
> Partition map exchange may hang if the cluster is deactivated during cache
> start failure handling.
> --------------------------------------------------------------------------------------------------
>
> Key: IGNITE-14227
> URL: https://issues.apache.org/jira/browse/IGNITE-14227
> Project: Ignite
> Issue Type: Bug
> Reporter: Pavel Pereslegin
> Priority: Major
>
> Partition map exchange may hang if the cluster is deactivated after
> processing DynamicCacheChangeBatch but before sending
> DynamicCacheChangeFailureMessage.
> The hang occurs because the current exchange (dynamic cache start) cannot be
> completed when the state changed to inactive and exchange future is not
> completed (see usage of
> {{GridCachePartitionExchangeManager#processEventInactive}} in
> {{DiscoveryEventListener}} and
> {{GridDhtPartitionsExchangeFuture#onDynamicCacheChangeFail}}).
> Reproducer:
> {code:java}
> public class DynamicCacheStartFailTest extends GridCommonAbstractTest {
> @Override protected IgniteConfiguration getConfiguration(String
> igniteInstanceName) throws Exception {
> IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName);
> TcpDiscoverySpi discoSpi = new BlockingDiscoverySpi();
>
> discoSpi.setIpFinder(((TcpDiscoverySpi)cfg.getDiscoverySpi()).getIpFinder());
> return cfg.setDiscoverySpi(new BlockingDiscoverySpi())
> .setDataStorageConfiguration(new DataStorageConfiguration()
> .setDefaultDataRegionConfiguration(new
> DataRegionConfiguration()
> .setMaxSize(100 * 1024 * 1024L)
> .setPersistenceEnabled(true)));
> }
> @Test
> public void testRollbackCacheStartOnDeactivate() throws Exception {
> IgniteEx crd = startGrids(2);
> CacheConfiguration<Object, Object> cfg = new
> CacheConfiguration<>("cache1").setDataRegionName("absent");
> crd.cluster().state(ACTIVE);
> BlockingDiscoverySpi spi =
> (BlockingDiscoverySpi)crd.context().discovery().getInjectedDiscoverySpi();
> spi.block(msg -> msg instanceof DynamicCacheChangeFailureMessage);
> IgniteInternalFuture<IgniteCache<Object, Object>> fut =
> GridTestUtils.runAsync(() -> crd.createCache(cfg));
> spi.waitBlocked(5_000);
> IgniteInternalFuture<?> stateChangeFut = runAsync(() ->
> grid(1).cluster().state(ClusterState.INACTIVE));
> spi.unblock();
> assertThrowsAnyCause(log,
> () -> fut.get(getTestTimeout()),
> IgniteCheckedException.class, null);
> stateChangeFut.get(getTestTimeout());
> }
> /** */
> private static class BlockingDiscoverySpi extends TcpDiscoverySpi {
> private final List<DiscoverySpiCustomMessage> blocked = new
> CopyOnWriteArrayList<>();
> private volatile IgnitePredicate<DiscoveryCustomMessage> blockPred;
> @Override public void sendCustomEvent(DiscoverySpiCustomMessage msg)
> throws IgniteException {
> if (msg instanceof CustomMessageWrapper) {
> DiscoveryCustomMessage msg0 =
> ((CustomMessageWrapper)msg).delegate();
> if (blockPred != null && blockPred.apply(msg0)) {
> blocked.add(msg);
> return;
> }
> }
> super.sendCustomEvent(msg);
> }
> public synchronized void
> block(IgnitePredicate<DiscoveryCustomMessage> pred) {
> blockPred = pred;
> }
> public synchronized void unblock() {
> blockPred = null;
> for (DiscoverySpiCustomMessage msg : blocked)
> sendCustomEvent(msg);
> blocked.clear();
> }
> public void waitBlocked(long timeout) throws
> IgniteInterruptedCheckedException {
> GridTestUtils.waitForCondition(() -> !blocked.isEmpty(), timeout);
> }
> }
> }
> {code}
> Typical output:
> {noformat}
> [2021-02-24 13:37:11,944][WARN
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCacheProcessor]
> Cache can not be started : cache=cache1
> [2021-02-24 13:37:11,944][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCacheProcessor]
> Cache can not be started : cache=cache1
> [2021-02-24
> 13:37:11,945][ERROR][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
> Failed to initialize cache(s) (will try to rollback)
> [exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], discoEvt=DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeBatch
> [id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
> [DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
> nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false,
> stop=false, destroy=false, disabledAfterStartfalse]],
> exchangeActions=ExchangeActions [startCaches=[cache1], stopCaches=null,
> startGrps=[cache1], stopGrps=[], resetParts=null, stateChangeRequest=null],
> startCaches=false], affTopVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163031766, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null, span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=02c46b75, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1614163031926]], nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
> caches=[o.a.i.i.processors.cache.ExchangeActions$CacheGroupActionData@50838b34]]
> class org.apache.ignite.IgniteCheckedException: Requested DataRegion is not
> configured: absent
> at
> org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager.dataRegion(IgniteCacheDatabaseSharedManager.java:911)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.startCacheGroup(GridCacheProcessor.java:2467)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.getOrCreateCacheGroupContext(GridCacheProcessor.java:2205)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheContext(GridCacheProcessor.java:2012)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheStart(GridCacheProcessor.java:1946)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCaches$55a0e703$1(GridCacheProcessor.java:1821)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCachesIfPossible$14(GridCacheProcessor.java:1791)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCaches(GridCacheProcessor.java:1818)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCachesIfPossible(GridCacheProcessor.java:1789)
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.processCacheStartRequests(CacheAffinitySharedManager.java:996)
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:882)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:1450)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:948)
> at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body0(GridCachePartitionExchangeManager.java:3387)
> at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:3209)
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
> at java.lang.Thread.run(Thread.java:748)
> [2021-02-24
> 13:37:11,945][ERROR][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
> Failed to initialize cache(s) (will try to rollback)
> [exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], discoEvt=DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeBatch
> [id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
> [DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
> nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false,
> stop=false, destroy=false, disabledAfterStartfalse]],
> exchangeActions=ExchangeActions [startCaches=[cache1], stopCaches=null,
> startGrps=[cache1], stopGrps=[], resetParts=null, stateChangeRequest=null],
> startCaches=false], affTopVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163031926, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null, span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1614163031926]], nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
> caches=[o.a.i.i.processors.cache.ExchangeActions$CacheGroupActionData@cc19771]]
> class org.apache.ignite.IgniteCheckedException: Requested DataRegion is not
> configured: absent
> at
> org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager.dataRegion(IgniteCacheDatabaseSharedManager.java:911)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.startCacheGroup(GridCacheProcessor.java:2467)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.getOrCreateCacheGroupContext(GridCacheProcessor.java:2205)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheContext(GridCacheProcessor.java:2012)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareCacheStart(GridCacheProcessor.java:1946)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCaches$55a0e703$1(GridCacheProcessor.java:1821)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$prepareStartCachesIfPossible$14(GridCacheProcessor.java:1791)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCaches(GridCacheProcessor.java:1818)
> at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.prepareStartCachesIfPossible(GridCacheProcessor.java:1789)
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.processCacheStartRequests(CacheAffinitySharedManager.java:996)
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:882)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:1450)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:948)
> at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body0(GridCachePartitionExchangeManager.java:3387)
> at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:3209)
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
> at java.lang.Thread.run(Thread.java:748)
> [2021-02-24 13:37:11,949][INFO
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
> Finished waiting for partition release future
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
> futInfo=NA, mode=DISTRIBUTED]
> [2021-02-24 13:37:11,950][INFO
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
> Finished waiting for partition release future
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
> futInfo=NA, mode=DISTRIBUTED]
> [2021-02-24 13:37:11,952][INFO
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
> Finished waiting for partitions release latch: ServerLatch [permits=0,
> pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid
> [id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
> [2021-02-24 13:37:11,952][INFO
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
> Finished waiting for partitions release latch: ClientLatch
> [coordinator=TcpDiscoveryNode [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163031766, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], ackSent=true,
> super=CompletableLatch [id=CompletableLatchUid [id=exchange,
> topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
> [2021-02-24 13:37:11,953][INFO
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
> Finished waiting for partition release future
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
> futInfo=NA, mode=LOCAL]
> [2021-02-24 13:37:11,953][INFO
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridDhtPartitionsExchangeFuture]
> Finished waiting for partition release future
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
> futInfo=NA, mode=LOCAL]
> [2021-02-24 13:37:11,953][INFO
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][time] Finished
> exchange init [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
> crd=true]
> [2021-02-24 13:37:11,954][INFO
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][time] Finished
> exchange init [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
> crd=false]
> [2021-02-24 13:37:11,955][INFO
> ][sys-#53%cache.DynamicCacheStartFailTest0%][GridDeploymentLocalStore] Class
> locally deployed: class org.apache.ignite.IgniteCheckedException
> [2021-02-24 13:37:11,955][INFO
> ][sys-#53%cache.DynamicCacheStartFailTest0%][GridDeploymentLocalStore] Class
> locally deployed: class [Ljava.lang.StackTraceElement;
> [2021-02-24 13:37:11,955][INFO
> ][sys-#53%cache.DynamicCacheStartFailTest0%][GridDhtPartitionsExchangeFuture]
> Coordinator received single message [ver=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], node=02c46b75-6648-4796-88b0-7ce6df700001, allReceived=true]
> [2021-02-24 13:37:12,133][INFO
> ][async-runnable-runner-1][GridClusterStateProcessor] Sending deactivate
> cluster request with BaselineTopology null
> [2021-02-24 13:37:12,137][INFO
> ][disco-notifier-worker-#54%cache.DynamicCacheStartFailTest0%][GridClusterStateProcessor]
> Received deactivate cluster request with BaselineTopology: null initiator
> node ID: 02c46b75-6648-4796-88b0-7ce6df700001
> [2021-02-24 13:37:12,138][INFO
> ][disco-notifier-worker-#54%cache.DynamicCacheStartFailTest0%][GridClusterStateProcessor]
> Started state transition: deactivate cluster
> [2021-02-24 13:37:12,139][INFO
> ][disco-notifier-worker-#116%cache.DynamicCacheStartFailTest1%][GridClusterStateProcessor]
> Received deactivate cluster request with BaselineTopology: null initiator
> node ID: 02c46b75-6648-4796-88b0-7ce6df700001
> [2021-02-24 13:37:12,140][INFO
> ][disco-notifier-worker-#116%cache.DynamicCacheStartFailTest1%][GridClusterStateProcessor]
> Started state transition: deactivate cluster
> [2021-02-24 13:37:12,156][INFO
> ][disco-event-worker-#125%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
> Ignore event, cluster is inactive: DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeFailureMessage [cacheNames=ArrayList [cache1],
> id=b062d93d771-b05182d2-c6e8-4b5b-bde2-576e1e700000,
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], discoEvt=null, nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
> cause=class org.apache.ignite.IgniteCheckedException: Failed to complete
> exchange process., exchangeActions=ExchangeActions [startCaches=null,
> stopCaches=[cache1], startGrps=[], stopGrps=[cache1, destroy=true],
> resetParts=null, stateChangeRequest=null]], affTopVer=AffinityTopologyVersion
> [topVer=2, minorTopVer=3], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163031766, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null,
> span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=02c46b75, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163032148]]
> [2021-02-24 13:37:12,157][INFO
> ][disco-event-worker-#59%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
> Ignore event, cluster is inactive: DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeFailureMessage [cacheNames=ArrayList [cache1],
> id=b062d93d771-b05182d2-c6e8-4b5b-bde2-576e1e700000,
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], discoEvt=DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeBatch
> [id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
> [DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
> nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false,
> stop=false, destroy=false, disabledAfterStartfalse]],
> exchangeActions=ExchangeActions [startCaches=[cache1], stopCaches=null,
> startGrps=[cache1], stopGrps=[], resetParts=null, stateChangeRequest=null],
> startCaches=false], affTopVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163032148, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null,
> span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1614163031926]], nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
> cause=class org.apache.ignite.IgniteCheckedException: Failed to complete
> exchange process., exchangeActions=ExchangeActions [startCaches=null,
> stopCaches=[cache1], startGrps=[], stopGrps=[cache1, destroy=true],
> resetParts=null, stateChangeRequest=null]], affTopVer=AffinityTopologyVersion
> [topVer=2, minorTopVer=3], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163032148, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null,
> span=org.apache.ignite.internal.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT, tstamp=1614163032148]]
> [2021-02-24 13:37:13,453][INFO
> ][sys-#176%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
> Delay process full message without exchange id (there is exchange in
> progress) [nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000]
> [2021-02-24 13:37:31,954][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Failed
> to wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], node=b05182d2-c6e8-4b5b-bde2-576e1e700000]. Dumping pending
> objects that might be the cause:
> [2021-02-24 13:37:31,955][WARN
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Failed
> to wait for partition map exchange [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], node=02c46b75-6648-4796-88b0-7ce6df700001]. Dumping pending
> objects that might be the cause:
> [2021-02-24 13:37:31,956][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Ready
> affinity version: AffinityTopologyVersion [topVer=2, minorTopVer=1]
> [2021-02-24 13:37:31,956][WARN
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Ready
> affinity version: AffinityTopologyVersion [topVer=2, minorTopVer=1]
> [2021-02-24 13:37:31,964][WARN
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][diagnostic] Last
> exchange future: GridDhtPartitionsExchangeFuture
> [firstDiscoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
> [id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
> [DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
> nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false,
> stop=false, destroy=false, disabledAfterStartfalse]],
> exchangeActions=ExchangeActions [startCaches=[cache1], stopCaches=null,
> startGrps=[cache1], stopGrps=[], resetParts=null, stateChangeRequest=null],
> startCaches=false], affTopVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163031766, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null, span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=02c46b75, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1614163031926]], crd=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163031766, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], discoEvt=DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeBatch
> [id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
> [DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
> nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false,
> stop=false, destroy=false, disabledAfterStartfalse]],
> exchangeActions=ExchangeActions [startCaches=[cache1], stopCaches=null,
> startGrps=[cache1], stopGrps=[], resetParts=null, stateChangeRequest=null],
> startCaches=false], affTopVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163031766, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null, span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=02c46b75, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1614163031926]], nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
> added=true, exchangeType=ALL, initFut=GridFutureAdapter
> [ignoreInterrupts=false, state=DONE, res=true, hash=425645765], init=true,
> lastVer=null, partReleaseFut=PartitionReleaseFuture
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
> futures=[ExplicitLockReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], futures=[]], AtomicUpdateReleaseFuture
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
> DataStreamerReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], futures=[]], LocalTxReleaseFuture
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
> AllTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
> futures=[RemoteTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], futures=[]]]]]], exchActions=ExchangeActions
> [startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
> resetParts=null, stateChangeRequest=null], affChangeMsg=null,
> centralizedAff=false, forceAffReassignment=false, exchangeLocE=class
> o.a.i.IgniteCheckedException: Failed to initialize exchange locally
> [locNodeId=02c46b75-6648-4796-88b0-7ce6df700001],
> cacheChangeFailureMsgSent=false, done=false, state=SRV,
> registerCachesFuture=null, startTime=1614163031933, initTime=1614163031938,
> rebalancedInfo=null, affinityReassign=false,
> span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, evtLatch=0,
> remaining=HashSet [b05182d2-c6e8-4b5b-bde2-576e1e700000],
> mergedJoinExchMsgs=null, awaitMergedMsgs=0, super=GridFutureAdapter
> [ignoreInterrupts=false, state=INIT, res=null, hash=1833752790]]
> [2021-02-24 13:37:31,964][WARN
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
> First 10 pending exchange futures [total=1]
> [2021-02-24 13:37:31,964][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Last
> exchange future: GridDhtPartitionsExchangeFuture
> [firstDiscoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
> [id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
> [DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
> nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false,
> stop=false, destroy=false, disabledAfterStartfalse]],
> exchangeActions=ExchangeActions [startCaches=[cache1], stopCaches=null,
> startGrps=[cache1], stopGrps=[], resetParts=null, stateChangeRequest=null],
> startCaches=false], affTopVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163051747, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null, span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1614163031926]], crd=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163051747, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], discoEvt=DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeBatch
> [id=af52d93d771-bd608b2d-8308-4556-9f9f-91bae6049b7c, reqs=ArrayList
> [DynamicCacheChangeRequest [cacheName=cache1, hasCfg=true,
> nodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000, clientStartOnly=false,
> stop=false, destroy=false, disabledAfterStartfalse]],
> exchangeActions=ExchangeActions [startCaches=[cache1], stopCaches=null,
> startGrps=[cache1], stopGrps=[], resetParts=null, stateChangeRequest=null],
> startCaches=false], affTopVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163051747, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], topVer=2,
> msgTemplate=null, span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5,
> nodeId8=b05182d2, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1614163031926]], nodeId=b05182d2, evt=DISCOVERY_CUSTOM_EVT],
> added=true, exchangeType=ALL, initFut=GridFutureAdapter
> [ignoreInterrupts=false, state=DONE, res=true, hash=1191663263], init=true,
> lastVer=GridCacheVersion [topVer=0, order=1614163030229, nodeOrder=0],
> partReleaseFut=PartitionReleaseFuture [topVer=AffinityTopologyVersion
> [topVer=2, minorTopVer=2], futures=[ExplicitLockReleaseFuture
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
> AtomicUpdateReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], futures=[]], DataStreamerReleaseFuture
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], futures=[]],
> LocalTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], futures=[]], AllTxReleaseFuture
> [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
> futures=[RemoteTxReleaseFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], futures=[]]]]]], exchActions=ExchangeActions
> [startCaches=[cache1], stopCaches=null, startGrps=[cache1], stopGrps=[],
> resetParts=null, stateChangeRequest=null], affChangeMsg=null,
> centralizedAff=false, forceAffReassignment=false, exchangeLocE=class
> o.a.i.IgniteCheckedException: Failed to initialize exchange locally
> [locNodeId=b05182d2-c6e8-4b5b-bde2-576e1e700000],
> cacheChangeFailureMsgSent=true, done=false, state=CRD,
> registerCachesFuture=null, startTime=1614163031932, initTime=1614163031938,
> rebalancedInfo=null, affinityReassign=false,
> span=o.a.i.i.processors.tracing.NoopSpan@7e02a8f5, evtLatch=0,
> remaining=HashSet [], mergedJoinExchMsgs=null, awaitMergedMsgs=0,
> super=GridFutureAdapter [ignoreInterrupts=false, state=INIT, res=null,
> hash=2101726312]]
> [2021-02-24 13:37:31,966][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
> First 10 pending exchange futures [total=1]
> [2021-02-24 13:37:31,966][WARN
> ][exchange-worker-#127%cache.DynamicCacheStartFailTest1%][GridCachePartitionExchangeManager]
> >>> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=2, minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
> [id=02c46b75-6648-4796-88b0-7ce6df700001,
> consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2,
> intOrder=2, lastExchangeTime=1614163051747, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], rebalanced=false,
> done=false, newCrdFut=null]
> [2021-02-24 13:37:31,968][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][GridCachePartitionExchangeManager]
> >>> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=2, minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
> [id=02c46b75-6648-4796-88b0-7ce6df700001,
> consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2,
> intOrder=2, lastExchangeTime=1614163031715, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], rebalanced=false,
> done=false, newCrdFut=null]
> [2021-02-24 13:37:31,972][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] Last 10
> exchange futures (total: 3):
> [2021-02-24 13:37:31,972][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
> [id=02c46b75-6648-4796-88b0-7ce6df700001,
> consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2,
> intOrder=2, lastExchangeTime=1614163031715, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], rebalanced=false,
> done=false, newCrdFut=null]
> [2021-02-24 13:37:31,973][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
> [id=b05182d2-c6e8-4b5b-bde2-576e1e700000,
> consistentId=9bc35ede-4ab7-44cb-9d15-0d7215350ed3, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1614163051747, loc=true,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], rebalanced=false,
> done=false, newCrdFut=null]
> [2021-02-24 13:37:31,973][WARN
> ][exchange-worker-#61%cache.DynamicCacheStartFailTest0%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=2,
> minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode
> [id=02c46b75-6648-4796-88b0-7ce6df700001,
> consistentId=be23b7a5-f2c4-4ac8-9f71-bc3d0dbbdaf7, addrs=ArrayList
> [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47501], discPort=47501, order=2,
> intOrder=2, lastExchangeTime=1614163031715, loc=false,
> ver=2.11.0#20210224-sha1:00000000, isClient=false], rebalanced=true,
> done=true, newCrdFut=null]
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
