cache.get and cache.isExists causes "Failed to process invalid partitions response" exception even though the cache message finished processing

classic Classic list List threaded Threaded
3 messages Options
vijay.bhatt vijay.bhatt
Reply | Threaded
Open this post in threaded view
|

cache.get and cache.isExists causes "Failed to process invalid partitions response" exception even though the cache message finished processing

This post was updated on .
Hi,

We have a cluster with 4 server nodes and 4 client nodes. Each VM is running
one server and one client node in their own JVMs. Each VM has dual IP. We are setting local IP to be used in ignite configuration.

*We are getting the following exception when I call
cache.get("WORK_ORDER_MESSAGE_TOPIC") where cache is an instance of IgniteCache*

javax.cache.CacheException: class org.apache.ignite.IgniteCheckedException:
Failed to process invalid partitions response (remote node reported invalid
partitions but remote topology version does not differ from local)
[topVer=AffinityTopologyVersion [topVer=58, minorTopVer=0],
rmtTopVer=AffinityTopologyVersion [topVer=58, minorTopVer=0], part=729,
nodeId=01220042-7d29-4fea-bca1-270abc356a38]

*Exception trace is as follows:*

Caused by: org.apache.ignite.IgniteCheckedException: Failed to process
invalid partitions response (remote node reported invalid partitions but
remote topology version does not differ from local)
[topVer=AffinityTopologyVersion [topVer=58, minorTopVer=0],
rmtTopVer=AffinityTopologyVersion [topVer=58, minorTopVer=0], part=729,
nodeId=01220042-7d29-4fea-bca1-270abc356a38]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.GridPartitionedSingleGetFuture.checkError(GridPartitionedSingleGetFuture.java:611)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.GridPartitionedSingleGetFuture.onResult(GridPartitionedSingleGetFuture.java:520)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtCacheAdapter.processNearSingleGetResponse(GridDhtCacheAdapter.java:368)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache.access$100(GridDhtColocatedCache.java:87)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache$2.apply(GridDhtColocatedCache.java:132)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache$2.apply(GridDhtColocatedCache.java:130)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1056)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:581)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:380)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:306)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:101)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:295)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1569)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1197)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager.access$4200(GridIoManager.java:127)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1093)
~[kernel.jar:?]
        at
org.apache.ignite.internal.util.StripedExecutor$Stripe.body(StripedExecutor.java:505)
~[kernel.jar:?]
        at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
~[kernel.jar:?]

*Ignite client node logs are as follows:*

