You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@ignite.apache.org by "vijay.bhatt" <vi...@gmail.com> on 2020/01/09 00:07:24 UTC
cache.get and cache.isExists causes "Failed to process invalid
partitions response" exception even though the cache message finished
processing
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/
Re: cache.get and cache.isExists causes "Failed to process invalid
partitions response" exception even though the cache message finished
processing
Posted by "vijay.bhatt" <vi...@gmail.com>.
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/
Re: cache.get and cache.isExists causes "Failed to process invalid
partitions response" exception even though the cache message finished processing
Posted by Evgenii Zhuravlev <e....@gmail.com>.
Hi,
Please share full logs from all nodes in the cluster, including clients.
Thanks,
Evgenii
ср, 8 янв. 2020 г. в 16:07, vijay.bhatt <vi...@gmail.com>:
> 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/
>