Apache Ignite Users

Failed to wait for affinity ready future for topology version: AffinityTopologyVersion

Classic

List

Threaded

5 messages Options

38797715

Failed to wait for affinity ready future for topology version: AffinityTopologyVersion

Hi community,

When a new client node is joining the cluster, other client nodes cannot
perform SQL query. Is this true? log are as follows:

[19:15:34,959][SEVERE][query-#44319][GridMapQueryExecutor] Failed to
execute local query.
class org.apache.ignite.IgniteException: Failed to wait for affinity
ready future for topology version: AffinityTopologyVersion [topVer=57,
minorTopVer=0]
     at
org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.awaitTopologyVersion(GridAffinityAssignmentCache.java:909)

     at
org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:784)

     at
org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:764)

     at
org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.primaryPartitions(GridAffinityAssignmentCache.java:690)

     at
org.apache.ignite.internal.processors.cache.GridCacheAffinityManager.primaryPartitions(GridCacheAffinityManager.java:387)

     at
org.apache.ignite.internal.processors.query.h2.twostep.PartitionReservationManager.reservePartitions(PartitionReservationManager.java:216)

     at
org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest0(GridMapQueryExecutor.java:313)

     at
org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest(GridMapQueryExecutor.java:241)

     at
org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.onMessage(IgniteH2Indexing.java:2186)

     at
org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.lambda$start$17(IgniteH2Indexing.java:2139)

     at
org.apache.ignite.internal.managers.communication.GridIoManager$ArrayListener.onMessage(GridIoManager.java:3386)

     at
org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1847)

     at
org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1472)

     at
org.apache.ignite.internal.managers.communication.GridIoManager.access$5200(GridIoManager.java:229)

     at
org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1367)

     at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

     at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

     at java.lang.Thread.run(Thread.java:748)
Caused by: class
org.apache.ignite.internal.processors.cache.CacheStoppedException:
Failed to perform cache operation (cache is stopped): Failed to wait for
topology update, cache group is stopping.
     at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$processCacheStopRequestOnExchangeDone$629e8679$1(GridCacheProcessor.java:2723)

     at
org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11157)

     at
org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11059)

     at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.processCacheStopRequestOnExchangeDone(GridCacheProcessor.java:2706)

     at
org.apache.ignite.internal.processors.cache.GridCacheProcessor.onExchangeDone(GridCacheProcessor.java:2862)

     at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onDone(GridDhtPartitionsExchangeFuture.java:2330)

     at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.processFullMessage(GridDhtPartitionsExchangeFuture.java:4375)

     at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.access$1500(GridDhtPartitionsExchangeFuture.java:148)

     at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4054)

     at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4042)

     at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:399)

     at
org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:354)

     at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceiveFullMessage(GridDhtPartitionsExchangeFuture.java:4042)

     at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processFullPartitionUpdate(GridCachePartitionExchangeManager.java:1886)

     at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:429)

     at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:416)

     at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3667)

     at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3646)

     at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)

     at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)

     at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)

     at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)

     at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)

     at
org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)

     ... 7 more
