You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@ignite.apache.org by jaipal <da...@gmail.com> on 2017/04/18 12:10:21 UTC

Re: Failed to wait for initial partition map exchange

We are facing the similar issue with 1.9 version..Is there any recommended
configuration parametres to overccome this issue



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p12028.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by ndipiazza3565 <ni...@lucidworks.com>.
No. Persistence is disabled in my case. 



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

Re: Failed to wait for initial partition map exchange

Posted by eugene miretsky <eu...@gmail.com>.
Do you have persistence enabled?

On Wed, Sep 12, 2018 at 6:31 PM ndipiazza3565 <
nicholas.dipiazza@lucidworks.com> wrote:

> I'm trying to build up a list of possible causes for this issue.
>
> I'm only really interested in the issues that occur after successful
> production deployments. Meaning the environment has been up for some time
> successfully, but then later on our ignite nodes will not start and stick
>
> But as of now, a certain bad behavior from a single node in the ignite
> cluster can cause a deadlock
>
> * Anything that causes one of the ignite nodes to become unresponsive
>   * oom
>   * high gc
>   * high cpu
>   * high disk usage
> * Network issues?
>
> I'm trying to get a list of the causes for this issue so I can troubleshoot
> further.
>
>
>
> --
> Sent from: http://apache-ignite-users.70518.x6.nabble.com/
>

Re: Failed to wait for initial partition map exchange

Posted by Ilya Kasnacheev <il...@gmail.com>.
Hello!

Regarding PME problems.
OOM will cause this. High GC could cause this under some circumstances.
High CPU or Disk usage should not cause this. Network inavailability (such
as closed communication port) could also cause it.

But the prime cause is programming errors. Either those are errors on
Apache Ignite side (caused by some strange circumstances since all normal
cases should be normally tested), or they are in your code.

Such as deadlocks. If you have deadlocks in your code exposed to Apache
Ignite, or you are manage to lock up Apache Ignite in other ways
(listeners, invokes and continuous queries are notorious for that, since
there are limitations on operations you can use from within them), you can
catch infinite PME very easily.

However, it's hard to say without reviewing logs and thread dumps./

Regards,
-- 
Ilya Kasnacheev


чт, 13 сент. 2018 г. в 1:31, ndipiazza3565 <nicholas.dipiazza@lucidworks.com
>:

> I'm trying to build up a list of possible causes for this issue.
>
> I'm only really interested in the issues that occur after successful
> production deployments. Meaning the environment has been up for some time
> successfully, but then later on our ignite nodes will not start and stick
>
> But as of now, a certain bad behavior from a single node in the ignite
> cluster can cause a deadlock
>
> * Anything that causes one of the ignite nodes to become unresponsive
>   * oom
>   * high gc
>   * high cpu
>   * high disk usage
> * Network issues?
>
> I'm trying to get a list of the causes for this issue so I can troubleshoot
> further.
>
>
>
> --
> Sent from: http://apache-ignite-users.70518.x6.nabble.com/
>

Re: Failed to wait for initial partition map exchange

Posted by ndipiazza3565 <ni...@lucidworks.com>.
I'm trying to build up a list of possible causes for this issue.

I'm only really interested in the issues that occur after successful
production deployments. Meaning the environment has been up for some time
successfully, but then later on our ignite nodes will not start and stick 

But as of now, a certain bad behavior from a single node in the ignite
cluster can cause a deadlock 

* Anything that causes one of the ignite nodes to become unresponsive 
  * oom
  * high gc
  * high cpu
  * high disk usage
* Network issues?

I'm trying to get a list of the causes for this issue so I can troubleshoot
further. 



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

Re: Failed to wait for initial partition map exchange

Posted by vkulichenko <va...@gmail.com>.
This looks like a network issue. Please check that connections can be
established between any nodes in topology and nothing is blocked by
firewall. Note that connectivity must be bidirectional, even for clients
(i.e. server node can establish TCP connection with client node). Also note
that both discovery and communication are required to work and they use
different ports (47500 and 47100 by default).