2020-Jan-07 Tue 13:04:48.780 DEBUG [main] -
org.apache.ignite.internal.processors.cache.GridCacheIoManager - Sending
cache message [msg=GridNearSingleGetRequest [futId=1578402251656,
key=UserKeyCacheObjectImpl [part=729, val=WORK_ORDER_MESSAGE_TOPIC,
hasValBytes=true], flags=1, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], subjId=81046742-907a-4ebc-ad37-cd5daabbf1fd, taskNameHash=0,
createTtl=-1, accessTtl=-1, mvccSnapshot=null], node=ClusterNode
[id=01220042-7d29-4fea-bca1-270abc356a38, order=55, addr=[172.31.42.183],
daemon=false]]
2020-Jan-07 Tue 13:04:48.780 TRACE [main] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Sending
message with ack to node [node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], msg=GridIoMessage [plc=2,
topic=TOPIC_CACHE, topicOrd=8, ordered=false, timeout=0,
skipOnTimeout=false, msg=GridNearSingleGetRequest [futId=1578402251656,
key=UserKeyCacheObjectImpl [part=729, val=WORK_ORDER_MESSAGE_TOPIC,
hasValBytes=true], flags=1, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], subjId=81046742-907a-4ebc-ad37-cd5daabbf1fd, taskNameHash=0,
createTtl=-1, accessTtl=-1, mvccSnapshot=null]]]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Encrypted data
[status=OK, handshakeStaus=NOT_HANDSHAKING, ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker [idx=3,
bytesRcvd=1029, bytesSent=0, bytesRcvd0=0, bytesSent0=0, select=true,
super=GridWorker [name=grid-nio-worker-tcp-comm-3,
igniteInstanceName=cr_client, finished=false, heartbeatTs=1578402288780,
hashCode=179424698, interrupted=false,
runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=89 lim=89 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1456, bytesRcvd=1029, bytesSent0=0, bytesRcvd0=0,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402283811, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]]
2020-Jan-07 Tue 13:04:48.780 TRACE
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Bytes sent
[sockCh=java.nio.channels.SocketChannel[connected local=/172.31.42.183:51255
remote=SRV-CR04.aalab.local/172.31.42.183:47100], cnt=118]
2020-Jan-07 Tue 13:04:48.780 TRACE
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Bytes received
[sockCh=java.nio.channels.SocketChannel[connected local=/172.31.42.183:51255
remote=SRV-CR04.aalab.local/172.31.42.183:47100], cnt=63]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Unwrapping
received data: GridSelectorNioSessionImpl [worker=DirectNioClientWorker
[super=AbstractNioClientWorker [idx=3, bytesRcvd=1092, bytesSent=0,
bytesRcvd0=63, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-3, igniteInstanceName=cr_client,
finished=false, heartbeatTs=1578402288780, hashCode=179424698,
interrupted=false, runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=63 lim=63 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1574, bytesRcvd=1092, bytesSent0=118, bytesRcvd0=63,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402288780, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Unwrapped raw
data [status=OK, handshakeStatus=NOT_HANDSHAKING,
ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
[super=AbstractNioClientWorker [idx=3, bytesRcvd=1092, bytesSent=0,
bytesRcvd0=63, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-3, igniteInstanceName=cr_client,
finished=false, heartbeatTs=1578402288780, hashCode=179424698,
interrupted=false, runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=63 lim=63 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1574, bytesRcvd=1092, bytesSent0=118, bytesRcvd0=63,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402288780, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Unwrapped raw
data [status=BUFFER_UNDERFLOW, handshakeStatus=NOT_HANDSHAKING,
ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
[super=AbstractNioClientWorker [idx=3, bytesRcvd=1092, bytesSent=0,
bytesRcvd0=63, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-3, igniteInstanceName=cr_client,
finished=false, heartbeatTs=1578402288780, hashCode=179424698,
interrupted=false, runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=63 lim=63 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1574, bytesRcvd=1092, bytesSent0=118, bytesRcvd0=63,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402288780, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]]
2020-Jan-07 Tue 13:04:48.780 DEBUG [sys-stripe-0-#1%cr_client%] -
org.apache.ignite.internal.processors.cache.GridCacheIoManager - Received
unordered cache communication message
[nodeId=01220042-7d29-4fea-bca1-270abc356a38,
locId=81046742-907a-4ebc-ad37-cd5daabbf1fd, msg=GridNearSingleGetResponse
[futId=1578402251656, res=null, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], err=null, flags=1]]
2020-Jan-07 Tue 13:04:48.780 DEBUG [sys-stripe-0-#1%cr_client%] -
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache
- <subscriptionHandlersMap> Processing near get response
[nodeId=01220042-7d29-4fea-bca1-270abc356a38, res=GridNearSingleGetResponse
[futId=1578402251656, res=null, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], err=null, flags=1]]
2020-Jan-07 Tue 13:04:48.780 DEBUG [sys-stripe-0-#1%cr_client%] -
org.apache.ignite.internal.processors.cache.GridCacheIoManager - Finished
processing cache communication message
[nodeId=01220042-7d29-4fea-bca1-270abc356a38, msg=GridNearSingleGetResponse
[futId=1578402251656, res=null, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], err=null, flags=1]]

*We don't encounter this issue when we have upto 2 servers and 2 clients in
the cluster. Please let us know what could be the root cause of this.*

Regards
-Vijay




--
Sent from: http://apache-ignite-users.70518.x6.nabble.com/
ezhuravlev ezhuravlev
Reply | Threaded
Open this post in threaded view
|

Re: cache.get and cache.isExists causes "Failed to process invalid partitions response" exception even though the cache message finished processing

Hi,

Please share full logs from all nodes in the cluster, including clients.

Thanks,
Evgenii

ср, 8 янв. 2020 г. в 16:07, vijay.bhatt <[hidden email]>:
Hi,

We have a cluster with 4 server nodes and 4 client nodes. Each VM is running
one server and one client node in their own JVMs.

*We are getting the following exception when I call
cache.get("WORK_ORDER_MESSAGE_TOPIC")

cache is an instance of IgniteCache*

javax.cache.CacheException: class org.apache.ignite.IgniteCheckedException:
Failed to process invalid partitions response (remote node reported invalid
partitions but remote topology version does not differ from local)
[topVer=AffinityTopologyVersion [topVer=58, minorTopVer=0],
rmtTopVer=AffinityTopologyVersion [topVer=58, minorTopVer=0], part=729,
nodeId=01220042-7d29-4fea-bca1-270abc356a38]

*Trace is as follows:*

Caused by: org.apache.ignite.IgniteCheckedException: Failed to process
invalid partitions response (remote node reported invalid partitions but
remote topology version does not differ from local)
[topVer=AffinityTopologyVersion [topVer=58, minorTopVer=0],
rmtTopVer=AffinityTopologyVersion [topVer=58, minorTopVer=0], part=729,
nodeId=01220042-7d29-4fea-bca1-270abc356a38]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.GridPartitionedSingleGetFuture.checkError(GridPartitionedSingleGetFuture.java:611)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.GridPartitionedSingleGetFuture.onResult(GridPartitionedSingleGetFuture.java:520)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtCacheAdapter.processNearSingleGetResponse(GridDhtCacheAdapter.java:368)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache.access$100(GridDhtColocatedCache.java:87)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache$2.apply(GridDhtColocatedCache.java:132)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache$2.apply(GridDhtColocatedCache.java:130)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1056)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:581)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:380)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:306)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:101)
~[kernel.jar:?]
        at
org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:295)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1569)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1197)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager.access$4200(GridIoManager.java:127)
~[kernel.jar:?]
        at