[19:15:54,661][WARNING][disco-event-worker-#44][GridDiscoveryManager]
Local node's value of 'java.net.preferIPv4Stack' system property differs
from remote node's (all nodes in topology should have identical value)
[locPreferIpV4=null, rmtPreferIpV4=true, locId8=82b60753,
rmtId8=cf7ae106, rmtAddrs=[node1/172.30.100.211], rmtNode=ClusterNode
[id=cf7ae106-9252-4f90-8378-92e0a382e4dd, order=57,
addr=[172.30.100.211], daemon=false]]
[19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager] Added
new node to topology: TcpDiscoveryNode
[id=cf7ae106-9252-4f90-8378-92e0a382e4dd,
consistentId=cf7ae106-9252-4f90-8378-92e0a382e4dd, addrs=ArrayList
[172.30.100.211], sockAddrs=HashSet [/172.30.100.211:0], discPort=0,
order=57, intOrder=32, lastExchangeTime=1607426074553, loc=false,
ver=2.8.1#20200521-sha1:86422096, isClient=true]
[19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]
Topology snapshot [ver=57, locNode=82b60753, servers=4, clients=3,
state=ACTIVE, CPUs=40, offheap=6.5GB, heap=29.0GB]
[19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]   ^--
Baseline [id=0, size=4, online=4, offline=0]

aealexsandrov

Re: Failed to wait for affinity ready future for topology version: AffinityTopologyVersion

Hello,

This means that some partition map exchange was blocked or took a long
time. SQL queries cannot be run during this period.

Most likely you are using a transaction with no timeouts. If yes, then
set the default tx timeout and tx timeout for PME:

https://ignite.apache.org/releases/latest/javadoc/org/apache/ignite/configuration/TransactionConfiguration.html#setTxTimeoutOnPartitionMapExchange-long-

https://ignite.apache.org/releases/latest/javadoc/org/apache/ignite/configuration/TransactionConfiguration.html#setDefaultTxTimeout-long-

If not, your logs are required.

BR,
Andrei

12/9/2020 4:15 PM, 38797715 пишет:

> Hi community,
>
> When a new client node is joining the cluster, other client nodes
> cannot perform SQL query. Is this true? log are as follows:
>
> [19:15:34,959][SEVERE][query-#44319][GridMapQueryExecutor] Failed to
> execute local query.
> class org.apache.ignite.IgniteException: Failed to wait for affinity
> ready future for topology version: AffinityTopologyVersion [topVer=57,
> minorTopVer=0]
>     at
> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.awaitTopologyVersion(GridAffinityAssignmentCache.java:909)
>
>     at
> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:784)
>
>     at
> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:764)
>
>     at
> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.primaryPartitions(GridAffinityAssignmentCache.java:690)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheAffinityManager.primaryPartitions(GridCacheAffinityManager.java:387)
>
>     at
> org.apache.ignite.internal.processors.query.h2.twostep.PartitionReservationManager.reservePartitions(PartitionReservationManager.java:216)
>
>     at
> org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest0(GridMapQueryExecutor.java:313)
>
>     at
> org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest(GridMapQueryExecutor.java:241)
>
>     at
> org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.onMessage(IgniteH2Indexing.java:2186)
>
>     at
> org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.lambda$start$17(IgniteH2Indexing.java:2139)
>
>     at
> org.apache.ignite.internal.managers.communication.GridIoManager$ArrayListener.onMessage(GridIoManager.java:3386)
>
>     at
> org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1847)
>
>     at
> org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1472)
>
>     at
> org.apache.ignite.internal.managers.communication.GridIoManager.access$5200(GridIoManager.java:229)
>
>     at
> org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1367)
>
>     at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>
>     at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>
>     at java.lang.Thread.run(Thread.java:748)
> Caused by: class
> org.apache.ignite.internal.processors.cache.CacheStoppedException:
> Failed to perform cache operation (cache is stopped): Failed to wait
> for topology update, cache group is stopping.
>     at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$processCacheStopRequestOnExchangeDone$629e8679$1(GridCacheProcessor.java:2723)
>
>     at
> org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11157)
>
>     at
> org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11059)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.processCacheStopRequestOnExchangeDone(GridCacheProcessor.java:2706)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheProcessor.onExchangeDone(GridCacheProcessor.java:2862)
>
>     at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onDone(GridDhtPartitionsExchangeFuture.java:2330)
>
>     at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.processFullMessage(GridDhtPartitionsExchangeFuture.java:4375)
>
>     at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.access$1500(GridDhtPartitionsExchangeFuture.java:148)
>
>     at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4054)
>
>     at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4042)
>
>     at
> org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:399)
>
>     at
> org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:354)
>
>     at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceiveFullMessage(GridDhtPartitionsExchangeFuture.java:4042)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processFullPartitionUpdate(GridCachePartitionExchangeManager.java:1886)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:429)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:416)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3667)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3646)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)
>
>     at
> org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)
>
>     ... 7 more
> [19:15:54,661][WARNING][disco-event-worker-#44][GridDiscoveryManager]
> Local node's value of 'java.net.preferIPv4Stack' system property
> differs from remote node's (all nodes in topology should have
> identical value) [locPreferIpV4=null, rmtPreferIpV4=true,
> locId8=82b60753, rmtId8=cf7ae106, rmtAddrs=[node1/172.30.100.211],
> rmtNode=ClusterNode [id=cf7ae106-9252-4f90-8378-92e0a382e4dd,
> order=57, addr=[172.30.100.211], daemon=false]]
> [19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]
> Added new node to topology: TcpDiscoveryNode
> [id=cf7ae106-9252-4f90-8378-92e0a382e4dd,
> consistentId=cf7ae106-9252-4f90-8378-92e0a382e4dd, addrs=ArrayList
> [172.30.100.211], sockAddrs=HashSet [/172.30.100.211:0], discPort=0,
> order=57, intOrder=32, lastExchangeTime=1607426074553, loc=false,
> ver=2.8.1#20200521-sha1:86422096, isClient=true]
> [19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]
> Topology snapshot [ver=57, locNode=82b60753, servers=4, clients=3,
> state=ACTIVE, CPUs=40, offheap=6.5GB, heap=29.0GB]
> [19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]
> ^-- Baseline [id=0, size=4, online=4, offline=0]
>

38797715

Re: Failed to wait for affinity ready future for topology version: AffinityTopologyVersion

Hi,

What I need to confirm is whether all SQL cannot be executed during PME
execution, or just some types of SQL (including DDL, DML, SELECT)?

Or, it is strongly related to some cache parameters, such as atomicityMode?

在 2020/12/9 下午10:31, andrei 写道:

> Hello,
>
> This means that some partition map exchange was blocked or took a
> long time. SQL queries cannot be run during this period.
>
> Most likely you are using a transaction with no timeouts. If yes, then
> set the default tx timeout and tx timeout for PME:
>
> https://ignite.apache.org/releases/latest/javadoc/org/apache/ignite/configuration/TransactionConfiguration.html#setTxTimeoutOnPartitionMapExchange-long-
>
>
> https://ignite.apache.org/releases/latest/javadoc/org/apache/ignite/configuration/TransactionConfiguration.html#setDefaultTxTimeout-long-
>
>
> If not, your logs are required.
>
> BR,
> Andrei
>
> 12/9/2020 4:15 PM, 38797715 пишет:
>> Hi community,
>>
>> When a new client node is joining the cluster, other client nodes
>> cannot perform SQL query. Is this true? log are as follows:
>>
>> [19:15:34,959][SEVERE][query-#44319][GridMapQueryExecutor] Failed to
>> execute local query.
>> class org.apache.ignite.IgniteException: Failed to wait for affinity
>> ready future for topology version: AffinityTopologyVersion
>> [topVer=57, minorTopVer=0]
>>     at
>> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.awaitTopologyVersion(GridAffinityAssignmentCache.java:909)
>>
>>     at
>> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:784)
>>
>>     at
>> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:764)
>>
>>     at
>> org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.primaryPartitions(GridAffinityAssignmentCache.java:690)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheAffinityManager.primaryPartitions(GridCacheAffinityManager.java:387)
>>
>>     at
>> org.apache.ignite.internal.processors.query.h2.twostep.PartitionReservationManager.reservePartitions(PartitionReservationManager.java:216)
>>
>>     at
>> org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest0(GridMapQueryExecutor.java:313)
>>
>>     at
>> org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest(GridMapQueryExecutor.java:241)
>>
>>     at
>> org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.onMessage(IgniteH2Indexing.java:2186)
>>
>>     at
>> org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.lambda$start$17(IgniteH2Indexing.java:2139)
>>
>>     at
>> org.apache.ignite.internal.managers.communication.GridIoManager$ArrayListener.onMessage(GridIoManager.java:3386)
>>
>>     at
>> org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1847)
>>
>>     at
>> org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1472)
>>
>>     at
>> org.apache.ignite.internal.managers.communication.GridIoManager.access$5200(GridIoManager.java:229)
>>
>>     at
>> org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1367)
>>
>>     at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>>
>>     at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>>
>>     at java.lang.Thread.run(Thread.java:748)
>> Caused by: class
>> org.apache.ignite.internal.processors.cache.CacheStoppedException:
>> Failed to perform cache operation (cache is stopped): Failed to wait
>> for topology update, cache group is stopping.
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$processCacheStopRequestOnExchangeDone$629e8679$1(GridCacheProcessor.java:2723)
>>
>>     at
>> org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11157)
>>
>>     at
>> org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11059)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheProcessor.processCacheStopRequestOnExchangeDone(GridCacheProcessor.java:2706)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheProcessor.onExchangeDone(GridCacheProcessor.java:2862)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onDone(GridDhtPartitionsExchangeFuture.java:2330)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.processFullMessage(GridDhtPartitionsExchangeFuture.java:4375)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.access$1500(GridDhtPartitionsExchangeFuture.java:148)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4054)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4042)
>>
>>     at
>> org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:399)
>>
>>     at
>> org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:354)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceiveFullMessage(GridDhtPartitionsExchangeFuture.java:4042)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processFullPartitionUpdate(GridCachePartitionExchangeManager.java:1886)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:429)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:416)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3667)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3646)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)
>>
>>     at
>> org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)
>>
>>     ... 7 more
>> [19:15:54,661][WARNING][disco-event-worker-#44][GridDiscoveryManager]
>> Local node's value of 'java.net.preferIPv4Stack' system property
>> differs from remote node's (all nodes in topology should have
>> identical value) [locPreferIpV4=null, rmtPreferIpV4=true,
>> locId8=82b60753, rmtId8=cf7ae106, rmtAddrs=[node1/172.30.100.211],
>> rmtNode=ClusterNode [id=cf7ae106-9252-4f90-8378-92e0a382e4dd,
>> order=57, addr=[172.30.100.211], daemon=false]]
>> [19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]
>> Added new node to topology: TcpDiscoveryNode
>> [id=cf7ae106-9252-4f90-8378-92e0a382e4dd,
>> consistentId=cf7ae106-9252-4f90-8378-92e0a382e4dd, addrs=ArrayList
>> [172.30.100.211], sockAddrs=HashSet [/172.30.100.211:0], discPort=0,
>> order=57, intOrder=32, lastExchangeTime=1607426074553, loc=false,
>> ver=2.8.1#20200521-sha1:86422096, isClient=true]
>> [19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]
>> Topology snapshot [ver=57, locNode=82b60753, servers=4, clients=3,
>> state=ACTIVE, CPUs=40, offheap=6.5GB, heap=29.0GB]
>> [19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]
>> ^-- Baseline [id=0, size=4, online=4, offline=0]
>>
>

38797715

Re: Failed to wait for affinity ready future for topology version: AffinityTopologyVersion

In reply to this post by aealexsandrov

Hi Andrei,

Another question is, what is the starting point of PME? PME starts when
a new node join request is received?

According to the log, the error occurred in '[19:15:34,959]', and he was
waiting for '[topVer = 57, minorTopVer = 0]', but 'Added new node to
topology: TcpDiscoveryNode' occurred in '[19:15:54,661]', indicating
that PME started very early.

在 2020/12/9 下午10:31, andrei 写道:

aealexsandrov

Re: Failed to wait for affinity ready future for topology version: AffinityTopologyVersion

Hi,

Yes, all SQL operations can be suspended by the PME process.

Events which causes PME

Topology events:

Node Join (EVT_NODE_JOINED) - new node discovered and joined topology (exchange is done after a node is included into the ring). This event doesn't trigger the PME if a thick client connects the cluster and an Ignite version is 2.8 or later.
Node Left (EVT_NODE_LEFT) - correct shutdown with call ignite.close. This event doesn't trigger the PME in Ignite 2.8 and later versions if a node belonging to an existing baseline topology leaves.
Node Failed (EVT_NODE_FAILED) - detected unresponsive node, probably crashed and is considered failed

Custom events:

Activation / Deactivation / Baseline topology set - ChangeGlobalStateMessage
Dynamic cache start / Dynamic cache stop - DynamicCacheChangeBatch
Snapshot create / restore - SnapshotDiscoveryMessage
Global WAL enable / disable - WalStateAbstractMessage
Late affinity assignment - CacheAffinityChangeMessage

BR,
Andrei

12/10/2020 3:54 AM, 38797715 пишет:

Hi Andrei,

Another question is, what is the starting point of PME? PME starts when a new node join request is received?

According to the log, the error occurred in '[19:15:34,959]', and he was waiting for '[topVer = 57, minorTopVer = 0]', but 'Added new node to topology: TcpDiscoveryNode' occurred in '[19:15:54,661]', indicating that PME started very early.

在 2020/12/9 下午10:31, andrei 写道:

Hello,

This means that some partition map exchange was blocked or took a long time. SQL queries cannot be run during this period.

Most likely you are using a transaction with no timeouts. If yes, then set the default tx timeout and tx timeout for PME:

https://ignite.apache.org/releases/latest/javadoc/org/apache/ignite/configuration/TransactionConfiguration.html#setTxTimeoutOnPartitionMapExchange-long-

https://ignite.apache.org/releases/latest/javadoc/org/apache/ignite/configuration/TransactionConfiguration.html#setDefaultTxTimeout-long-

If not, your logs are required.

BR,
Andrei

12/9/2020 4:15 PM, 38797715 пишет:

Hi community,

When a new client node is joining the cluster, other client nodes cannot perform SQL query. Is this true? log are as follows:

[19:15:34,959][SEVERE][query-#44319][GridMapQueryExecutor] Failed to execute local query.
class org.apache.ignite.IgniteException: Failed to wait for affinity ready future for topology version: AffinityTopologyVersion [topVer=57, minorTopVer=0]
    at org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.awaitTopologyVersion(GridAffinityAssignmentCache.java:909)
    at org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:784)
    at org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.cachedAffinity(GridAffinityAssignmentCache.java:764)
    at org.apache.ignite.internal.processors.affinity.GridAffinityAssignmentCache.primaryPartitions(GridAffinityAssignmentCache.java:690)
    at org.apache.ignite.internal.processors.cache.GridCacheAffinityManager.primaryPartitions(GridCacheAffinityManager.java:387)
    at org.apache.ignite.internal.processors.query.h2.twostep.PartitionReservationManager.reservePartitions(PartitionReservationManager.java:216)
    at org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest0(GridMapQueryExecutor.java:313)
    at org.apache.ignite.internal.processors.query.h2.twostep.GridMapQueryExecutor.onQueryRequest(GridMapQueryExecutor.java:241)
    at org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.onMessage(IgniteH2Indexing.java:2186)
    at org.apache.ignite.internal.processors.query.h2.IgniteH2Indexing.lambda$start$17(IgniteH2Indexing.java:2139)
    at org.apache.ignite.internal.managers.communication.GridIoManager$ArrayListener.onMessage(GridIoManager.java:3386)
    at org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1847)
    at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1472)
    at org.apache.ignite.internal.managers.communication.GridIoManager.access$5200(GridIoManager.java:229)
    at org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1367)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: class org.apache.ignite.internal.processors.cache.CacheStoppedException: Failed to perform cache operation (cache is stopped): Failed to wait for topology update, cache group is stopping.
    at org.apache.ignite.internal.processors.cache.GridCacheProcessor.lambda$processCacheStopRequestOnExchangeDone$629e8679$1(GridCacheProcessor.java:2723)
    at org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11157)
    at org.apache.ignite.internal.util.IgniteUtils.doInParallel(IgniteUtils.java:11059)
    at org.apache.ignite.internal.processors.cache.GridCacheProcessor.processCacheStopRequestOnExchangeDone(GridCacheProcessor.java:2706)
    at org.apache.ignite.internal.processors.cache.GridCacheProcessor.onExchangeDone(GridCacheProcessor.java:2862)
    at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onDone(GridDhtPartitionsExchangeFuture.java:2330)
    at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.processFullMessage(GridDhtPartitionsExchangeFuture.java:4375)
    at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.access$1500(GridDhtPartitionsExchangeFuture.java:148)
    at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4054)
    at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture$4.apply(GridDhtPartitionsExchangeFuture.java:4042)
    at org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:399)
    at org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:354)
    at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceiveFullMessage(GridDhtPartitionsExchangeFuture.java:4042)
    at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processFullPartitionUpdate(GridCachePartitionExchangeManager.java:1886)
    at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:429)
    at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$3.onMessage(GridCachePartitionExchangeManager.java:416)
    at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3667)
    at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:3646)
    at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)
    at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)
    at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)
    at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)
    at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)
    at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)
    ... 7 more