-Val



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p14283.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by Vladimir <vl...@yandex.ru>.
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[OS: Linux
4.1.12-61.1.18.el7uek.x86_64 amd64]]
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[PID: 7608]]
[20:36:22] VM information: Java(TM) SE Runtime Environment 1.8.0_102-b14
Oracle Corporation Java HotSpot(TM) 64-Bit Server VM 25.102-b14
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[Language runtime: Java
Platform API Specification ver. 1.8]]
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[VM information: Java(TM) SE
Runtime Environment 1.8.0_102-b14 Oracle Corporation Java HotSpot(TM) 64-Bit
Server VM 25.102-b14]]
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[VM total memory: 2.1GB]]
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[Remote Management [restart:
off, REST: on, JMX (remote: off)]]]
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[System cache's MemoryPolicy
size is configured to 40 MB. Use MemoryConfiguration.systemCacheMemorySize
property to change the setting.]]
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[Configured caches [in
'default' memoryPolicy: ['ignite-sys-cache', 'ignite-atomics-sys-cache']]]]
INFO  2017-06-13 20:36:22 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[Local node user attribute
[IgSupport_LogicClusterGroups=com.bpcbt.common.support.ignite.beans.IgLogicClusterGroups@0]]]
WARN  2017-06-13 20:36:22 [pub-#14%svip%]
org.apache.ignite.internal.GridDiagnostic - [[Initial heap size is 154MB
(should be no less than 512MB, use -Xms512m -Xmx512m).]]
[20:36:22] Initial heap size is 154MB (should be no less than 512MB, use
-Xms512m -Xmx512m).
[20:36:23] Configured plugins:
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor -
[[Configured plugins:]]
[20:36:23]   ^-- None
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor - [[  ^--
None]]
[20:36:23] 
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.processors.plugin.IgnitePluginProcessor - [[]]
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[Successfully
bound communication NIO server to TCP port [port=9343, locHost=/127.0.0.1,
selectorsCnt=4, selectorSpins=0, pairedConn=false]]]
WARN  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[Message
queue limit is set to 0 which may lead to potential OOMEs when running cache
operations in FULL_ASYNC or PRIMARY_SYNC modes due to message queues growth
on sender and receiver sides.]]
[20:36:23] Message queue limit is set to 0 which may lead to potential OOMEs
when running cache operations in FULL_ASYNC or PRIMARY_SYNC modes due to
message queues growth on sender and receiver sides.
WARN  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.spi.checkpoint.noop.NoopCheckpointSpi - [[Checkpoints are
disabled (to enable configure any GridCheckpointSpi implementation)]]
WARN  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.managers.collision.GridCollisionManager -
[[Collision resolution is disabled (all jobs will be activated upon
arrival).]]
[20:36:23] Security status [authentication=off, tls/ssl=off]
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[Security status
[authentication=off, tls/ssl=off]]]
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.processors.rest.protocols.tcp.GridTcpRestProtocol
- [[Command protocol successfully started [name=TCP binary,
host=0.0.0.0/0.0.0.0, port=11214]]]
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[Non-loopback local IPs:
192.168.122.1, 192.168.209.65]]
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.internal.IgniteKernal%svip - [[Enabled local MACs:
0021F6321229, 5254000A6937]]
INFO  2017-06-13 20:36:23 [localhost-startStop-1]
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi - [[Successfully bound
to TCP port [port=9463, localHost=/127.0.0.1,
locNodeId=7fc5ea30-913d-4ff5-932b-62d81c6027db]]]
INFO  2017-06-13 20:36:24 [localhost-startStop-1]
org.apache.ignite.internal.processors.cache.GridCacheProcessor - [[Started
cache [name=ignite-sys-cache, memoryPolicyName=sysMemPlc, mode=REPLICATED]]]
INFO  2017-06-13 20:36:24 [localhost-startStop-1]
org.apache.ignite.internal.processors.cache.GridCacheProcessor - [[Started
cache [name=ignite-atomics-sys-cache, memoryPolicyName=sysMemPlc,
mode=REPLICATED]]]
INFO  2017-06-13 20:36:24 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[Established
outgoing communication connection [locAddr=/127.0.0.1:47331,
rmtAddr=/127.0.0.1:9340]]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353794662, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353794662, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353794662, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353794662, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=0,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1305, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1305, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353784631,
lastSndTime=1497353784897, lastRcvTime=1497353787145, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:36:34 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:36:34 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:34 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:34 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:34 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1305, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=0, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1305, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:36:44 [localhost-startStop-1]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for initial partition map exchange. Possible reasons are: 
  ^-- Transactions in deadlock.
  ^-- Long running transactions (ignore if this is the case).
  ^-- Unreleased explicit locks.]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353804668, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353804668, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353804668, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353804668, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=0,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1305, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=0, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1305, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353784631,
