ignite-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Nikolai Tikhonov <ntikho...@apache.org>
Subject Re: Activation: slow and: Ignite node crashed in the middle of checkpoint.
Date Wed, 16 Aug 2017 17:05:06 GMT
Hi Roger,

>From this logs not clear why you got this behaviour. Could you also take
thread dump from all nodes? Also would be great if you share them as
separate files.

On Wed, Aug 16, 2017 at 2:50 AM, Roger Fischer (CW) <rfische@brocade.com>
wrote:

> Hi Dmitry and Alex,
>
> the cache contains 19.2M objects. The work/db directory is 23, 26 and 22
> GB respectively. The 3 nodes have 8 GB RAM each.
>
> I initiated deactivate at 14:13:39. As of 16:50:00, deactivate has not
> completed. Only server node 2 continues to log warnings.
>
>
>
> The client shows the following logs:
>
> [14:13:39,473][INFO][main][GridClusterStateProcessor] Sending deactivate
> request from node [id=548f4233-67e9-4043-aa3a-086fb541c427,
> topVer=AffinityTopologyVersion [topVer=12, minorTopVer=0], client=true,
> daemonfalse]
> [14:13:40,369][INFO][tcp-client-disco-msg-worker-#4%null%][GridClusterStateProcessor]
> Start state transition: false
> [14:13:40,395][INFO][exchange-worker-#96%null%][time] Started exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> crd=false, evt=18, node=TcpDiscoveryNode [id=548f4233-67e9-4043-aa3a-086fb541c427,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/0:0:0:0:0:0:0:1%lo:0,
> /127.0.0.1:0, /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=11,
> intOrder=0, lastExchangeTime=1502830168939, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true],
> evtNode=TcpDiscoveryNode [id=548f4233-67e9-4043-aa3a-086fb541c427,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/0:0:0:0:0:0:0:1%lo:0,
> /127.0.0.1:0, /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=11,
> intOrder=0, lastExchangeTime=1502830168939, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], customEvt=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false]]
> [14:13:40,396][INFO][exchange-worker-#96%null%][
> GridDhtPartitionsExchangeFuture] Start deactivation process
> [nodeId=548f4233-67e9-4043-aa3a-086fb541c427, client=true,
> topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1]]
> [14:13:40,397][INFO][exchange-worker-#96%null%][
> GridDhtPartitionsExchangeFuture] Successfully deactivated data
> structures, services and caches [nodeId=548f4233-67e9-4043-aa3a-086fb541c427,
> client=true, topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1]]
> [14:13:40,398][INFO][exchange-worker-#96%null%][
> GridDhtPartitionsExchangeFuture] Snapshot initialization completed
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1], time=0ms]
> [14:13:40,398][INFO][exchange-worker-#96%null%][time] Finished exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> crd=false]
> [14:13:41,173][INFO][tcp-client-disco-msg-worker-#4%null%][GridClusterStateProcessor]
> Received state change finish message: false
> [14:13:45,355][INFO][grid-timeout-worker-#15%null%][IgniteKernal]
> Metrics for local node (to disable set 'metricsLogFrequency' to 0)
>     ^-- Node [id=548f4233, name=null, uptime=00:24:07:982]
>     ^-- H/N/C [hosts=3, nodes=4, CPUs=12]
>     ^-- CPU [cur=0.6%, avg=0.89%, GC=0%]
>     ^-- PageMemory [pages=0]
>     ^-- Heap [used=248MB, free=86.36%, comm=951MB]
>     ^-- Non heap [used=48MB, free=-1%, comm=49MB]
>     ^-- Public thread pool [active=0, idle=0, qSize=0]
>     ^-- System thread pool [active=0, idle=0, qSize=0]
>     ^-- Outbound messages queue [size=0]
> [14:13:50,399][WARNING][exchange-worker-#96%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=548f4233-67e9-4043-aa3a-086fb541c427].
> Dumping pending objects that might be the cause:
> [14:13:50,400][WARNING][exchange-worker-#96%null%][diagnostic] Ready
> affinity version: AffinityTopologyVersion [topVer=12, minorTopVer=0]
> [14:13:50,624][WARNING][exchange-worker-#96%null%][diagnostic] Last
> exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831381649, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=548f4233, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1502831620392]], crd=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831381649,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=1870944589], init=true, lastVer=null, partReleaseFut=null,
> exchActions=ExchangeActions [startCaches=null,
> stopCaches=[ignite-sys-cache, PortCache, FcPortStatsCache, SwitchCache,
> FabricCache], startGrps=[], stopGrps=[ignite-sys-cache, destroy=false,
> PortCache, destroy=false, FcPortStatsCache, destroy=false, SwitchCache,
> destroy=false, FabricCache, destroy=false], resetParts=null,
> stateChangeRequest=StateChangeRequest [msg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=true,
> clientOnlyExchange=true, initTs=1502831620392, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=false, evtLatch=0,
> remaining=[6ffb9c55-4f23-4920-8134-36a649371cda, bda65979-33d1-4d6f-8a32-45b71255f835,
> 4d8c099c-b04f-48f9-a825-25eba9d794c5], super=GridFutureAdapter
> [ignoreInterrupts=false, state=INIT, res=null, hash=959636403]]
> [14:13:50,624][WARNING][exchange-worker-#96%null%][
> GridCachePartitionExchangeManager] First 10 pending exchange futures
> [total=1]
> [14:13:51,397][WARNING][exchange-worker-#96%null%][diagnostic] Last 10
> exchange futures (total: 3):
> [14:13:51,398][WARNING][exchange-worker-#96%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], evt=18, evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831381649, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=false]
> [14:13:51,398][WARNING][exchange-worker-#96%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=0], evt=12, evtNode=TcpDiscoveryNode
> [id=d8c9f516-433d-4914-aed0-d07fb78aa960, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=10,
> intOrder=7, lastExchangeTime=1502831381649, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,399][WARNING][exchange-worker-#96%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=11, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=548f4233-67e9-4043-aa3a-086fb541c427, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=11,
> intOrder=0, lastExchangeTime=1502830168939, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,400][WARNING][exchange-worker-#96%null%][diagnostic] Pending
> transactions:
> [14:13:51,400][WARNING][exchange-worker-#96%null%][diagnostic] Pending
> explicit locks:
> [14:13:51,403][WARNING][exchange-worker-#96%null%][diagnostic] Pending
> cache futures:
> [14:13:51,404][WARNING][exchange-worker-#96%null%][diagnostic] Pending
> atomic cache futures:
> [14:13:51,404][WARNING][exchange-worker-#96%null%][diagnostic] Pending
> data streamer futures:
> [14:13:51,404][WARNING][exchange-worker-#96%null%][diagnostic] Pending
> transaction deadlock detection futures:
> [14:13:51,779][INFO][grid-nio-worker-tcp-comm-3-#20%null%][diagnostic]
> Exchange future waiting for coordinator response
> [crd=bda65979-33d1-4d6f-8a32-45b71255f835, topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1]]
> Remote node information:
> General node info [id=bda65979-33d1-4d6f-8a32-45b71255f835, client=false,
> discoTopVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> time=14:13:51.525]
> Partitions exchange info [readyVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=0]]
> Last initialized exchange future: GridDhtPartitionsExchangeFuture
> [dummy=false, forcePreload=false, reassign=false,
> discoEvt=DiscoveryCustomEvent [customMsg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831630880, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=bda65979, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1502831620166]], crd=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831630880,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=360559332], init=true, lastVer=GridCacheVersion [topVer=114231443,
> order=1502764777482, nodeOrder=3], partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions
> [startCaches=null, stopCaches=[ignite-sys-cache, PortCache,
> FcPortStatsCache, SwitchCache, FabricCache], startGrps=[],
> stopGrps=[ignite-sys-cache, destroy=false, PortCache, destroy=false,
> FcPortStatsCache, destroy=false, SwitchCache, destroy=false, FabricCache,
> destroy=false], resetParts=null, stateChangeRequest=StateChangeRequest
> [msg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620166, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[], super=GridFutureAdapter [ignoreInterrupts=false, state=INIT,
> res=null, hash=428221662]]
> Communication SPI statistics [rmtNode=548f4233-67e9-4043-
> aa3a-086fb541c427]
> Communication SPI recovery descriptors:
>     [key=ConnectionKey [nodeId=548f4233-67e9-4043-aa3a-086fb541c427,
> idx=0, connCnt=0], msgsSent=103, msgsAckedByRmt=96, msgsRcvd=106,
> lastAcked=96, reserveCnt=1, descIdHash=2019083035]
> Communication SPI clients:
>     [node=548f4233-67e9-4043-aa3a-086fb541c427, client=GridTcpNioCommunicationClient
> [ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
> [super=AbstractNioClientWorker [idx=1, bytesRcvd=569566918,
> bytesSent=3727054, bytesRcvd0=853, bytesSent0=0, select=true,
> super=GridWorker [name=grid-nio-worker-tcp-comm-1,
> igniteInstanceName=null, finished=false, hashCode=1204083040,
> interrupted=false, runner=grid-nio-worker-tcp-comm-1-#18%null%]]],
> writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
> readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], inRecovery=GridNioRecoveryDescriptor
> [acked=96, resendCnt=0, rcvCnt=106, sentCnt=103, reserved=true, lastAck=96,
> nodeLeft=false, node=TcpDiscoveryNode [id=548f4233-67e9-4043-aa3a-086fb541c427,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/0:0:0:0:0:0:0:1%lo:0,
> /127.0.0.1:0, /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /
> 10.24.51.187:0], discPort=0, order=11, intOrder=8, lastExchangeTime=1502831380784,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true],
> connected=true, connectCnt=0, queueLimit=4096, reserveCnt=1,
> pairedConnections=false], outRecovery=GridNioRecoveryDescriptor
> [acked=96, resendCnt=0, rcvCnt=106, sentCnt=103, reserved=true, lastAck=96,
> nodeLeft=false, node=TcpDiscoveryNode [id=548f4233-67e9-4043-aa3a-086fb541c427,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/0:0:0:0:0:0:0:1%lo:0,
> /127.0.0.1:0, /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /
> 10.24.51.187:0], discPort=0, order=11, intOrder=8, lastExchangeTime=1502831380784,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true],
> connected=true, connectCnt=0, queueLimit=4096, reserveCnt=1,
> pairedConnections=false], super=GridNioSessionImpl
> [locAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982:47100,
> rmtAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39926,
> createTime=1502831383244, closeTime=0, bytesSent=3569974, bytesRcvd=4153,
> bytesSent0=0, bytesRcvd0=853, sndSchedTime=1502831383244,
> lastSndTime=1502831546390, lastRcvTime=1502831631525, readsPaused=false,
> filterChain=FilterChain[filters=[GridNioCodecFilter
> [parser=org.apache.ignite.internal.util.nio.GridDirectParser@33874199,
> directMode=true], GridConnectionBytesVerifyFilter], accepted=true]],
> super=GridAbstractCommunicationClient [lastUsed=1502831383244,
> closed=false, connIdx=0]]]
> NIO sessions statistics:
> >> Selector info [idx=1, keysCnt=1, bytesRcvd=569566918, bytesRcvd0=853,
> bytesSent=3727054, bytesSent0=0]
>     Connection info [in=true, rmtAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39926,
> locAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982:47100, msgsSent=103,
> msgsAckedByRmt=96, descIdHash=2019083035, unackedMsgs=[GridQueryNextPageResponse,
> GridQueryNextPageResponse, GridQueryNextPageResponse,
> GridQueryNextPageResponse, GridQueryNextPageResponse], msgsRcvd=106,
> lastAcked=96, descIdHash=2019083035, bytesRcvd=4153, bytesRcvd0=853,
> bytesSent=3569974, bytesSent0=0, opQueueSize=0]
> Exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831631537, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=bda65979, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1502831620166]], crd=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831631537,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=360559332], init=true, lastVer=GridCacheVersion [topVer=114231443,
> order=1502764777482, nodeOrder=3], partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions
> [startCaches=null, stopCaches=[ignite-sys-cache, PortCache,
> FcPortStatsCache, SwitchCache, FabricCache], startGrps=[],
> stopGrps=[ignite-sys-cache, destroy=false, PortCache, destroy=false,
> FcPortStatsCache, destroy=false, SwitchCache, destroy=false, FabricCache,
> destroy=false], resetParts=null, stateChangeRequest=StateChangeRequest
> [msg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620166, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[], super=GridFutureAdapter [ignoreInterrupts=false, state=INIT,
> res=null, hash=428221662]]
> Local communication statistics:
> Communication SPI statistics [rmtNode=bda65979-33d1-4d6f-
> 8a32-45b71255f835]
> Communication SPI recovery descriptors:
>     [key=ConnectionKey [nodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> idx=0, connCnt=-1], msgsSent=106, msgsAckedByRmt=96, msgsRcvd=104,
> lastAcked=96, reserveCnt=1, descIdHash=859262134]
> Communication SPI clients:
>     [node=bda65979-33d1-4d6f-8a32-45b71255f835, client=GridTcpNioCommunicationClient
> [ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
> [super=AbstractNioClientWorker [idx=3, bytesRcvd=3579228, bytesSent=4129,
> bytesRcvd0=9282, bytesSent0=853, select=true, super=GridWorker
> [name=grid-nio-worker-tcp-comm-3, igniteInstanceName=null,
> finished=false, hashCode=969336725, interrupted=false,
> runner=grid-nio-worker-tcp-comm-3-#20%null%]]], writeBuf=java.nio.DirectByteBuffer[pos=0
> lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768
> cap=32768], inRecovery=GridNioRecoveryDescriptor [acked=96, resendCnt=0,
> rcvCnt=104, sentCnt=106, reserved=true, lastAck=96, nodeLeft=false,
> node=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831381649,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=1, queueLimit=4096, reserveCnt=1,
> pairedConnections=false], outRecovery=GridNioRecoveryDescriptor
> [acked=96, resendCnt=0, rcvCnt=104, sentCnt=106, reserved=true, lastAck=96,
> nodeLeft=false, node=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831381649,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=1, queueLimit=4096, reserveCnt=1,
> pairedConnections=false], super=GridNioSessionImpl
> [locAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39926,
> rmtAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47100,
> createTime=1502831383242, closeTime=0, bytesSent=4111, bytesRcvd=3579228,
> bytesSent0=853, bytesRcvd0=9282, sndSchedTime=1502831383242,
> lastSndTime=1502831631530, lastRcvTime=1502831631541, readsPaused=false,
> filterChain=FilterChain[filters=[GridNioCodecFilter
> [parser=org.apache.ignite.internal.util.nio.GridDirectParser@438486ef,
> directMode=true], GridConnectionBytesVerifyFilter], accepted=false]],
> super=GridAbstractCommunicationClient [lastUsed=1502831383242,
> closed=false, connIdx=0]]]
> NIO sessions statistics:
> >> Selector info [idx=3, keysCnt=1, bytesRcvd=3579228, bytesRcvd0=9282,
> bytesSent=4129, bytesSent0=853]
>     Connection info [in=false, rmtAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47100,
> locAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39926, msgsSent=106,
> msgsAckedByRmt=96, descIdHash=859262134, unackedMsgs=[GridQueryNextPageRequest,
> GridQueryNextPageRequest, GridQueryNextPageRequest,
> GridQueryNextPageRequest, GridQueryNextPageRequest], msgsRcvd=104,
> lastAcked=96, descIdHash=859262134, bytesRcvd=3579228, bytesRcvd0=9282,
> bytesSent=4111, bytesSent0=853, opQueueSize=0]
>
> Then the logs seem to repeat starting with " Failed to wait for partition
> map exchange ...".
>
> Eventually only logs like this are repeated, seems every 10 seconds.
>
> [16:10:53,425][WARNING][exchange-worker-#96%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=548f4233-67e9-4043-aa3a-
> 086fb541c427]. Dumping pending objects that might be the cause:
> [16:11:03,426][WARNING][exchange-worker-#96%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=548f4233-67e9-4043-aa3a-
> 086fb541c427]. Dumping pending objects that might be the cause:
> [16:11:13,427][WARNING][exchange-worker-#96%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=548f4233-67e9-4043-aa3a-
> 086fb541c427]. Dumping pending objects that might be the cause:
> [16:11:23,428][WARNING][exchange-worker-#96%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=548f4233-67e9-4043-aa3a-
> 086fb541c427]. Dumping pending objects that might be the cause:
> [16:11:33,428][WARNING][exchange-worker-#96%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=548f4233-67e9-4043-aa3a-
> 086fb541c427]. Dumping pending objects that might be the cause:
> [16:11:43,428][WARNING][exchange-worker-#96%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=548f4233-67e9-4043-aa3a-
> 086fb541c427]. Dumping pending objects that might be the cause:
>
>
> Server node 1 logs:
>
> [14:13:40,170][INFO][tcp-disco-msg-worker-#3%null%][GridClusterStateProcessor]
> Start state transition: false
> [14:13:40,172][INFO][exchange-worker-#34%null%][time] Started exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> crd=true, evt=18, node=T
> cpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockA
> ddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort
> =47500, order=1, intOrder=1, lastExchangeTime=1502831618858, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> evtNode=TcpDiscoveryNode [id=bda65979-
> 33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190,
> 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9
> dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1,
> lastExchangeTime=1502831618858, loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a,
> isClient=false], customEvt=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46
> f7-b156-f1ceac90bb7a, reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d,
> initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835, activate=false]]
> [14:13:40,172][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Start deactivation process
> [nodeId=bda65979-33d1-4d6f-8a32-45b71255f835, client
> =false, topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1]]
> [14:13:40,320][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Successfully deactivated data
> structures, services and caches [nodeId=bda65979-
> 33d1-4d6f-8a32-45b71255f835, client=false, topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1]]
> [14:13:40,344][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Finished waiting for partition release
> future [topVer=AffinityTopologyVersion [
> topVer=12, minorTopVer=1], waitTime=0ms]
> [14:13:40,345][INFO][exchange-worker-#34%null%][time] Finished exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1], crd=true]
> [14:13:40,612][INFO][grid-nio-worker-tcp-comm-3-#20%null%][TcpCommunicationSpi]
> Accepted incoming communication connection [locAddr=/2620:100:0:fe07:
> f92c:9dbd:9
> b0f:9982:47100, rmtAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39956]
> [14:13:40,780][INFO][grid-nio-worker-tcp-comm-2-#19%null%][TcpCommunicationSpi]
> Accepted incoming communication connection [locAddr=/2620:100:0:fe07:
> f92c:9dbd:9
> b0f:9982:47100, rmtAddr=/2620:100:0:fe07:537b:3459:e373:2436:46124]
> [14:13:41,153][INFO][tcp-disco-msg-worker-#3%null%][GridClusterStateProcessor]
> Received state change finish message: false
> [14:13:41,367][INFO][sys-#8331%null%][GridDhtPartitionsExchangeFuture]
> Snapshot initialization completed [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer
> =1], time=0ms]
> [14:13:50,385][WARNING][exchange-worker-#34%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer
> =1], node=bda65979-33d1-4d6f-8a32-45b71255f835]. Dumping pending objects
> that might be the cause:
> [14:13:50,387][WARNING][exchange-worker-#34%null%][diagnostic] Ready
> affinity version: AffinityTopologyVersion [topVer=12, minorTopVer=0]
> [14:13:50,418][WARNING][exchange-worker-#34%null%][diagnostic] Last
> exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831628889, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=bda65979, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1502831620166]], crd=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831628889,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=360559332], init=true, lastVer=GridCacheVersion [topVer=114231443,
> order=1502764777482, nodeOrder=3], partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions
> [startCaches=null, stopCaches=[ignite-sys-cache, PortCache,
> FcPortStatsCache, SwitchCache, FabricCache], startGrps=[],
> stopGrps=[ignite-sys-cache, destroy=false, PortCache, destroy=false,
> FcPortStatsCache, destroy=false, SwitchCache, destroy=false, FabricCache,
> destroy=false], resetParts=null, stateChangeRequest=StateChangeRequest
> [msg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620166, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[], super=GridFutureAdapter [ignoreInterrupts=false, state=INIT,
> res=null, hash=428221662]]
> [14:13:50,419][WARNING][exchange-worker-#34%null%][
> GridCachePartitionExchangeManager] First 10 pending exchange futures
> [total=0]
> [14:13:50,419][WARNING][exchange-worker-#34%null%][diagnostic] Last 10
> exchange futures (total: 12):
> [14:13:50,419][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], evt=18, evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831628889, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=false]
> [14:13:50,420][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=0], evt=12, evtNode=TcpDiscoveryNode
> [id=d8c9f516-433d-4914-aed0-d07fb78aa960, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=10, intOrder=7, lastExchangeTime=1502830171605,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:50,420][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=11, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=548f4233-67e9-4043-aa3a-086fb541c427, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=11, intOrder=8, lastExchangeTime=1502831380784,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:50,420][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=10, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=d8c9f516-433d-4914-aed0-d07fb78aa960, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=10, intOrder=7, lastExchangeTime=1502830171605,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:50,420][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=9, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=3d162ac0-049f-4aa8-a4aa-3cc1667d7c70, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=4, intOrder=4, lastExchangeTime=1502751454121,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:50,420][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=8, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=8b933c1c-bf0c-4fb8-ba2e-fc188248099c, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=7, intOrder=6, lastExchangeTime=1502816032452,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:50,421][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=7, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=8b933c1c-bf0c-4fb8-ba2e-fc188248099c, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=7, intOrder=6, lastExchangeTime=1502816032452,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:50,421][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=2], evt=18, evtNode=TcpDiscoveryNode
> [id=4d8c099c-b04f-48f9-a825-25eba9d794c5, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.150, 127.0.0.1, 2620:100:0:fe07:537b:3459:e373:2436%enp0s3],
> sockAddrs=[5e29cfd6.englab.brocade.com/10.24.51.150:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500, /2620:100:0:fe07:537b:3459:e373:2436%enp0s3:47500],
> discPort=47500, order=3, intOrder=3, lastExchangeTime=1502751448020,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=true]
> [14:13:50,421][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=1], evt=18, evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831628889, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=true]
> [14:13:50,421][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=b6e50583-4f35-46fc-9f7b-4702abf9bea3, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=5, intOrder=5, lastExchangeTime=1502753203971,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:50,422][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> transactions:
> [14:13:50,436][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> explicit locks:
> [14:13:50,437][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> cache futures:
> [14:13:50,437][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> atomic cache futures:
> [14:13:50,437][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> data streamer futures:
> [14:13:50,437][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> transaction deadlock detection futures:
>
> Logs seem to repeat starting with " Failed to wait for partition map
> exchange ...".
>
> Later repetitions only have these logs:
>
> [16:18:35,463][WARNING][exchange-worker-#34%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer
> =1], node=bda65979-33d1-4d6f-8a32-45b71255f835]. Dumping pending objects
> that might be the cause:
> [16:18:45,465][WARNING][exchange-worker-#34%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer
> =1], node=bda65979-33d1-4d6f-8a32-45b71255f835]. Dumping pending objects
> that might be the cause:
> [16:18:52,458][INFO][db-checkpoint-thread-#562%null%][
> GridCacheDatabaseSharedManager] Skipping checkpoint (no pages were
> modified) [checkpointLockWait=0ms, chec
> kpointLockHoldTime=0ms, reason='timeout']
> [16:18:52,738][INFO][exchange-worker-#34%null%][
> GridCachePartitionExchangeManager] Skipping rebalancing (nothing
> scheduled) [top=AffinityTopologyVersion [topVer
> =12, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
> node=bda65979-33d1-4d6f-8a32-45b71255f835]
>
>
> Server node 2 logs:
>
> [14:13:40,299][INFO][tcp-disco-msg-worker-#3%null%][GridClusterStateProcessor]
> Start state transition: false
> [14:13:40,302][INFO][exchange-worker-#34%null%][time] Started exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> crd=false, evt=18, node=TcpDiscoveryNode [id=6ffb9c55-4f23-4920-8134-36a649371cda,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/2620:100:0:fe07:
> ed4c:b7b8:f80c:9bef%enp0s3:47500, /0:0:0:0:0:0:0:1%lo:47500, /
> 127.0.0.1:47500, rfische-2.englab.brocade.com/10.24.51.187:47500],
> discPort=47500, order=2, intOrder=2, lastExchangeTime=1502831618860,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> evtNode=TcpDiscoveryNode [id=6ffb9c55-4f23-4920-8134-36a649371cda,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/2620:100:0:fe07:
> ed4c:b7b8:f80c:9bef%enp0s3:47500, /0:0:0:0:0:0:0:1%lo:47500, /
> 127.0.0.1:47500, rfische-2.englab.brocade.com/10.24.51.187:47500],
> discPort=47500, order=2, intOrder=2, lastExchangeTime=1502831618860,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], customEvt=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false]]
> [14:13:40,302][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Start deactivation process
> [nodeId=6ffb9c55-4f23-4920-8134-36a649371cda, client=false,
> topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1]]
> [14:13:40,314][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Successfully deactivated data
> structures, services and caches [nodeId=6ffb9c55-4f23-4920-8134-36a649371cda,
> client=false, topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1]]
> [14:13:40,320][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Finished waiting for partition release
> future [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> waitTime=0ms]
> [14:13:40,940][INFO][grid-nio-worker-tcp-comm-2-#19%null%][TcpCommunicationSpi]
> Established outgoing communication connection [locAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39956,
> rmtAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47100]
> [14:13:40,940][INFO][exchange-worker-#34%null%][time] Finished exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> crd=false]
> [14:13:41,169][INFO][tcp-disco-msg-worker-#3%null%][GridClusterStateProcessor]
> Received state change finish message: false
> [14:13:41,926][INFO][sys-#8323%null%][GridDhtPartitionsExchangeFuture]
> Snapshot initialization completed [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], time=0ms]
> [14:13:50,965][WARNING][exchange-worker-#34%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], node=6ffb9c55-4f23-4920-8134-36a649371cda].
> Dumping pending objects that might be the cause:
> [14:13:50,966][WARNING][exchange-worker-#34%null%][diagnostic] Ready
> affinity version: AffinityTopologyVersion [topVer=12, minorTopVer=0]
> [14:13:51,078][WARNING][exchange-worker-#34%null%][diagnostic] Last
> exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502751442316, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=6ffb9c55, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1502831620299]], crd=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502751442316,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=1900349389], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions
> [startCaches=null, stopCaches=[ignite-sys-cache, PortCache,
> FcPortStatsCache, SwitchCache, FabricCache], startGrps=[],
> stopGrps=[ignite-sys-cache, destroy=false, PortCache, destroy=false,
> FcPortStatsCache, destroy=false, SwitchCache, destroy=false, FabricCache,
> destroy=false], resetParts=null, stateChangeRequest=StateChangeRequest
> [msg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620299, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[bda65979-33d1-4d6f-8a32-45b71255f835, 4d8c099c-b04f-48f9-a825-25eba9d794c5],
> super=GridFutureAdapter [ignoreInterrupts=false, state=INIT, res=null,
> hash=322499757]]
> [14:13:51,078][WARNING][exchange-worker-#34%null%][
> GridCachePartitionExchangeManager] First 10 pending exchange futures
> [total=0]
> [14:13:51,080][WARNING][exchange-worker-#34%null%][diagnostic] Last 10
> exchange futures (total: 12):
> [14:13:51,081][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], evt=18, evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502751442316, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=false]
> [14:13:51,081][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=0], e:
> vt=12, evtNode=TcpDiscoveryNode [id=d8c9f516-433d-4914-aed0-d07fb78aa960,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/0:0:0:0:0:0:0:1%lo:0,
> /127.0.0.1:0, /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=10,
> intOrder=7, lastExchangeTime=1502830171994, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,081][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=11, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=548f4233-67e9-4043-aa3a-086fb541c427, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=11,
> intOrder=8, lastExchangeTime=1502831380904, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,081][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=10, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=d8c9f516-433d-4914-aed0-d07fb78aa960, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=10,
> intOrder=7, lastExchangeTime=1502830171994, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,081][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=9, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=3d162ac0-049f-4aa8-a4aa-3cc1667d7c70, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=4,
> intOrder=4, lastExchangeTime=1502751454165, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,082][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=8, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=8b933c1c-bf0c-4fb8-ba2e-fc188248099c, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=7,
> intOrder=6, lastExchangeTime=1502816032799, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,082][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=7, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=8b933c1c-bf0c-4fb8-ba2e-fc188248099c, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=7,
> intOrder=6, lastExchangeTime=1502816032799, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,082][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=2], evt=18, evtNode=TcpDiscoveryNode
> [id=4d8c099c-b04f-48f9-a825-25eba9d794c5, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.150, 127.0.0.1, 2620:100:0:fe07:537b:3459:e373:2436%enp0s3],
> sockAddrs=[rfische-3.englab.brocade.com/10.24.51.150:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500, /2620:100:0:fe07:537b:3459:e373:2436%enp0s3:47500],
> discPort=47500, order=3, intOrder=3, lastExchangeTime=1502751448052,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=true]
> [14:13:51,082][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=1], evt=18, evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502751442316, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=true]
> [14:13:51,082][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=b6e50583-4f35-46fc-9f7b-4702abf9bea3, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0,
> rfische-2.englab.brocade.com/10.24.51.187:0], discPort=0, order=5,
> intOrder=5, lastExchangeTime=1502753205000, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,082][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> transactions:
> [14:13:51,082][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> explicit locks:
> [14:13:51,089][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> cache futures:
> [14:13:51,089][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> atomic cache futures:
> [14:13:51,089][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> data streamer futures:
> [14:13:51,090][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> transaction deadlock detection futures:
> [14:13:51,863][INFO][grid-nio-worker-tcp-comm-3-#20%null%][diagnostic]
> Exchange future waiting for coordinator response
> [crd=bda65979-33d1-4d6f-8a32-45b71255f835, topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1]]
> Remote node information:
> General node info [id=bda65979-33d1-4d6f-8a32-45b71255f835, client=false,
> discoTopVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> time=14:13:51.481]
> Partitions exchange info [readyVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=0]]
> Last initialized exchange future: GridDhtPartitionsExchangeFuture
> [dummy=false, forcePreload=false, reassign=false,
> discoEvt=DiscoveryCustomEvent [customMsg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastEx:
> changeTime=1502831630880, loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a,
> isClient=false], topVer=12, nodeId8=bda65979, msg=null,
> type=DISCOVERY_CUSTOM_EVT, tstamp=1502831620166]], crd=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831630880, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=360559332], init=true, lastVer=GridCacheVersion [topVer=114231443,
> order=1502764777482, nodeOrder=3], partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions
> [startCaches=null, stopCaches=[ignite-sys-cache, PortCache,
> FcPortStatsCache, SwitchCache, FabricCache], startGrps=[],
> stopGrps=[ignite-sys-cache, destroy=false, PortCache, destroy=false,
> FcPortStatsCache, destroy=false, SwitchCache, destroy=false, FabricCache,
> destroy=false], resetParts=null, stateChangeRequest=StateChangeRequest
> [msg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620166, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[], super=GridFutureAdapter [ignoreInterrupts=false, state=INIT,
> res=null, hash=428221662]]
> Communication SPI statistics [rmtNode=6ffb9c55-4f23-4920-
> 8134-36a649371cda]
> Communication SPI recovery descriptors:
>     [key=ConnectionKey [nodeId=6ffb9c55-4f23-4920-8134-36a649371cda,
> idx=0, connCnt=0], msgsSent=6, msgsAckedByRmt=5, msgsRcvd=7, lastAcked=5,
> reserveCnt=3, descIdHash=1831806861]
> Communication SPI clients:
>     [node=6ffb9c55-4f23-4920-8134-36a649371cda, client=GridTcpNioCommunicationClient
> [ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
> [super=AbstractNioClientWorker [idx=3, bytesRcvd=778699647,
> bytesSent=188269, bytesRcvd0=853, bytesSent0=0, select=true,
> super=GridWorker [name=grid-nio-worker-tcp-comm-3,
> igniteInstanceName=null, finished=false, hashCode=1677075109,
> interrupted=false, runner=grid-nio-worker-tcp-comm-3-#20%null%]]],
> writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
> readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], inRecovery=GridNioRecoveryDescriptor
> [acked=5, resendCnt=0, rcvCnt=7, sentCnt=6, reserved=true, lastAck=5,
> nodeLeft=false, node=TcpDiscoveryNode [id=6ffb9c55-4f23-4920-8134-36a649371cda,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/2620:100:0:fe07:
> ed4c:b7b8:f80c:9bef%enp0s3:47500, /0:0:0:0:0:0:0:1%lo:47500, /
> 127.0.0.1:47500, /10.24.51.187:47500], discPort=47500, order=2,
> intOrder=2, lastExchangeTime=1502751442204, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], connected=true,
> connectCnt=0, queueLimit=4096, reserveCnt=3, pairedConnections=false],
> outRecovery=GridNioRecoveryDescriptor [acked=5, resendCnt=0, rcvCnt=7,
> sentCnt=6, reserved=true, lastAck=5, nodeLeft=false, node=TcpDiscoveryNode
> [id=6ffb9c55-4f23-4920-8134-36a649371cda, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500, /10.24.51.187:47500],
> discPort=47500, order=2, intOrder=2, lastExchangeTime=1502751442204,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=0, queueLimit=4096, reserveCnt=3,
> pairedConnections=false], super=GridNioSessionImpl
> [locAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982:47100,
> rmtAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39956,
> createTime=1502831620610, closeTime=0, bytesSent=5151, bytesRcvd=11937,
> bytesSent0=0, bytesRcvd0=853, sndSchedTime=1502831620610,
> lastSndTime=1502831621365, lastRcvTime=1502831631409, readsPaused=false,
> filterChain=FilterChain[filters=[GridNioCodecFilter
> [parser=org.apache.ignite.internal.util.nio.GridDirectParser@33874199,
> directMode=true], GridConnectionBytesVerifyFilter], accepted=true]],
> super=GridAbstractCommunicationClient [lastUsed=1502831620713,
> closed=false, connIdx=0]]]
> NIO sessions statistics:
> >> Selector info [idx=3, keysCnt=1, bytesRcvd=778699647, bytesRcvd0=853,
> bytesSent=188269, bytesSent0=0]
>     Connection info [in=true, rmtAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39956,
> locAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982:47100, msgsSent=6,
> msgsAckedByRmt=5, descIdHash=1831806861, unackedMsgs=[GridDhtPartitionsFullMessage],
> msgsRcvd=7, lastAcked=5, descIdHash=1831806861, bytesRcvd=11937,
> bytesRcvd0=853, bytesSent=5151, bytesSent0=0, opQueueSize=0]
> Exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831630880, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=bda65979, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1502831620166]], crd=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831630880,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=360559332], init=true, lastVer=GridCacheVersion [topVer=114231443,
> order=1502764777482, nodeOrder=3], partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions [startCaches=nu:
> ll, stopCaches=[ignite-sys-cache, PortCache, FcPortStatsCache,
> SwitchCache, FabricCache], startGrps=[], stopGrps=[ignite-sys-cache,
> destroy=false, PortCache, destroy=false, FcPortStatsCache, destroy=false,
> SwitchCache, destroy=false, FabricCache, destroy=false], resetParts=null,
> stateChangeRequest=StateChangeRequest [msg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620166, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[], super=GridFutureAdapter [ignoreInterrupts=false, state=INIT,
> res=null, hash=428221662]]
> Local communication statistics:
> Communication SPI statistics [rmtNode=bda65979-33d1-4d6f-
> 8a32-45b71255f835]
> Communication SPI recovery descriptors:
>     [key=ConnectionKey [nodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> idx=0, connCnt=-1], msgsSent=7, msgsAckedByRmt=5, msgsRcvd=7, lastAcked=5,
> reserveCnt=3, descIdHash=1699623061]
> Communication SPI clients:
>     [node=bda65979-33d1-4d6f-8a32-45b71255f835, client=GridTcpNioCommunicationClient
> [ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
> [super=AbstractNioClientWorker [idx=2, bytesRcvd=1301067310,
> bytesSent=316517, bytesRcvd0=9187, bytesSent0=853, select=true,
> super=GridWorker [name=grid-nio-worker-tcp-comm-2,
> igniteInstanceName=null, finished=false, hashCode=1774276493,
> interrupted=false, runner=grid-nio-worker-tcp-comm-2-#19%null%]]],
> writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
> readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], inRecovery=GridNioRecoveryDescriptor
> [acked=5, resendCnt=0, rcvCnt=7, sentCnt=7, reserved=true, lastAck=5,
> nodeLeft=false, node=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502751442316,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=3, queueLimit=4096, reserveCnt=3,
> pairedConnections=false], outRecovery=GridNioRecoveryDescriptor [acked=5,
> resendCnt=0, rcvCnt=7, sentCnt=7, reserved=true, lastAck=5, nodeLeft=false,
> node=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502751442316,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=3, queueLimit=4096, reserveCnt=3,
> pairedConnections=false], super=GridNioSessionImpl
> [locAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39956,
> rmtAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47100,
> createTime=1502831620938, closeTime=0, bytesSent=11895, bytesRcvd=14310,
> bytesSent0=853, bytesRcvd0=9187, sndSchedTime=1502831620938,
> lastSndTime=1502831631416, lastRcvTime=1502831631519, readsPaused=false,
> filterChain=FilterChain[filters=[GridNioCodecFilter
> [parser=org.apache.ignite.internal.util.nio.GridDirectParser@58c3122a,
> directMode=true], GridConnectionBytesVerifyFilter], accepted=false]],
> super=GridAbstractCommunicationClient [lastUsed=1502831620938,
> closed=false, connIdx=0]]]
> NIO sessions statistics:
> >> Selector info [idx=2, keysCnt=1, bytesRcvd=1301067310, bytesRcvd0=9187,
> bytesSent=316517, bytesSent0=853]
>     Connection info [in=false, rmtAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47100,
> locAddr=/2620:100:0:fe07:ed4c:b7b8:f80c:9bef:39956, msgsSent=7,
> msgsAckedByRmt=5, descIdHash=1699623061, unackedMsgs=[
> GridDhtPartitionsSingleMessage, IgniteDiagnosticMessage], msgsRcvd=7,
> lastAcked=5, descIdHash=1699623061, bytesRcvd=14310, bytesRcvd0=9187,
> bytesSent=11895, bytesSent0=853, opQueueSize=0]
>
> Again repeating some of the above logs.
>
>
> Server node 3:
>
> [14:13:40,311][INFO][tcp-disco-msg-worker-#3%null%][GridClusterStateProcessor]
> Start state transition: false
> [14:13:40,314][INFO][exchange-worker-#34%null%][time] Started exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> crd=false, evt=18, node=
> TcpDiscoveryNode [id=4d8c099c-b04f-48f9-a825-25eba9d794c5,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.150, 127.0.0.1,
> 2620:100:0:fe07:537b:3459:e373:2436%enp0s3], sock
> Addrs=[rfische-3.englab.brocade.com/10.24.51.150:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500, /2620:100:0:fe07:537b:3459:e373:2436%enp0s3:47500],
> discPor
> t=47500, order=3, intOrder=3, lastExchangeTime=1502831620309, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> evtNode=TcpDiscoveryNode [id=4d8c099c
> -b04f-48f9-a825-25eba9d794c5, addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.150,
> 127.0.0.1, 2620:100:0:fe07:537b:3459:e373:2436%enp0s3],
> sockAddrs=[rfische-3.englab.broca
> de.com/10.24.51.150:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500,
> /2620:100:0:fe07:537b:3459:e373:2436%enp0s3:47500], discPort=47500,
> order=3, intOrder=3,
>  lastExchangeTime=1502831620309, loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a,
> isClient=false], customEvt=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-4
> 6f7-b156-f1ceac90bb7a, reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d,
> initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835, activate=false]]
> [14:13:40,314][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Start deactivation process
> [nodeId=4d8c099c-b04f-48f9-a825-25eba9d794c5, client
> =false, topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1]]
> [14:13:40,334][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Successfully deactivated data
> structures, services and caches [nodeId=4d8c099c-
> b04f-48f9-a825-25eba9d794c5, client=false, topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1]]
> [14:13:40,335][INFO][exchange-worker-#34%null%][
> GridDhtPartitionsExchangeFuture] Finished waiting for partition release
> future [topVer=AffinityTopologyVersion [
> topVer=12, minorTopVer=1], waitTime=0ms]
> [14:13:40,789][INFO][grid-nio-worker-tcp-comm-3-#20%null%][TcpCommunicationSpi]
> Established outgoing communication connection [locAddr=/2620:100:0:fe07:
> 537b:345
> 9:e373:2436:46124, rmtAddr=/2620:100:0:fe07:f92c:
> 9dbd:9b0f:9982%enp0s3:47100]
> [14:13:40,790][INFO][exchange-worker-#34%null%][time] Finished exchange
> init [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> crd=false]
> [14:13:41,178][INFO][tcp-disco-msg-worker-#3%null%][GridClusterStateProcessor]
> Received state change finish message: false
> [14:13:42,151][INFO][sys-#8325%null%][GridDhtPartitionsExchangeFuture]
> Snapshot initialization completed [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer
> =1], time=0ms]
> [14:13:50,908][WARNING][exchange-worker-#34%null%][diagnostic] Failed to
> wait for partition map exchange [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer
> =1], node=4d8c099c-b04f-48f9-a825-25eba9d794c5]. Dumping pending objects
> that might be the cause:
> [14:13:50,909][WARNING][exchange-worker-#34%null%][diagnostic] Ready
> affinity version: AffinityTopologyVersion [topVer=12, minorTopVer=0]
> [14:13:51,141][WARNING][exchange-worker-#34%null%][diagnostic] Last
> exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=
> false, discoEvt=DiscoveryCustomEvent [customMsg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7
> a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=Discovery
> Event [evtNode=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:998
> 2%enp0s3], sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500, /
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, orde
> r=1, intOrder=1, lastExchangeTime=1502751448111, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=4d8c099c, msg=null, type=DISCO
> VERY_CUSTOM_EVT, tstamp=1502831620309]], crd=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620
> :100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, /10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.
> 1:47500], discPort=47500, order=1, intOrder=1, lastExchangeTime=1502751448111,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> exchId=GridDhtParti
> tionExchangeId [topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ig
> noreInterrupts=false, state=DONE, res=true, hash=1067966306], init=true,
> lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
> lsnrCalls=4, don
> e=true, cancelled=false, err=null, futs=[true, true, true, true]],
> exchActions=ExchangeActions [startCaches=null,
> stopCaches=[ignite-sys-cache, PortCache, FcPor
> tStatsCache, SwitchCache, FabricCache], startGrps=[],
> stopGrps=[ignite-sys-cache, destroy=false, PortCache, destroy=false,
> FcPortStatsCache, destroy=false, Swit
> chCache, destroy=false, FabricCache, destroy=false], resetParts=null,
> stateChangeRequest=StateChangeRequest [msg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246
> ce-e4d1-46f7-b156-f1ceac90bb7a, reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d,
> initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835, activate=false],
> topVer=Affin
> ityTopologyVersion [topVer=12, minorTopVer=1]]], affChangeMsg=null,
> skipPreload=false, clientOnlyExchange=false, initTs=1502831620309,
> centralizedAff=false, cha
> ngeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[6ffb9c55-4f23-4920-8134-36a649371cda, bda65979-33d1-4d6f-8a32-45b71255f835],
> super=Gr
> idFutureAdapter [ignoreInterrupts=false, state=INIT, res=null,
> hash=297725997]]
> [14:13:51,141][WARNING][exchange-worker-#34%null%][
> GridCachePartitionExchangeManager] First 10 pending exchange futures
> [total=0]
> [14:13:51,143][WARNING][exchange-worker-#34%null%][diagnostic] Last 10
> exchange futures (total: 12):
> [14:13:51,143][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=1], e
> vt=18, evtNode=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:998
> 2%enp0s3], sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500, /
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, orde
> r=1, intOrder=1, lastExchangeTime=1502751448111, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=false]
> [14:13:51,144][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=12, minorTopVer=0], e
> vt=12, evtNode=TcpDiscoveryNode [id=d8c9f516-433d-4914-aed0-d07fb78aa960,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.187, 127.0.0.1,
> 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3], sockAddrs=[/0:0:0:0:0:0:0:1%lo:0,
> /127.0.0.1:0, /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /
> 10.24.51.187:0], discPort=0, order=10, intOrder=7, lastExchangeTime=1502830173974,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,144][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=11, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=548f4233-67e9-4043-aa3a-086fb541c427, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=11, intOrder=8, lastExchangeTime=1502831381070,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,144][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=10, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=d8c9f516-433d-4914-aed0-d07fb78aa960, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=10, intOrder=7, lastExchangeTime=1502830173974,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,144][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=9, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=3d162ac0-049f-4aa8-a4aa-3cc1667d7c70, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=4, intOrder=4, lastExchangeTime=1502751454208,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,144][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=8, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=8b933c1c-bf0c-4fb8-ba2e-fc188248099c, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=7, intOrder=6, lastExchangeTime=1502816033053,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,145][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=7, minorTopVer=0], evt=10, evtNode=TcpDiscoveryNode
> [id=8b933c1c-bf0c-4fb8-ba2e-fc188248099c, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=7, intOrder=6, lastExchangeTime=1502816033053,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,145][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=2], evt=18, evtNode=TcpDiscoveryNode
> [id=4d8c099c-b04f-48f9-a825-25eba9d794c5, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.150, 127.0.0.1, 2620:100:0:fe07:537b:3459:e373:2436%enp0s3],
> sockAddrs=[rfische-3.englab.brocade.com/10.24.51.150:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500, /2620:100:0:fe07:537b:3459:e373:2436%enp0s3:47500],
> discPort=47500, order=3, intOrder=3, lastExchangeTime=1502831630889,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=true]
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=1], evt=18, evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500, /
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502751448111,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], done=true]
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] >>>
> GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
> [topVer=6, minorTopVer=0], evt=11, evtNode=TcpDiscoveryNode
> [id=b6e50583-4f35-46fc-9f7b-4702abf9bea3, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.187, 127.0.0.1, 2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3],
> sockAddrs=[/0:0:0:0:0:0:0:1%lo:0, /127.0.0.1:0,
> /2620:100:0:fe07:ed4c:b7b8:f80c:9bef%enp0s3:0, /10.24.51.187:0],
> discPort=0, order=5, intOrder=5, lastExchangeTime=1502753205141,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=true], done=true]
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> transactions:
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> explicit locks:
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> cache futures:
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> atomic cache futures:
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> data streamer futures:
> [14:13:51,146][WARNING][exchange-worker-#34%null%][diagnostic] Pending
> transaction deadlock detection futures:
> [14:13:51,690][INFO][sys-#8327%null%][diagnostic] Exchange future waiting
> for coordinator response [crd=bda65979-33d1-4d6f-8a32-45b71255f835,
> topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1]]
> Remote node information:
> General node info [id=bda65979-33d1-4d6f-8a32-45b71255f835, client=false,
> discoTopVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> time=14:13:51.525]
> Partitions exchange info [readyVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=0]]
> Last initialized exchange future: GridDhtPartitionsExchangeFuture
> [dummy=false, forcePreload=false, reassign=false,
> discoEvt=DiscoveryCustomEvent [customMsg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastEx:
> changeTime=1502831630880, loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a,
> isClient=false], topVer=12, nodeId8=bda65979, msg=null,
> type=DISCOVERY_CUSTOM_EVT, tstamp=1502831620166]], crd=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831630880, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=360559332], init=true, lastVer=GridCacheVersion [topVer=114231443,
> order=1502764777482, nodeOrder=3], partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions
> [startCaches=null, stopCaches=[ignite-sys-cache, PortCache,
> FcPortStatsCache, SwitchCache, FabricCache], startGrps=[],
> stopGrps=[ignite-sys-cache, destroy=false, PortCache, destroy=false,
> FcPortStatsCache, destroy=false, SwitchCache, destroy=false, FabricCache,
> destroy=false], resetParts=null, stateChangeRequest=StateChangeRequest
> [msg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620166, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[], super=GridFutureAdapter [ignoreInterrupts=false, state=INIT,
> res=null, hash=428221662]]
> Communication SPI statistics [rmtNode=4d8c099c-b04f-48f9-
> a825-25eba9d794c5]
> Communication SPI recovery descriptors:
>     [key=ConnectionKey [nodeId=4d8c099c-b04f-48f9-a825-25eba9d794c5,
> idx=0, connCnt=0], msgsSent=7, msgsAckedByRmt=6, msgsRcvd=7, lastAcked=5,
> reserveCnt=2, descIdHash=839849160]
> Communication SPI clients:
>     [node=4d8c099c-b04f-48f9-a825-25eba9d794c5, client=GridTcpNioCommunicationClient
> [ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
> [super=AbstractNioClientWorker [idx=2, bytesRcvd=27033, bytesSent=31221,
> bytesRcvd0=853, bytesSent0=0, select=true, super=GridWorker
> [name=grid-nio-worker-tcp-comm-2, igniteInstanceName=null,
> finished=false, hashCode=916303930, interrupted=false,
> runner=grid-nio-worker-tcp-comm-2-#19%null%]]], writeBuf=java.nio.DirectByteBuffer[pos=0
> lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768
> cap=32768], inRecovery=GridNioRecoveryDescriptor [acked=6, resendCnt=0,
> rcvCnt=7, sentCnt=7, reserved=true, lastAck=5, nodeLeft=false,
> node=TcpDiscoveryNode [id=4d8c099c-b04f-48f9-a825-25eba9d794c5,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.150, 127.0.0.1,
> 2620:100:0:fe07:537b:3459:e373:2436%enp0s3], sockAddrs=[5e29cfd6.englab.
> brocade.com/10.24.51.150:47500, /0:0:0:0:0:0:0:1%lo:47500, /
> 127.0.0.1:47500, /2620:100:0:fe07:537b:3459:e373:2436%enp0s3:47500],
> discPort=47500, order=3, intOrder=3, lastExchangeTime=1502751448020,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=0, queueLimit=4096, reserveCnt=2,
> pairedConnections=false], outRecovery=GridNioRecoveryDescriptor [acked=6,
> resendCnt=0, rcvCnt=7, sentCnt=7, reserved=true, lastAck=5, nodeLeft=false,
> node=TcpDiscoveryNode [id=4d8c099c-b04f-48f9-a825-25eba9d794c5,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.150, 127.0.0.1,
> 2620:100:0:fe07:537b:3459:e373:2436%enp0s3], sockAddrs=[5e29cfd6.englab.
> brocade.com/10.24.51.150:47500, /0:0:0:0:0:0:0:1%lo:47500, /
> 127.0.0.1:47500, /2620:100:0:fe07:537b:3459:e373:2436%enp0s3:47500],
> discPort=47500, order=3, intOrder=3, lastExchangeTime=1502751448020,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=0, queueLimit=4096, reserveCnt=2,
> pairedConnections=false], super=GridNioSessionImpl
> [locAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982:47100,
> rmtAddr=/2620:100:0:fe07:537b:3459:e373:2436:46124,
> createTime=1502831620775, closeTime=0, bytesSent=5151, bytesRcvd=12342,
> bytesSent0=0, bytesRcvd0=853, sndSchedTime=1502831620775,
> lastSndTime=1502831621365, lastRcvTime=1502831631275, readsPaused=false,
> filterChain=FilterChain[filters=[GridNioCodecFilter
> [parser=org.apache.ignite.internal.util.nio.GridDirectParser@33874199,
> directMode=true], GridConnectionBytesVerifyFilter], accepted=true]],
> super=GridAbstractCommunicationClient [lastUsed=1502831620775,
> closed=false, connIdx=0]]]
> NIO sessions statistics:
> >> Selector info [idx=2, keysCnt=1, bytesRcvd=27033, bytesRcvd0=853,
> bytesSent=31221, bytesSent0=0]
>     Connection info [in=true, rmtAddr=/2620:100:0:fe07:537b:3459:e373:2436:46124,
> locAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982:47100, msgsSent=7,
> msgsAckedByRmt=6, descIdHash=839849160, unackedMsgs=[GridDhtPartitionsFullMessage],
> msgsRcvd=7, lastAcked=5, descIdHash=839849160, bytesRcvd=12342,
> bytesRcvd0=853, bytesSent=5151, bytesSent0=0, opQueueSize=0]
> Exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=ChangeGlobalStateMessage [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], affTopVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500,
> rfische-1.englab.brocade.com/10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502831630880, loc=true,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], topVer=12,
> nodeId8=bda65979, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1502831620166]], crd=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, rfische-1.englab.brocade.com/
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502831630880,
> loc=true, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1],
> nodeId=bda65979, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
> hash=360559332], init=true, lastVer=GridCacheVersion [topVer=114231443,
> order=1502764777482, nodeOrder=3], partReleaseFut=GridCompoundFuture
> [rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
> futs=[true, true, true, true]], exchActions=ExchangeActions [startCaches=nu
> ll, stopCaches=[ignite-sys-cache, PortCache, FcPortStatsCache,
> SwitchCache, FabricCache], startGrps=[], stopGrps=[ignite-sys-cache,
> destroy=false, PortCache, destroy=false, FcPortStatsCache, destroy=false,
> SwitchCache, destroy=false, FabricCache, destroy=false], resetParts=null,
> stateChangeRequest=StateChangeRequest [msg=ChangeGlobalStateMessage
> [id=c90edf2ed51-d51246ce-e4d1-46f7-b156-f1ceac90bb7a,
> reqId=5505420d-5d31-4d2c-b0ae-fa7a77629d2d, initiatingNodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> activate=false], topVer=AffinityTopologyVersion [topVer=12,
> minorTopVer=1]]], affChangeMsg=null, skipPreload=false,
> clientOnlyExchange=false, initTs=1502831620166, centralizedAff=false,
> changeGlobalStateE=null, forcedRebFut=null, done=true, evtLatch=0,
> remaining=[], super=GridFutureAdapter [ignoreInterrupts=false, state=INIT,
> res=null, hash=428221662]]
> Local communication statistics:
> Communication SPI statistics [rmtNode=bda65979-33d1-4d6f-
> 8a32-45b71255f835]
> Communication SPI recovery descriptors:
>     [key=ConnectionKey [nodeId=bda65979-33d1-4d6f-8a32-45b71255f835,
> idx=0, connCnt=-1], msgsSent=7, msgsAckedByRmt=5, msgsRcvd=8, lastAcked=6,
> reserveCnt=2, descIdHash=1344296970]
> Communication SPI clients:
>     [node=bda65979-33d1-4d6f-8a32-45b71255f835, client=GridTcpNioCommunicationClient
> [ses=GridSelectorNioSessionImpl [worker=DirectNioClientWorker
> [super=AbstractNioClientWorker [idx=3, bytesRcvd=148911614,
> bytesSent=52025, bytesRcvd0=9227, bytesSent0=853, select=true,
> super=GridWorker [name=grid-nio-worker-tcp-comm-3,
> igniteInstanceName=null, finished=false, hashCode=9014207,
> interrupted=false, runner=grid-nio-worker-tcp-comm-3-#20%null%]]],
> writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
> readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768], inRecovery=GridNioRecoveryDescriptor
> [acked=5, resendCnt=0, rcvCnt=8, sentCnt=7, reserved=true, lastAck=6,
> nodeLeft=false, node=TcpDiscoveryNode [id=bda65979-33d1-4d6f-8a32-45b71255f835,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.24.51.190, 127.0.0.1,
> 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3], sockAddrs=[/2620:100:0:fe07:
> f92c:9dbd:9b0f:9982%enp0s3:47500, /10.24.51.190:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1502751448111, loc=false,
> ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false], connected=true,
> connectCnt=2, queueLimit=4096, reserveCnt=2, pairedConnections=false],
> outRecovery=GridNioRecoveryDescriptor [acked=5, resendCnt=0, rcvCnt=8,
> sentCnt=7, reserved=true, lastAck=6, nodeLeft=false, node=TcpDiscoveryNode
> [id=bda65979-33d1-4d6f-8a32-45b71255f835, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.24.51.190, 127.0.0.1, 2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3],
> sockAddrs=[/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47500, /
> 10.24.51.190:47500, /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500],
> discPort=47500, order=1, intOrder=1, lastExchangeTime=1502751448111,
> loc=false, ver=2.1.0#20170720-sha1:a6ca5c8a, isClient=false],
> connected=true, connectCnt=2, queueLimit=4096, reserveCnt=2,
> pairedConnections=false], super=GridNioSessionImpl
> [locAddr=/2620:100:0:fe07:537b:3459:e373:2436:46124,
> rmtAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47100,
> createTime=1502831620779, closeTime=0, bytesSent=12300, bytesRcvd=14350,
> bytesSent0=853, bytesRcvd0=9227, sndSchedTime=1502831620779,
> lastSndTime=1502831631275, lastRcvTime=1502831631532, readsPaused=false,
> filterChain=FilterChain[filters=[GridNioCodecFilter
> [parser=org.apache.ignite.internal.util.nio.GridDirectParser@14439bfb,
> directMode=true], GridConnectionBytesVerifyFilter], accepted=false]],
> super=GridAbstractCommunicationClient [lastUsed=1502831620790,
> closed=false, connIdx=0]]]
> NIO sessions statistics:
> >> Selector info [idx=3, keysCnt=1, bytesRcvd=148911614, bytesRcvd0=9227,
> bytesSent=52025, bytesSent0=853]
>     Connection info [in=false, rmtAddr=/2620:100:0:fe07:f92c:9dbd:9b0f:9982%enp0s3:47100,
> locAddr=/2620:100:0:fe07:537b:3459:e373:2436:46124, msgsSent=7,
> msgsAckedByRmt=5, descIdHash=1344296970, unackedMsgs=[
> GridDhtPartitionsSingleMessage, IgniteDiagnosticMessage], msgsRcvd=8,
> lastAcked=6, descIdHash=1344296970, bytesRcvd=14350, bytesRcvd0=9227,
> bytesSent=12300, bytesSent0=853, opQueueSize=0]
>
> Similar repetition as on the other nodes.
>
>
>
>
> Roger
>
> -----Original Message-----
> From: dkarachentsev [mailto:dkarachentsev@gridgain.com]
> Sent: Tuesday, August 15, 2017 2:05 AM
> To: user@ignite.apache.org
> Subject: RE: Activation: slow and: Ignite node crashed in the middle of
> checkpoint.
>
> Hi Roger,
>
> The recovery message in logs is normal case when node was forced to stop.
> This only means that data are restoring from WAL on start.
>
> Slow activation doesn't look OK, it shouldn't take so long. Could you
> please restart grid with -DIGNITE_QUIET=false JVM flag and share logs?
>
> Thanks!
> -Dmitry.
>
>
>
> --
> View this message in context: https://urldefense.proofpoint.
> com/v2/url?u=http-3A__apache-2Dignite-2Dusers.70518.x6.
> nabble.com_Activation-2Dslow-2Dand-2DIgnite-2Dnode-
> 2Dcrashed-2Din-2Dthe-2Dmiddle-2Dof-2Dcheckpoint-
> 2Dtp16144p16197.html&d=DwICAg&c=IL_XqQWOjubgfqINi2jTzg&r=
> 1esZO0r0bYS90lcsaLA6N4AFxuNo6lzauhETGwdJQoQ&m=JnQpalzeJE6hfAmoGt1Tq-
> Zwzjfs9siZ3AYjV5hHHy4&s=ub_f0AESPKsYlIHTcAoQVTKPwMZzvov4U6MNrYQVBmg&e=
> Sent from the Apache Ignite Users mailing list archive at Nabble.com.
>
>

Mime
View raw message