org.apache.ignite.internal.managers.communication.GridIoManager$9.run(GridIoManager.java:1093)
~[kernel.jar:?]
        at
org.apache.ignite.internal.util.StripedExecutor$Stripe.body(StripedExecutor.java:505)
~[kernel.jar:?]
        at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
~[kernel.jar:?]

*Ignite client node logs are as follows:*

2020-Jan-07 Tue 13:04:48.780 DEBUG [main] -
org.apache.ignite.internal.processors.cache.GridCacheIoManager - Sending
cache message [msg=GridNearSingleGetRequest [futId=1578402251656,
key=UserKeyCacheObjectImpl [part=729, val=WORK_ORDER_MESSAGE_TOPIC,
hasValBytes=true], flags=1, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], subjId=81046742-907a-4ebc-ad37-cd5daabbf1fd, taskNameHash=0,
createTtl=-1, accessTtl=-1, mvccSnapshot=null], node=ClusterNode
[id=01220042-7d29-4fea-bca1-270abc356a38, order=55, addr=[172.31.42.183],
daemon=false]]
2020-Jan-07 Tue 13:04:48.780 TRACE [main] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Sending
message with ack to node [node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], msg=GridIoMessage [plc=2,
topic=TOPIC_CACHE, topicOrd=8, ordered=false, timeout=0,
skipOnTimeout=false, msg=GridNearSingleGetRequest [futId=1578402251656,
key=UserKeyCacheObjectImpl [part=729, val=WORK_ORDER_MESSAGE_TOPIC,
hasValBytes=true], flags=1, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], subjId=81046742-907a-4ebc-ad37-cd5daabbf1fd, taskNameHash=0,
createTtl=-1, accessTtl=-1, mvccSnapshot=null]]]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Encrypted data
[status=OK, handshakeStaus=NOT_HANDSHAKING, ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker [idx=3,
bytesRcvd=1029, bytesSent=0, bytesRcvd0=0, bytesSent0=0, select=true,
super=GridWorker [name=grid-nio-worker-tcp-comm-3,
igniteInstanceName=cr_client, finished=false, heartbeatTs=1578402288780,
hashCode=179424698, interrupted=false,
runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=89 lim=89 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1456, bytesRcvd=1029, bytesSent0=0, bytesRcvd0=0,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402283811, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]]
2020-Jan-07 Tue 13:04:48.780 TRACE
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Bytes sent
[sockCh=java.nio.channels.SocketChannel[connected local=/172.31.42.183:51255
remote=SRV-CR04.aalab.local/172.31.42.183:47100], cnt=118]
2020-Jan-07 Tue 13:04:48.780 TRACE
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Bytes received
[sockCh=java.nio.channels.SocketChannel[connected local=/172.31.42.183:51255
remote=SRV-CR04.aalab.local/172.31.42.183:47100], cnt=63]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Unwrapping
received data: GridSelectorNioSessionImpl [worker=DirectNioClientWorker
[super=AbstractNioClientWorker [idx=3, bytesRcvd=1092, bytesSent=0,
bytesRcvd0=63, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-3, igniteInstanceName=cr_client,
finished=false, heartbeatTs=1578402288780, hashCode=179424698,
interrupted=false, runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=63 lim=63 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1574, bytesRcvd=1092, bytesSent0=118, bytesRcvd0=63,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402288780, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Unwrapped raw
data [status=OK, handshakeStatus=NOT_HANDSHAKING,
ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
[super=AbstractNioClientWorker [idx=3, bytesRcvd=1092, bytesSent=0,
bytesRcvd0=63, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-3, igniteInstanceName=cr_client,
finished=false, heartbeatTs=1578402288780, hashCode=179424698,
interrupted=false, runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=63 lim=63 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1574, bytesRcvd=1092, bytesSent0=118, bytesRcvd0=63,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402288780, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]]
2020-Jan-07 Tue 13:04:48.780 DEBUG
[grid-nio-worker-tcp-comm-3-#17%cr_client%] -
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - Unwrapped raw
data [status=BUFFER_UNDERFLOW, handshakeStatus=NOT_HANDSHAKING,
ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
[super=AbstractNioClientWorker [idx=3, bytesRcvd=1092, bytesSent=0,
bytesRcvd0=63, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-3, igniteInstanceName=cr_client,
finished=false, heartbeatTs=1578402288780, hashCode=179424698,
interrupted=false, runner=grid-nio-worker-tcp-comm-3-#17%cr_client%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=63 lim=63 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=0, resendCnt=0, rcvCnt=6,
sentCnt=7, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=01220042-7d29-4fea-bca1-270abc356a38, addrs=[172.31.42.183],
sockAddrs=[SRV-CR04.aalab.local/172.31.42.183:47500], discPort=47500,
order=55, intOrder=31, lastExchangeTime=1578402259264, loc=false,
ver=2.7.0#20181130-sha1:256ae401, isClient=false], connected=false,
connectCnt=1, queueLimit=4096, reserveCnt=1, pairedConnections=false],
super=GridNioSessionImpl [locAddr=/172.31.42.183:51255,
rmtAddr=SRV-CR04.aalab.local/172.31.42.183:47100, createTime=1578402273186,
closeTime=0, bytesSent=1574, bytesRcvd=1092, bytesSent0=118, bytesRcvd0=63,
sndSchedTime=1578402273186, lastSndTime=1578402288780,
lastRcvTime=1578402288780, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=org.apache.ignite.internal.util.nio.GridDirectParser@5bc44d78,
directMode=true], GridConnectionBytesVerifyFilter, SSL filter],
accepted=false, markedForClose=false]]]
2020-Jan-07 Tue 13:04:48.780 DEBUG [sys-stripe-0-#1%cr_client%] -
org.apache.ignite.internal.processors.cache.GridCacheIoManager - Received
unordered cache communication message
[nodeId=01220042-7d29-4fea-bca1-270abc356a38,
locId=81046742-907a-4ebc-ad37-cd5daabbf1fd, msg=GridNearSingleGetResponse
[futId=1578402251656, res=null, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], err=null, flags=1]]
2020-Jan-07 Tue 13:04:48.780 DEBUG [sys-stripe-0-#1%cr_client%] -
org.apache.ignite.internal.processors.cache.distributed.dht.colocated.GridDhtColocatedCache
- <subscriptionHandlersMap> Processing near get response
[nodeId=01220042-7d29-4fea-bca1-270abc356a38, res=GridNearSingleGetResponse
[futId=1578402251656, res=null, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], err=null, flags=1]]
2020-Jan-07 Tue 13:04:48.780 DEBUG [sys-stripe-0-#1%cr_client%] -
org.apache.ignite.internal.processors.cache.GridCacheIoManager - Finished
processing cache communication message
[nodeId=01220042-7d29-4fea-bca1-270abc356a38, msg=GridNearSingleGetResponse
[futId=1578402251656, res=null, topVer=AffinityTopologyVersion [topVer=58,
minorTopVer=0], err=null, flags=1]]

*We don't encounter this issue when we have upto 2 servers and 2 clients in
the cluster.*

Regards
-Vijay




--
Sent from: http://apache-ignite-users.70518.x6.nabble.com/
vijay.bhatt vijay.bhatt
Reply | Threaded
Open this post in threaded view
|

Re: cache.get and cache.isExists causes "Failed to process invalid partitions response" exception even though the cache message finished processing

Hi Evgenii,

Thanks for looking in this one. Can I send the logs directly to you? There
are some implementation specific things which I am not allowed to share on a
mailing list.

Regards
-Vijay



--
Sent from: http://apache-ignite-users.70518.x6.nabble.com/