lastSndTime=1497353784897, lastRcvTime=1497353787145, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:36:44 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:36:44 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1305, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=0, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1305, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:36:44 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:44 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:44 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353814702, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353814702, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353814702, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353814702, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=2,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1315, bytesRcvd0=0, bytesSent0=10, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1315, bytesRcvd=45363,
bytesSent0=10, bytesRcvd0=0, sndSchedTime=1497353784631,
lastSndTime=1497353813114, lastRcvTime=1497353787145, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:36:54 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:36:54 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1315, bytesSent0=10]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=2, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1315, bytesSent0=10, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:36:54 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:54 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:36:54 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:04 [localhost-startStop-1]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Still waiting for initial partition map exchange
[fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353824361, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353824361, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353824726, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353824726, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353824726, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353824726, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=2,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1315, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1315, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353818946,
lastSndTime=1497353813114, lastRcvTime=1497353818946, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:37:04 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:37:04 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1315, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=2, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1315, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:37:04 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:04 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:04 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353834746, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353834746, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353834746, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353834746, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=2,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1315, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1315, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353818946,
lastSndTime=1497353813114, lastRcvTime=1497353818946, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:37:14 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:37:14 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1315, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=2, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1315, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:37:14 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:14 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:14 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:24 [localhost-startStop-1]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Still waiting for initial partition map exchange
[fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353844387, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353844387, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353844791, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353844791, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353844791, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353844791, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=2,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1315, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1315, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353818946,
lastSndTime=1497353813114, lastRcvTime=1497353818946, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:37:24 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:37:24 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1315, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=2, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1315, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:37:24 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:24 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:24 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
INFO  2017-06-13 20:37:34 [ignite-update-notifier-timer]
org.apache.ignite.internal.processors.cluster.GridUpdateNotifier - [[Update
status is not available.]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353854788, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353854788, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353854788, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353854788, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=2,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1315, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1315, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353848962,
lastSndTime=1497353813114, lastRcvTime=1497353848962, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:37:34 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:37:34 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1315, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=2, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1315, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:37:34 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:34 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:34 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:44 [localhost-startStop-1]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Still waiting for initial partition map exchange
[fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353864442, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353864442, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353864796, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353864796, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353864796, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353864796, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=2,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1315, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1315, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353848962,
lastSndTime=1497353813114, lastRcvTime=1497353848962, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:37:44 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:37:44 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1315, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=2, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1315, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:37:44 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:44 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:44 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Failed to wait for partition map exchange
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0],
node=7fc5ea30-913d-4ff5-932b-62d81c6027db]. Dumping pending objects that
might be the cause: ]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Ready affinity version: AffinityTopologyVersion [topVer=-1,
minorTopVer=0]]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
forcePreload=false, reassign=false, discoEvt=DiscoveryEvent
[evtNode=TcpDiscoveryNode [id=7fc5ea30-913d-4ff5-932b-62d81c6027db,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62,
intOrder=33, lastExchangeTime=1497353874839, loc=true,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], topVer=62,
nodeId8=7fc5ea30, msg=null, type=NODE_JOINED, tstamp=1497353784308],
crd=TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false],
exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
[topVer=62, minorTopVer=0], nodeId=7fc5ea30, evt=NODE_JOINED], added=false,
initFut=GridFutureAdapter [ignoreInterrupts=false, state=DONE, res=true,
hash=1130708319], init=true, lastVer=null, partReleaseFut=GridCompoundFuture
[rdc=null, initFlag=1, lsnrCalls=4, done=true, cancelled=false, err=null,
futs=[true, true, true, true]], affChangeMsg=null, skipPreload=false,
clientOnlyExchange=false, initTs=1497353784601, centralizedAff=false,
changeGlobalStateE=null, exchangeOnChangeGlobalState=false,
forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353874839, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending exchange futures:]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Last 10 exchange futures (total: 1):]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[>>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353874839, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=62, nodeId8=7fc5ea30, msg=null, type=NODE_JOINED,
tstamp=1497353784308], crd=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=62, minorTopVer=0], nodeId=7fc5ea30,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1130708319], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1497353784601, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[a7a74608-3b2d-440f-910d-3ef3537d907f,
a4a43486-2322-475c-9b25-aef7907500dc, f03fe6d2-8858-4b32-9ac2-260d1a79693a],
srvNodes=[TcpDiscoveryNode [id=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=a4a43486-2322-475c-9b25-aef7907500dc, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=2, intOrder=2,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=a7a74608-3b2d-440f-910d-3ef3537d907f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=60,
intOrder=32, lastExchangeTime=1497353784020, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=7fc5ea30-913d-4ff5-932b-62d81c6027db, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=62, intOrder=33,
lastExchangeTime=1497353874839, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=277178513]]]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transactions:]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending explicit locks:]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending cache futures:]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending atomic cache futures:]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending data streamer futures:]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager
- [[Pending transaction deadlock detection futures:]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi -
[[Communication SPI recovery descriptors: 
    [key=ConnectionKey [nodeId=f03fe6d2-8858-4b32-9ac2-260d1a79693a, idx=0,
connCnt=-1], msgsSent=3, msgsAckedByRmt=3, msgsRcvd=2, lastAcked=2,
reserveCnt=1, descIdHash=2015302722]
Communication SPI clients: 
    [node=f03fe6d2-8858-4b32-9ac2-260d1a79693a,
client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
[worker=DirectNioClientWorker [super=AbstractNioClientWorker
[selector=sun.nio.ch.EPollSelectorImpl@3e96a835, idx=0, bytesRcvd=45363,
bytesSent=1315, bytesRcvd0=0, bytesSent0=0, select=true, super=GridWorker
[name=grid-nio-worker-tcp-comm-0, igniteInstanceName=svip, finished=false,
hashCode=518525437, interrupted=false,
runner=grid-nio-worker-tcp-comm-0-#17%svip%]]],
writeBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
readBuf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
inRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false],
outRecovery=GridNioRecoveryDescriptor [acked=3, resendCnt=0, rcvCnt=2,
sentCnt=3, reserved=true, lastAck=2, nodeLeft=false, node=TcpDiscoveryNode
[id=f03fe6d2-8858-4b32-9ac2-260d1a79693a, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1497353784020, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], connected=true, connectCnt=1, queueLimit=4096,
reserveCnt=1, pairedConnections=false], super=GridNioSessionImpl
[locAddr=/127.0.0.1:47331, rmtAddr=/127.0.0.1:9340,
createTime=1497353784631, closeTime=0, bytesSent=1315, bytesRcvd=45363,
bytesSent0=0, bytesRcvd0=0, sndSchedTime=1497353848962,
lastSndTime=1497353813114, lastRcvTime=1497353848962, readsPaused=false,
filterChain=FilterChain[filters=[GridNioCodecFilter
[parser=o.a.i.i.util.nio.GridDirectParser@5e7030df, directMode=true],
GridConnectionBytesVerifyFilter], accepted=false]],
super=GridAbstractCommunicationClient [lastUsed=1497353784642, closed=false,
connIdx=0]]]
]]
WARN  2017-06-13 20:37:54 [exchange-worker-#29%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[NIO server
statistics [readerSesBalanceCnt=0, writerSesBalanceCnt=0]]]
WARN  2017-06-13 20:37:54 [grid-nio-worker-tcp-comm-0-#17%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=0, keysCnt=1, bytesRcvd=45363, bytesRcvd0=0,
>> bytesSent=1315, bytesSent0=0]
    Connection info [in=false, rmtAddr=/127.0.0.1:9340,
locAddr=/127.0.0.1:47331, msgsSent=3, msgsAckedByRmt=3,
descIdHash=2015302722, msgsRcvd=2, lastAcked=2, descIdHash=2015302722,
bytesRcvd=45363, bytesRcvd0=0, bytesSent=1315, bytesSent0=0, opQueueSize=0,
msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
stack=[StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013860000, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0, hdrWritten=false],
null, null, null, null, null, null]]], msgReader=DirectMessageReader
[state=DirectMessageState [pos=0, stack=[StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0],
StateItem [stream=DirectByteBufferStreamImplV2
[buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
baseOff=139765013892784, arrOff=-1, tmpArrOff=0, tmpArrBytes=0,
msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1, keyDone=false,
readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0, uuidMost=0,
uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], StateItem
[stream=DirectByteBufferStreamImplV2 [buf=java.nio.DirectByteBuffer[pos=0
lim=32768 cap=32768], baseOff=139765013892784, arrOff=-1, tmpArrOff=0,
tmpArrBytes=0, msgTypeDone=false, msg=null, mapIt=null, it=null, arrPos=-1,
keyDone=false, readSize=-1, readItems=0, prim=0, primShift=0, uuidState=0,
uuidMost=0, uuidLeast=0, uuidLocId=0, lastFinished=true], state=0], null,
null, null, null, null, null, null]], lastRead=true]]
]]
WARN  2017-06-13 20:37:54 [grid-nio-worker-tcp-comm-1-#18%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=1, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:54 [grid-nio-worker-tcp-comm-2-#19%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=2, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]
WARN  2017-06-13 20:37:54 [grid-nio-worker-tcp-comm-3-#20%svip%]
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi - [[
>> Selector info [idx=3, keysCnt=0, bytesRcvd=0, bytesRcvd0=0, bytesSent=0,
>> bytesSent0=0]
]]



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p13645.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.


Re: Failed to wait for initial partition map exchange

Posted by vkulichenko <va...@gmail.com>.
Please attach full logs.

-Val



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p13487.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by Vladimir <vl...@yandex.ru>.
Unfortunately, it’s not a warning. New node cannot join the cluster. And
there is no heavy load on the cluster, no CPU/memory consumption. No any
network problem because I tested all the nodes on single machine.



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p13458.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by vkulichenko <va...@gmail.com>.
Vladimir,

As I told before, this message is very generic and can be caused by multiple
reasons (sometimes it's not even an issue BTW - it's warning, not an error).
First things to check is memory consumption, GC and network.

-Val



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p13439.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by Vladimir <vl...@yandex.ru>.
I have met similar problem too. A node cannot start:

WARN  16:08:36.158 [main]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager:
Still waiting for initial partition map exchange
[fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
[id=fa2d0f11-80cf-4891-9533-7a36392157f6, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=8, intOrder=6,
lastExchangeTime=1496754516085, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], topVer=8, nodeId8=fa2d0f11, msg=null, type=NODE_JOINED,
tstamp=1496754274106], crd=TcpDiscoveryNode
[id=7751c8dc-9bf6-4a21-9ea5-376f2be83913, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1, intOrder=1,
lastExchangeTime=1496754273954, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], exchId=GridDhtPartitionExchangeId
[topVer=AffinityTopologyVersion [topVer=8, minorTopVer=0], nodeId=fa2d0f11,
evt=NODE_JOINED], added=false, initFut=GridFutureAdapter
[ignoreInterrupts=false, state=DONE, res=true, hash=1259192920], init=true,
lastVer=null, partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
lsnrCalls=4, done=true, cancelled=false, err=null, futs=[true, true, true,
true]], affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
initTs=1496754276137, centralizedAff=false, changeGlobalStateE=null,
exchangeOnChangeGlobalState=false, forcedRebFut=null, evtLatch=0,
remaining=[bf7a4e48-4867-437b-9cc5-dd598b8795f3,
7751c8dc-9bf6-4a21-9ea5-376f2be83913, 373fd690-4171-4503-ab1b-d622c3ec6fc7],
srvNodes=[TcpDiscoveryNode [id=7751c8dc-9bf6-4a21-9ea5-376f2be83913,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9460], discPort=9460, order=1,
intOrder=1, lastExchangeTime=1496754273954, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=bf7a4e48-4867-437b-9cc5-dd598b8795f3, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9461], discPort=9461, order=6, intOrder=4,
lastExchangeTime=1496754273954, loc=false, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false], TcpDiscoveryNode [id=373fd690-4171-4503-ab1b-d622c3ec6fc7,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:9462], discPort=9462, order=7,
intOrder=5, lastExchangeTime=1496754273954, loc=false,
ver=2.0.0#20170430-sha1:d4eef3c6, isClient=false], TcpDiscoveryNode
[id=fa2d0f11-80cf-4891-9533-7a36392157f6, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:9463], discPort=9463, order=8, intOrder=6,
lastExchangeTime=1496754516085, loc=true, ver=2.0.0#20170430-sha1:d4eef3c6,
isClient=false]], super=GridFutureAdapter [ignoreInterrupts=false,
state=INIT, res=null, hash=1079801970]]]
WARN  16:08:36.499 [exchange-worker-#37%svip%]
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager:
Failed to wait for partition map exchange [topVer=AffinityTopologyVersion
[topVer=8, minorTopVer=0], node=fa2d0f11-80cf-4891-9533-7a36392157f6].
Dumping pending objects that might be the cause: 

What can it be?



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p13414.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by vkulichenko <va...@gmail.com>.
Generally, you can't add new node while holding a lock. If you're holding
locks for long period of time, I would recommend you to revisit the
architecture. In any case, make sure that you properly release all the
locks. Also I think you should to upgrade to the latest version, I believe
there were some fixes in this area.

-Val



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p12960.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by jaipal <da...@gmail.com>.
Val,

It doesn't look like a memory issue.We are using explicit locking (lock
entry , do processing and then unlock).Under high load, When we bring down
one of the Ignite Server nodes and then again add it back to the cluster,We
are getting this issue.We observed the exceptions like Failed to wait for
partition map exchange.sometimes it also gives Failed to wait for partition
release future and then dumps the pending cache futures,exchange futures and
transactions.Once we encounter this issue,Cluster hangs with out processing.
We need to clean start all Ignite Nodes to resolve this.We are observing
this issue quite often and it is preventing us from scaling up and down.
Please find the attached file that contains the  ignite configuration we
used.Is something wrong with cache configuration or with way we are using
locking or with  Ignite ?