[19:15:54,661][WARNING][disco-event-worker-#44][GridDiscoveryManager] Local node's value of 'java.net.preferIPv4Stack' system property differs from remote node's (all nodes in topology should have identical value) [locPreferIpV4=null, rmtPreferIpV4=true, locId8=82b60753, rmtId8=cf7ae106, rmtAddrs=[node1/172.30.100.211], rmtNode=ClusterNode [id=cf7ae106-9252-4f90-8378-92e0a382e4dd, order=57, addr=[172.30.100.211], daemon=false]]
[19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager] Added new node to topology: TcpDiscoveryNode [id=cf7ae106-9252-4f90-8378-92e0a382e4dd, consistentId=cf7ae106-9252-4f90-8378-92e0a382e4dd, addrs=ArrayList [172.30.100.211], sockAddrs=HashSet [/172.30.100.211:0], discPort=0, order=57, intOrder=32, lastExchangeTime=1607426074553, loc=false, ver=2.8.1#20200521-sha1:86422096, isClient=true]
[19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager] Topology snapshot [ver=57, locNode=82b60753, servers=4, clients=3, state=ACTIVE, CPUs=40, offheap=6.5GB, heap=29.0GB]
[19:15:54,661][INFO][disco-event-worker-#44][GridDiscoveryManager]   ^-- Baseline [id=0, size=4, online=4, offline=0]