ignite.xml
<http://apache-ignite-users.70518.x6.nabble.com/file/n12957/ignite.xml>  



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p12957.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by vkulichenko <va...@gmail.com>.
Jai,

So what is the result of investigation? Does it look like memory issue or
not? As I said earlier, the issue itself doesn't have generic solution, you
need to find out the reason.

-Val



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p12890.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by jaipal <da...@gmail.com>.
Hii val,

I tried recommended settings and configurations. still I observe this issue
and it can be reproduced easily.

Is there any fix available to this issue.

Regards
Jai



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Failed-to-wait-for-initial-partition-map-exchange-tp6252p12885.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.

Re: Failed to wait for initial partition map exchange

Posted by Valentin Kulichenko <va...@gmail.com>.
Usually it's caused by GC or network issues. First, I would recommend to
check if you're not running out of memory, and then collect and investigate
GC logs:
https://apacheignite.readme.io/docs/jvm-and-system-tuning#debugging-memory-usage-issues-and-gc-pauses

-Val

On Tue, Apr 18, 2017 at 2:10 PM, jaipal <da...@gmail.com> wrote:

> We are facing the similar issue with 1.9 version..Is there any recommended
> configuration parametres to overccome this issue
>
>
>
> --
> View this message in context: http://apache-ignite-users.
> 70518.x6.nabble.com/Failed-to-wait-for-initial-partition-
> map-exchange-tp6252p12028.html
> Sent from the Apache Ignite Users mailing list archive at Nabble.com.
>