ignite-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Andrey Mashenkov <andrey.mashen...@gmail.com>
Subject Re: error - Failed to wait for partition release future
Date Fri, 17 Feb 2017 04:58:21 GMT
Hi Cameron,

It looks like nodes cant see each other.
Would you please attach grid configuration and full logs?


BTW, ignite version on nodes still "ver=1.8.1#20161208-sha1:a8fcb7b2"

On Fri, Feb 17, 2017 at 2:15 AM, Cameron Braid <cameron@braid.com.au> wrote:

> Ok,  I have moved to using apache ignite 1.8.0 jar and the same issue is
> there.
>
> I don't believe that  it is slow networking that is causing this as it does
> also happen on a single host single node cluster - its hard to reproduce
> but it does happen.
>
> I've included a log from the grid locking up  on a single node grid.
>
> Any ideas on what I can do to stop the cluster from locking up ?
>
> Feb 17 09:09:22 webapp-97-3v11l webapp  85614 WARN
> o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture
> [exchange-worker-#26%webapp%] Failed to wait for partition release future
> [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=6],
> node=68845172-67fb-4f49-ae81-f3024ef89e66]. Dumping pending objects that
> might be the cause:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85614 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Ready affinity version: AffinityTopologyVersion [topVer=1, minorTopVer=5]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85619 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Last exchange future: GridDhtPartitionsExchangeFuture [dummy=false,
> forcePreload=false, reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeBatch [reqs=[DynamicCacheChangeRequest
> [deploymentId=d7f09f84a51-923f7cb7-d9c2-46e8-b121-c7fe21e14aa2,
> startCfg=CacheConfiguration [name=query.starRatings.aggregate,
> storeConcurrentLoadAllThreshold=5, rebalancePoolSize=2,
> rebalanceTimeout=10000, evictPlc=LruEvictionPolicy [max=500, batchSize=1,
> maxMemSize=0, memSize=0, size=0], evictSync=false, evictKeyBufSize=1024,
> evictSyncConcurrencyLvl=4, evictSyncTimeout=10000, evictFilter=null,
> evictMaxOverflowRatio=10.0, eagerTtl=true, dfltLockTimeout=0,
> startSize=1500000, nearCfg=null, writeSync=PRIMARY_SYNC, storeFactory=null,
> storeKeepBinary=false, loadPrevVal=false,
> aff=o.a.i.cache.affinity.rendezvous.RendezvousAffinityFunction@3cfe01ec,
> cacheMode=REPLICATED, atomicityMode=ATOMIC, atomicWriteOrderMode=PRIMARY,
> backups=2147483647, invalidate=false, tmLookupClsName=null,
> rebalanceMode=ASYNC, rebalanceOrder=0, rebalanceBatchSize=524288,
> rebalanceBatchesPrefetchCount=2, offHeapMaxMem=-1, swapEnabled=false,
> maxConcurrentAsyncOps=500, writeBehindEnabled=false,
> writeBehindFlushSize=10240, writeBehindFlushFreq=5000,
> writeBehindFlushThreadCnt=1, writeBehindBatchSize=512, maxQryIterCnt=1024,
> memMode=ONHEAP_TIERED,
> affMapper=o.a.i.i.processors.cache.CacheDefaultBinaryAffinityKeyM
> apper@387ac79,
> rebalanceDelay=0, rebalanceThrottle=0, interceptor=null,
> longQryWarnTimeout=3000, qryDetailMetricsSz=0, readFromBackup=true,
> nodeFilter=o.a.i.configuration.CacheConfiguration$IgniteAllNodesPredicate@
> 2a423797,
> sqlSchema=null, sqlEscapeAll=false, sqlOnheapRowCacheSize=10240,
> snapshotableIdx=false, cpOnRead=true, topValidator=null], cacheType=USER,
> initiatingNodeId=68845172-67fb-4f49-ae81-f3024ef89e66, nearCacheCfg=null,
> clientStartOnly=false, stop=false, close=false, failIfExists=true,
> template=false, rcvdFrom=null, exchangeNeeded=true, cacheFutTopVer=null,
> cacheName=query.starRatings.aggregate]], clientNodes=null,
> id=e7f09f84a51-923f7cb7-d9c2-46e8-b121-c7fe21e14aa2,
> clientReconnect=false], affTopVer=AffinityTopologyVersion [topVer=1,
> minorTopVer=6], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1487282952548]], crd=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> [topVer=1, minorTopVer=6], nodeId=68845172, evt=DISCOVERY_CUSTOM_EVT],
> added=true, initFut=GridFutureAdapter [resFlag=0, res=null,
> startTime=1487282952548, endTime=0, ignoreInterrupts=false, state=INIT],
> init=false, topSnapshot=null, lastVer=null,
> partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=3,
> done=false, cancelled=false, err=null, futs=[true, true, true, false]],
> affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
> initTs=1487282952548, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[TcpDiscoveryNode [id=68845172-67fb-4f49-ae81-f3024ef89e66,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.129.1.132, 127.0.0.1],
> sockAddrs=[webapp-97-3v11l/10.129.1.132:47500, /0:0:0:0:0:0:0:1%lo:47500,
> /
> 127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
> lastExchangeTime=1487282891381, loc=true, ver=1.8.1#20161208-sha1:
> a8fcb7b2,
> isClient=false]], super=GridFutureAdapter [resFlag=0, res=null,
> startTime=1487282952548, endTime=0, ignoreInterrupts=false, state=INIT]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85619 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Pending exchange futures:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85619 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Last 10 exchange futures (total: 7):
> Feb 17 09:09:22 webapp-97-3v11l webapp  85620 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryCustomEvent
> [customMsg=DynamicCacheChangeBatch [reqs=[DynamicCacheChangeRequest
> [deploymentId=d7f09f84a51-923f7cb7-d9c2-46e8-b121-c7fe21e14aa2,
> startCfg=CacheConfiguration [name=query.starRatings.aggregate,
> storeConcurrentLoadAllThreshold=5, rebalancePoolSize=2,
> rebalanceTimeout=10000, evictPlc=LruEvictionPolicy [max=500, batchSize=1,
> maxMemSize=0, memSize=0, size=0], evictSync=false, evictKeyBufSize=1024,
> evictSyncConcurrencyLvl=4, evictSyncTimeout=10000, evictFilter=null,
> evictMaxOverflowRatio=10.0, eagerTtl=true, dfltLockTimeout=0,
> startSize=1500000, nearCfg=null, writeSync=PRIMARY_SYNC, storeFactory=null,
> storeKeepBinary=false, loadPrevVal=false,
> aff=o.a.i.cache.affinity.rendezvous.RendezvousAffinityFunction@3cfe01ec,
> cacheMode=REPLICATED, atomicityMode=ATOMIC, atomicWriteOrderMode=PRIMARY,
> backups=2147483647, invalidate=false, tmLookupClsName=null,
> rebalanceMode=ASYNC, rebalanceOrder=0, rebalanceBatchSize=524288,
> rebalanceBatchesPrefetchCount=2, offHeapMaxMem=-1, swapEnabled=false,
> maxConcurrentAsyncOps=500, writeBehindEnabled=false,
> writeBehindFlushSize=10240, writeBehindFlushFreq=5000,
> writeBehindFlushThreadCnt=1, writeBehindBatchSize=512, maxQryIterCnt=1024,
> memMode=ONHEAP_TIERED,
> affMapper=o.a.i.i.processors.cache.CacheDefaultBinaryAffinityKeyM
> apper@387ac79,
> rebalanceDelay=0, rebalanceThrottle=0, interceptor=null,
> longQryWarnTimeout=3000, qryDetailMetricsSz=0, readFromBackup=true,
> nodeFilter=o.a.i.configuration.CacheConfiguration$IgniteAllNodesPredicate@
> 2a423797,
> sqlSchema=null, sqlEscapeAll=false, sqlOnheapRowCacheSize=10240,
> snapshotableIdx=false, cpOnRead=true, topValidator=null], cacheType=USER,
> initiatingNodeId=68845172-67fb-4f49-ae81-f3024ef89e66, nearCacheCfg=null,
> clientStartOnly=false, stop=false, close=false, failIfExists=true,
> template=false, rcvdFrom=null, exchangeNeeded=true, cacheFutTopVer=null,
> cacheName=query.starRatings.aggregate]], clientNodes=null,
> id=e7f09f84a51-923f7cb7-d9c2-46e8-b121-c7fe21e14aa2,
> clientReconnect=false], affTopVer=AffinityTopologyVersion [topVer=1,
> minorTopVer=6], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1487282952548]], crd=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> [topVer=1, minorTopVer=6], nodeId=68845172, evt=DISCOVERY_CUSTOM_EVT],
> added=true, initFut=GridFutureAdapter [resFlag=0, res=null,
> startTime=1487282952548, endTime=0, ignoreInterrupts=false, state=INIT],
> init=false, topSnapshot=null, lastVer=null,
> partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1, lsnrCalls=3,
> done=false, cancelled=false, err=null, futs=[true, true, true, false]],
> affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
> initTs=1487282952548, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[TcpDiscoveryNode [id=68845172-67fb-4f49-ae81-f3024ef89e66,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.129.1.132, 127.0.0.1],
> sockAddrs=[webapp-97-3v11l/10.129.1.132:47500, /0:0:0:0:0:0:0:1%lo:47500,
> /
> 127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
> lastExchangeTime=1487282891381, loc=true, ver=1.8.1#20161208-sha1:
> a8fcb7b2,
> isClient=false]], super=GridFutureAdapter [resFlag=0, res=null,
> startTime=1487282952548, endTime=0, ignoreInterrupts=false, state=INIT]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85621 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryCustomEvent [customMsg=null,
> affTopVer=AffinityTopologyVersion [topVer=1, minorTopVer=5],
> super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1487282919123]], crd=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> [topVer=1, minorTopVer=5], nodeId=68845172, evt=DISCOVERY_CUSTOM_EVT],
> added=true, initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487282919123, endTime=1487282919153, ignoreInterrupts=false,
> state=DONE], init=false, topSnapshot=null, lastVer=GridCacheVersion
> [topVer=98762892, time=1487282908333, order=1487282890865, nodeOrder=1],
> 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=1487282919133, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[], super=GridFutureAdapter [resFlag=2,
> res=AffinityTopologyVersion [topVer=1, minorTopVer=5],
> startTime=1487282919123, endTime=1487282919153, ignoreInterrupts=false,
> state=DONE]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85633 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryCustomEvent [customMsg=null,
> affTopVer=AffinityTopologyVersion [topVer=1, minorTopVer=4],
> super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1487282919062]], crd=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> [topVer=1, minorTopVer=4], nodeId=68845172, evt=DISCOVERY_CUSTOM_EVT],
> added=true, initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487282919062, endTime=1487282919113, ignoreInterrupts=false,
> state=DONE], init=false, topSnapshot=null, lastVer=GridCacheVersion
> [topVer=98762892, time=1487282908333, order=1487282890865, nodeOrder=1],
> 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=1487282919072, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[], super=GridFutureAdapter [resFlag=2,
> res=AffinityTopologyVersion [topVer=1, minorTopVer=4],
> startTime=1487282919062, endTime=1487282919113, ignoreInterrupts=false,
> state=DONE]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85634 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryCustomEvent [customMsg=null,
> affTopVer=AffinityTopologyVersion [topVer=1, minorTopVer=3],
> super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1487282919012]], crd=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> [topVer=1, minorTopVer=3], nodeId=68845172, evt=DISCOVERY_CUSTOM_EVT],
> added=true, initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487282919012, endTime=1487282919062, ignoreInterrupts=false,
> state=DONE], init=false, topSnapshot=null, lastVer=GridCacheVersion
> [topVer=98762892, time=1487282908333, order=1487282890865, nodeOrder=1],
> 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=1487282919012, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[], super=GridFutureAdapter [resFlag=2,
> res=AffinityTopologyVersion [topVer=1, minorTopVer=3],
> startTime=1487282919012, endTime=1487282919062, ignoreInterrupts=false,
> state=DONE]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85635 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryCustomEvent [customMsg=null,
> affTopVer=AffinityTopologyVersion [topVer=1, minorTopVer=2],
> super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1487282901428]], crd=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> [topVer=1, minorTopVer=2], nodeId=68845172, evt=DISCOVERY_CUSTOM_EVT],
> added=true, initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487282901428, endTime=1487282901449, ignoreInterrupts=false,
> state=DONE], init=false, topSnapshot=null, lastVer=GridCacheVersion
> [topVer=98762892, time=1487282892579, order=1487282890857, nodeOrder=1],
> 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=1487282901428, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[], super=GridFutureAdapter [resFlag=2,
> res=AffinityTopologyVersion [topVer=1, minorTopVer=2],
> startTime=1487282901428, endTime=1487282901449, ignoreInterrupts=false,
> state=DONE]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85636 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryCustomEvent [customMsg=null,
> affTopVer=AffinityTopologyVersion [topVer=1, minorTopVer=1],
> super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1487282901358]], crd=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> [topVer=1, minorTopVer=1], nodeId=68845172, evt=DISCOVERY_CUSTOM_EVT],
> added=true, initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487282901358, endTime=1487282901388, ignoreInterrupts=false,
> state=DONE], init=false, topSnapshot=null, lastVer=GridCacheVersion
> [topVer=98762892, time=1487282892579, order=1487282890857, nodeOrder=1],
> 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=1487282901358, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[], super=GridFutureAdapter [resFlag=2,
> res=AffinityTopologyVersion [topVer=1, minorTopVer=1],
> startTime=1487282901358, endTime=1487282901388, ignoreInterrupts=false,
> state=DONE]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85636 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=68845172-67fb-4f49-ae81-f3024ef89e66, addrs=[0:0:0:0:0:0:0:1%lo,
> 10.129.1.132, 127.0.0.1], sockAddrs=[webapp-97-3v11l/10.129.1.132:47500,
> /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1487282891381, loc=true,
> ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=1,
> nodeId8=68845172, msg=null, type=NODE_JOINED, tstamp=1487282891575],
> crd=TcpDiscoveryNode [id=68845172-67fb-4f49-ae81-f3024ef89e66,
> addrs=[0:0:0:0:0:0:0:1%lo, 10.129.1.132, 127.0.0.1],
> sockAddrs=[webapp-97-3v11l/10.129.1.132:47500, /0:0:0:0:0:0:0:1%lo:47500,
> /
> 127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
> lastExchangeTime=1487282891381, loc=true, ver=1.8.1#20161208-sha1:
> a8fcb7b2,
> isClient=false], exchId=GridDhtPartitionExchangeId
> [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=0],
> nodeId=68845172,
> evt=NODE_JOINED], added=false, initFut=GridFutureAdapter [resFlag=2,
> res=true, startTime=1487282892253, endTime=1487282892347,
> ignoreInterrupts=false, state=DONE], init=false, topSnapshot=null,
> lastVer=GridCacheVersion [topVer=0, time=0, order=1487282890849,
> nodeOrder=0], 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=1487282892263, centralizedAff=false, evtLatch=0, remaining=[],
> srvNodes=[], super=GridFutureAdapter [resFlag=2,
> res=AffinityTopologyVersion [topVer=1, minorTopVer=0],
> startTime=1487282892253, endTime=1487282892347, ignoreInterrupts=false,
> state=DONE]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85637 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Pending transactions:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85637 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Pending explicit locks:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85637 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Pending cache futures:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85637 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Pending atomic cache futures:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85637 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Pending data streamer futures:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85637 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> >>> DataStreamerFuture [topVer=AffinityTopologyVersion [topVer=1,
> minorTopVer=5], super=GridFutureAdapter [resFlag=0, res=null,
> startTime=1487282949012, endTime=0, ignoreInterrupts=false, state=INIT]]
> Feb 17 09:09:22 webapp-97-3v11l webapp  85638 WARN
> o.a.i.i.p.c.GridCachePartitionExchangeManager
> [exchange-worker-#26%webapp%]
> Pending transaction deadlock detection futures:
> Feb 17 09:09:22 webapp-97-3v11l webapp  85639 WARN
> o.a.i.s.c.tcp.TcpCommunicationSpi [exchange-worker-#26%webapp%]
> Communication SPI recovery descriptors:
> Feb 17 09:09:22 webapp-97-3v11l webapp  Communication SPI clients:
> Feb 17 09:09:22 webapp-97-3v11l webapp
> Feb 17 09:09:22 webapp-97-3v11l webapp  85644 WARN
> o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-1-#11%webapp%]
> Feb 17 09:09:22 webapp-97-3v11l webapp  >> Selector info [idx=1, keysCnt=0]
> Feb 17 09:09:22 webapp-97-3v11l webapp
> Feb 17 09:09:22 webapp-97-3v11l webapp  85644 WARN
> o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-2-#12%webapp%]
> Feb 17 09:09:22 webapp-97-3v11l webapp  >> Selector info [idx=2, keysCnt=0]
> Feb 17 09:09:22 webapp-97-3v11l webapp
> Feb 17 09:09:22 webapp-97-3v11l webapp  85644 WARN
> o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-3-#13%webapp%]
> Feb 17 09:09:22 webapp-97-3v11l webapp  >> Selector info [idx=3, keysCnt=0]
> Feb 17 09:09:22 webapp-97-3v11l webapp
> Feb 17 09:09:22 webapp-97-3v11l webapp  85644 WARN
> o.a.i.s.c.tcp.TcpCommunicationSpi [grid-nio-worker-0-#10%webapp%]
> Feb 17 09:09:22 webapp-97-3v11l webapp  >> Selector info [idx=0, keysCnt=0]
> Feb 17 09:09:22 webapp-97-3v11l webapp
>
>
>
>
> On Fri, 17 Feb 2017 at 03:11 Andrey Mashenkov <andrey.mashenkov@gmail.com>
> wrote:
>
> > Hi Cameron,
> >
> > You wrote on Apache Ignite Community dev-list.  Iginte does not have
> > versions like 1.8.x.
> > Git repository you refer to is not belong to the Apache Ignite project.
> >
> >
> > On Thu, Feb 16, 2017 at 6:58 PM, Cameron Braid <cameron@braid.com.au>
> > wrote:
> >
> > > Hi,
> > >
> > > Thanks for looking at my issue.
> > >
> > > There are tags for 1.8.1, 1.8.2 and 1.8.3 at
> > > https://github.com/gridgain/apache-ignite  so I have been trying using
> > > jars
> > > built from those tags, including 1.9
> > >
> > > I'm still getting the issues. What concerns me the most is that it is
> > very
> > > easy to lockup the whole grid.  I have tried various short (2s) .. long
> > > (40s) FailureDetectionTimeout and I still get a lockup.  I've tried the
> > > prefer ip4 as you suggested but it didn't make any difference.  I've
> > > included my jvm args, an excerpt from the jvm gc logs, and some more
> > recent
> > > ignite logs.
> > >
> > > Cheers
> > >
> > > Cameron
> > >
> > > *[jvm args]*
> > >
> > > -Xms2G -Xmx2G
> > >
> > > -XX:+PrintGCDetails
> > > -XX:+PrintGCTimeStamps
> > > -XX:+PrintGCDateStamps
> > > -XX:+UseGCLogFileRotation
> > > -XX:NumberOfGCLogFiles=10
> > > -XX:GCLogFileSize=100M
> > > -Xloggc:target/gc-log-devA.txt
> > >
> > > -XX:+UseParNewGC  -XX:+UseConcMarkSweepGC  -XX:+UseTLAB
> > > -XX:NewSize=128m  -XX:MaxNewSize=128m
> > > -XX:MaxTenuringThreshold=0  -XX:SurvivorRatio=1024
> > > -XX:+UseCMSInitiatingOccupancyOnly
> > > -XX:CMSInitiatingOccupancyFraction=40 -XX:MaxGCPauseMillis=1000
> > > -XX:InitiatingHeapOccupancyPercent=50  -XX:+UseCompressedOops
> > > -XX:ParallelGCThreads=6  -XX:ConcGCThreads=6
> > >
> > > *[GC logs]*
> > >
> > > 2017-02-17T02:43:31.345+1100: 1997.387: [CMS-concurrent-reset:
> > 0.004/0.004
> > > secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:43:32.099+1100: 1998.141: [GC (Allocation Failure)
> > > 2017-02-17T02:43:32.100+1100: 1998.141: [ParNew: 130485K->0K(131008K),
> > > 0.0332423 secs] 773911K->655291K(2097088K), 0.0336493 secs] [Times:
> > > user=0.10 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:43:32.498+1100: 1998.539: [GC (Allocation Failure)
> > > 2017-02-17T02:43:32.498+1100: 1998.539: [ParNew: 130944K->0K(131008K),
> > > 0.0489761 secs] 786235K->683673K(2097088K), 0.0492079 secs] [Times:
> > > user=0.13 sys=0.01, real=0.05 secs]
> > > 2017-02-17T02:43:33.578+1100: 1999.620: [GC (Allocation Failure)
> > > 2017-02-17T02:43:33.578+1100: 1999.620: [ParNew: 130944K->0K(131008K),
> > > 0.0589320 secs] 814617K->710468K(2097088K), 0.0594862 secs] [Times:
> > > user=0.19 sys=0.01, real=0.06 secs]
> > > 2017-02-17T02:43:33.997+1100: 2000.038: [GC (Allocation Failure)
> > > 2017-02-17T02:43:33.997+1100: 2000.038: [ParNew: 130944K->0K(131008K),
> > > 0.0382098 secs] 841412K->723510K(2097088K), 0.0386616 secs] [Times:
> > > user=0.11 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:43:34.724+1100: 2000.765: [GC (Allocation Failure)
> > > 2017-02-17T02:43:34.724+1100: 2000.765: [ParNew: 130944K->0K(131008K),
> > > 0.0061646 secs] 854454K->725669K(2097088K), 0.0064497 secs] [Times:
> > > user=0.03 sys=0.01, real=0.01 secs]
> > > 2017-02-17T02:43:35.303+1100: 2001.344: [GC (Allocation Failure)
> > > 2017-02-17T02:43:35.303+1100: 2001.345: [ParNew: 130944K->0K(131008K),
> > > 0.0102684 secs] 856613K->727224K(2097088K), 0.0105370 secs] [Times:
> > > user=0.04 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:43:35.582+1100: 2001.623: [GC (Allocation Failure)
> > > 2017-02-17T02:43:35.582+1100: 2001.623: [ParNew: 130944K->0K(131008K),
> > > 0.0201246 secs] 858168K->735764K(2097088K), 0.0204913 secs] [Times:
> > > user=0.09 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:35.856+1100: 2001.898: [GC (Allocation Failure)
> > > 2017-02-17T02:43:35.856+1100: 2001.898: [ParNew: 130944K->0K(131008K),
> > > 0.0176264 secs] 866708K->745151K(2097088K), 0.0178741 secs] [Times:
> > > user=0.08 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:36.554+1100: 2002.595: [GC (Allocation Failure)
> > > 2017-02-17T02:43:36.554+1100: 2002.596: [ParNew: 130944K->0K(131008K),
> > > 0.0480600 secs] 876095K->752482K(2097088K), 0.0483472 secs] [Times:
> > > user=0.08 sys=0.00, real=0.05 secs]
> > > 2017-02-17T02:43:38.991+1100: 2005.033: [GC (Allocation Failure)
> > > 2017-02-17T02:43:38.991+1100: 2005.033: [ParNew: 130930K->0K(131008K),
> > > 0.0188153 secs] 883413K->764137K(2097088K), 0.0191396 secs] [Times:
> > > user=0.08 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:40.428+1100: 2006.470: [GC (Allocation Failure)
> > > 2017-02-17T02:43:40.428+1100: 2006.470: [ParNew: 130941K->0K(131008K),
> > > 0.0272629 secs] 895079K->775860K(2097088K), 0.0274685 secs] [Times:
> > > user=0.07 sys=0.01, real=0.02 secs]
> > > 2017-02-17T02:43:41.195+1100: 2007.237: [GC (Allocation Failure)
> > > 2017-02-17T02:43:41.195+1100: 2007.237: [ParNew: 130944K->0K(131008K),
> > > 0.0117222 secs] 906804K->778960K(2097088K), 0.0120822 secs] [Times:
> > > user=0.05 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:43:41.919+1100: 2007.960: [GC (Allocation Failure)
> > > 2017-02-17T02:43:41.919+1100: 2007.961: [ParNew: 130944K->0K(131008K),
> > > 0.0181342 secs] 909904K->782162K(2097088K), 0.0183815 secs] [Times:
> > > user=0.05 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:42.337+1100: 2008.378: [GC (Allocation Failure)
> > > 2017-02-17T02:43:42.337+1100: 2008.378: [ParNew: 130944K->0K(131008K),
> > > 0.0182636 secs] 913106K->790713K(2097088K), 0.0187463 secs] [Times:
> > > user=0.08 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:42.358+1100: 2008.399: [GC (CMS Initial Mark) [1
> > > CMS-initial-mark: 790713K(1966080K)] 791332K(2097088K), 0.0103648 secs]
> > > [Times: user=0.02 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:42.368+1100: 2008.410: [CMS-concurrent-mark-start]
> > > 2017-02-17T02:43:42.668+1100: 2008.709: [CMS-concurrent-mark:
> 0.299/0.299
> > > secs] [Times: user=1.76 sys=0.00, real=0.29 secs]
> > > 2017-02-17T02:43:42.668+1100: 2008.709: [CMS-concurrent-preclean-
> start]
> > > 2017-02-17T02:43:42.674+1100: 2008.716: [CMS-concurrent-preclean:
> > > 0.006/0.006 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:43:42.674+1100: 2008.716:
> > > [CMS-concurrent-abortable-preclean-start]
> > > 2017-02-17T02:43:43.450+1100: 2009.491: [GC (Allocation Failure)
> > > 2017-02-17T02:43:43.450+1100: 2009.491: [ParNew: 130944K->0K(131008K),
> > > 0.0551432 secs] 921657K->801859K(2097088K), 0.0556674 secs] [Times:
> > > user=0.14 sys=0.00, real=0.05 secs]
> > > 2017-02-17T02:43:45.723+1100: 2011.764: [CMS-concurrent-abortable-
> > > preclean:
> > > 0.322/3.048 secs] [Times: user=1.42 sys=0.04, real=3.05 secs]
> > > 2017-02-17T02:43:45.724+1100: 2011.766: [GC (CMS Final Remark) [YG
> > > occupancy: 115048 K (131008 K)]2017-02-17T02:43:45.724+1100: 2011.766:
> > > [Rescan (parallel) , 0.0249292 secs]2017-02-17T02:43:45.749+1100:
> > > 2011.791:
> > > [weak refs processing, 0.0221092 secs]2017-02-17T02:43:45.772+1100:
> > > 2011.813: [class unloading, 0.0755943 secs]2017-02-17T02:43:45.847+
> 1100:
> > > 2011.889: [scrub symbol table, 0.0482050 secs]2017-02-17T02:43:45.895+
> > > 1100:
> > > 2011.937: [scrub string table, 0.0079892 secs][1 CMS-remark:
> > > 801859K(1966080K)] 916908K(2097088K), 0.1793458 secs] [Times: user=0.28
> > > sys=0.00, real=0.18 secs]
> > > 2017-02-17T02:43:45.905+1100: 2011.946: [CMS-concurrent-sweep-start]
> > > 2017-02-17T02:43:45.921+1100: 2011.962: [GC (Allocation Failure)
> > > 2017-02-17T02:43:45.921+1100: 2011.962: [ParNew: 130944K->0K(131008K),
> > > 0.0357489 secs] 930403K->813145K(2097088K), 0.0360470 secs] [Times:
> > > user=0.14 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:43:46.320+1100: 2012.362: [CMS-concurrent-sweep:
> > 0.375/0.415
> > > secs] [Times: user=1.13 sys=0.00, real=0.42 secs]
> > > 2017-02-17T02:43:46.320+1100: 2012.362: [CMS-concurrent-reset-start]
> > > 2017-02-17T02:43:46.322+1100: 2012.363: [CMS-concurrent-reset:
> > 0.002/0.002
> > > secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:43:50.055+1100: 2016.097: [GC (Allocation Failure)
> > > 2017-02-17T02:43:50.056+1100: 2016.097: [ParNew: 130944K->0K(131008K),
> > > 0.0349198 secs] 749766K->633040K(2097088K), 0.0353595 secs] [Times:
> > > user=0.12 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:43:50.371+1100: 2016.413: [GC (Allocation Failure)
> > > 2017-02-17T02:43:50.371+1100: 2016.413: [ParNew: 130944K->0K(131008K),
> > > 0.0282887 secs] 763984K->644930K(2097088K), 0.0285394 secs] [Times:
> > > user=0.09 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:51.940+1100: 2017.981: [GC (Allocation Failure)
> > > 2017-02-17T02:43:51.940+1100: 2017.981: [ParNew: 130944K->0K(131008K),
> > > 0.0328645 secs] 775874K->656750K(2097088K), 0.0332418 secs] [Times:
> > > user=0.09 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:43:53.526+1100: 2019.567: [GC (Allocation Failure)
> > > 2017-02-17T02:43:53.526+1100: 2019.567: [ParNew: 130944K->0K(131008K),
> > > 0.0335550 secs] 787694K->669230K(2097088K), 0.0339693 secs] [Times:
> > > user=0.13 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:43:56.384+1100: 2022.425: [GC (Allocation Failure)
> > > 2017-02-17T02:43:56.384+1100: 2022.425: [ParNew: 130944K->0K(131008K),
> > > 0.0216725 secs] 800174K->683670K(2097088K), 0.0218995 secs] [Times:
> > > user=0.08 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:43:56.723+1100: 2022.764: [GC (Allocation Failure)
> > > 2017-02-17T02:43:56.723+1100: 2022.765: [ParNew: 130944K->0K(131008K),
> > > 0.0282867 secs] 814614K->696494K(2097088K), 0.0285313 secs] [Times:
> > > user=0.10 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:43:59.368+1100: 2025.410: [GC (Allocation Failure)
> > > 2017-02-17T02:43:59.368+1100: 2025.410: [ParNew: 130944K->0K(131008K),
> > > 0.0202311 secs] 827438K->708728K(2097088K), 0.0204566 secs] [Times:
> > > user=0.09 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:00.094+1100: 2026.135: [GC (Allocation Failure)
> > > 2017-02-17T02:44:00.094+1100: 2026.135: [ParNew: 130944K->0K(131008K),
> > > 0.0543868 secs] 839672K->722031K(2097088K), 0.0547452 secs] [Times:
> > > user=0.16 sys=0.00, real=0.06 secs]
> > > 2017-02-17T02:44:00.740+1100: 2026.782: [GC (Allocation Failure)
> > > 2017-02-17T02:44:00.740+1100: 2026.782: [ParNew: 130944K->0K(131008K),
> > > 0.0965223 secs] 852975K->753244K(2097088K), 0.0969327 secs] [Times:
> > > user=0.24 sys=0.00, real=0.09 secs]
> > > 2017-02-17T02:44:03.694+1100: 2029.736: [GC (Allocation Failure)
> > > 2017-02-17T02:44:03.694+1100: 2029.736: [ParNew: 130944K->0K(131008K),
> > > 0.0083419 secs] 884188K->758851K(2097088K), 0.0085863 secs] [Times:
> > > user=0.04 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:44:03.944+1100: 2029.986: [GC (Allocation Failure)
> > > 2017-02-17T02:44:03.945+1100: 2029.986: [ParNew: 130944K->0K(131008K),
> > > 0.0322574 secs] 889795K->771415K(2097088K), 0.0324985 secs] [Times:
> > > user=0.12 sys=0.01, real=0.03 secs]
> > > 2017-02-17T02:44:04.315+1100: 2030.356: [GC (Allocation Failure)
> > > 2017-02-17T02:44:04.315+1100: 2030.356: [ParNew: 130944K->0K(131008K),
> > > 0.0184334 secs] 902359K->776472K(2097088K), 0.0186736 secs] [Times:
> > > user=0.10 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:04.672+1100: 2030.713: [GC (Allocation Failure)
> > > 2017-02-17T02:44:04.672+1100: 2030.714: [ParNew: 130944K->0K(131008K),
> > > 0.0104419 secs] 907416K->779222K(2097088K), 0.0107390 secs] [Times:
> > > user=0.04 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:44:06.929+1100: 2032.971: [GC (Allocation Failure)
> > > 2017-02-17T02:44:06.929+1100: 2032.971: [ParNew: 130944K->0K(131008K),
> > > 0.0306160 secs] 910166K->788721K(2097088K), 0.0309050 secs] [Times:
> > > user=0.09 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:06.962+1100: 2033.004: [GC (CMS Initial Mark) [1
> > > CMS-initial-mark: 788721K(1966080K)] 789037K(2097088K), 0.0104127 secs]
> > > [Times: user=0.02 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:44:06.973+1100: 2033.015: [CMS-concurrent-mark-start]
> > > 2017-02-17T02:44:07.222+1100: 2033.264: [CMS-concurrent-mark:
> 0.249/0.249
> > > secs] [Times: user=1.55 sys=0.01, real=0.25 secs]
> > > 2017-02-17T02:44:07.222+1100: 2033.264: [CMS-concurrent-preclean-
> start]
> > > 2017-02-17T02:44:07.232+1100: 2033.273: [CMS-concurrent-preclean:
> > > 0.009/0.009 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:44:07.232+1100: 2033.273:
> > > [CMS-concurrent-abortable-preclean-start]
> > > 2017-02-17T02:44:07.303+1100: 2033.344: [GC (Allocation Failure)
> > > 2017-02-17T02:44:07.303+1100: 2033.344: [ParNew: 130944K->0K(131008K),
> > > 0.0210551 secs] 919665K->798886K(2097088K), 0.0212904 secs] [Times:
> > > user=0.08 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:10.241+1100: 2036.283: [CMS-concurrent-abortable-
> > > preclean:
> > > 0.254/3.009 secs] [Times: user=0.95 sys=0.03, real=3.01 secs]
> > > 2017-02-17T02:44:10.243+1100: 2036.284: [GC (CMS Final Remark) [YG
> > > occupancy: 129195 K (131008 K)]2017-02-17T02:44:10.243+1100: 2036.285:
> > > [Rescan (parallel) , 0.0237959 secs]2017-02-17T02:44:10.267+1100:
> > > 2036.308:
> > > [weak refs processing, 0.0135225 secs]2017-02-17T02:44:10.280+1100:
> > > 2036.322: [class unloading, 0.0650329 secs]2017-02-17T02:44:10.345+
> 1100:
> > > 2036.387: [scrub symbol table, 0.0456804 secs]2017-02-17T02:44:10.391+
> > > 1100:
> > > 2036.433: [scrub string table, 0.0033289 secs][1 CMS-remark:
> > > 798886K(1966080K)] 928081K(2097088K), 0.1516345 secs] [Times: user=0.26
> > > sys=0.00, real=0.15 secs]
> > > 2017-02-17T02:44:10.395+1100: 2036.437: [CMS-concurrent-sweep-start]
> > > 2017-02-17T02:44:10.400+1100: 2036.442: [GC (Allocation Failure)
> > > 2017-02-17T02:44:10.400+1100: 2036.442: [ParNew: 130944K->0K(131008K),
> > > 0.0445364 secs] 929185K->811108K(2097088K), 0.0450258 secs] [Times:
> > > user=0.11 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:44:10.842+1100: 2036.883: [CMS-concurrent-sweep:
> > 0.396/0.447
> > > secs] [Times: user=1.12 sys=0.01, real=0.45 secs]
> > > 2017-02-17T02:44:10.842+1100: 2036.883: [CMS-concurrent-reset-start]
> > > 2017-02-17T02:44:10.845+1100: 2036.887: [CMS-concurrent-reset:
> > 0.003/0.003
> > > secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:44:11.903+1100: 2037.944: [GC (Allocation Failure)
> > > 2017-02-17T02:44:11.903+1100: 2037.944: [ParNew: 130944K->0K(131008K),
> > > 0.0221250 secs] 744770K->626298K(2097088K), 0.0224061 secs] [Times:
> > > user=0.09 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:15.166+1100: 2041.208: [GC (Allocation Failure)
> > > 2017-02-17T02:44:15.166+1100: 2041.208: [ParNew: 130944K->0K(131008K),
> > > 0.0177362 secs] 757242K->637567K(2097088K), 0.0179457 secs] [Times:
> > > user=0.08 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:15.504+1100: 2041.545: [GC (Allocation Failure)
> > > 2017-02-17T02:44:15.504+1100: 2041.546: [ParNew: 130944K->0K(131008K),
> > > 0.0277922 secs] 768511K->650176K(2097088K), 0.0280503 secs] [Times:
> > > user=0.10 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:18.209+1100: 2044.251: [GC (Allocation Failure)
> > > 2017-02-17T02:44:18.210+1100: 2044.251: [ParNew: 130944K->0K(131008K),
> > > 0.0233300 secs] 781120K->664952K(2097088K), 0.0237955 secs] [Times:
> > > user=0.10 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:20.464+1100: 2046.506: [GC (Allocation Failure)
> > > 2017-02-17T02:44:20.464+1100: 2046.506: [ParNew: 130944K->0K(131008K),
> > > 0.0273960 secs] 795896K->676992K(2097088K), 0.0278519 secs] [Times:
> > > user=0.08 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:21.484+1100: 2047.525: [GC (Allocation Failure)
> > > 2017-02-17T02:44:21.484+1100: 2047.525: [ParNew: 130944K->0K(131008K),
> > > 0.0449985 secs] 807936K->690259K(2097088K), 0.0453177 secs] [Times:
> > > user=0.12 sys=0.00, real=0.05 secs]
> > > 2017-02-17T02:44:21.945+1100: 2047.987: [GC (Allocation Failure)
> > > 2017-02-17T02:44:21.946+1100: 2047.987: [ParNew: 130944K->0K(131008K),
> > > 0.0251679 secs] 821203K->699483K(2097088K), 0.0262224 secs] [Times:
> > > user=0.09 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:24.626+1100: 2050.667: [GC (Allocation Failure)
> > > 2017-02-17T02:44:24.626+1100: 2050.667: [ParNew: 130944K->0K(131008K),
> > > 0.0251576 secs] 830427K->713888K(2097088K), 0.0254822 secs] [Times:
> > > user=0.10 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:26.128+1100: 2052.170: [GC (Allocation Failure)
> > > 2017-02-17T02:44:26.128+1100: 2052.170: [ParNew: 130944K->0K(131008K),
> > > 0.0426065 secs] 844832K->726675K(2097088K), 0.0428679 secs] [Times:
> > > user=0.14 sys=0.00, real=0.05 secs]
> > > 2017-02-17T02:44:27.678+1100: 2053.719: [GC (Allocation Failure)
> > > 2017-02-17T02:44:27.678+1100: 2053.719: [ParNew: 130944K->0K(131008K),
> > > 0.0323946 secs] 857619K->740490K(2097088K), 0.0327861 secs] [Times:
> > > user=0.14 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:44:30.840+1100: 2056.882: [GC (Allocation Failure)
> > > 2017-02-17T02:44:30.840+1100: 2056.882: [ParNew: 130944K->0K(131008K),
> > > 0.0477350 secs] 871434K->753192K(2097088K), 0.0483545 secs] [Times:
> > > user=0.11 sys=0.00, real=0.05 secs]
> > > 2017-02-17T02:44:31.322+1100: 2057.363: [GC (Allocation Failure)
> > > 2017-02-17T02:44:31.322+1100: 2057.363: [ParNew: 130944K->0K(131008K),
> > > 0.0307054 secs] 884136K->763364K(2097088K), 0.0309678 secs] [Times:
> > > user=0.11 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:34.620+1100: 2060.661: [GC (Allocation Failure)
> > > 2017-02-17T02:44:34.620+1100: 2060.661: [ParNew: 130944K->0K(131008K),
> > > 0.0201055 secs] 894308K->770865K(2097088K), 0.0203720 secs] [Times:
> > > user=0.06 sys=0.02, real=0.03 secs]
> > > 2017-02-17T02:44:34.971+1100: 2061.012: [GC (Allocation Failure)
> > > 2017-02-17T02:44:34.971+1100: 2061.012: [ParNew: 130944K->0K(131008K),
> > > 0.0315070 secs] 901809K->782181K(2097088K), 0.0317446 secs] [Times:
> > > user=0.14 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:38.021+1100: 2064.063: [GC (Allocation Failure)
> > > 2017-02-17T02:44:38.021+1100: 2064.063: [ParNew: 130944K->0K(131008K),
> > > 0.0275684 secs] 913125K->797709K(2097088K), 0.0279734 secs] [Times:
> > > user=0.10 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:38.052+1100: 2064.094: [GC (CMS Initial Mark) [1
> > > CMS-initial-mark: 797709K(1966080K)] 798588K(2097088K), 0.0051309 secs]
> > > [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:44:38.058+1100: 2064.099: [CMS-concurrent-mark-start]
> > > 2017-02-17T02:44:38.288+1100: 2064.330: [CMS-concurrent-mark:
> 0.230/0.230
> > > secs] [Times: user=1.45 sys=0.01, real=0.24 secs]
> > > 2017-02-17T02:44:38.288+1100: 2064.330: [CMS-concurrent-preclean-
> start]
> > > 2017-02-17T02:44:38.294+1100: 2064.335: [CMS-concurrent-preclean:
> > > 0.005/0.005 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:44:38.294+1100: 2064.335:
> > > [CMS-concurrent-abortable-preclean-start]
> > > 2017-02-17T02:44:38.387+1100: 2064.428: [GC (Allocation Failure)
> > > 2017-02-17T02:44:38.387+1100: 2064.428: [ParNew: 130944K->0K(131008K),
> > > 0.0140969 secs] 928653K->805184K(2097088K), 0.0143336 secs] [Times:
> > > user=0.05 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:41.231+1100: 2067.272: [CMS-concurrent-abortable-
> > > preclean:
> > > 0.254/2.937 secs] [Times: user=1.09 sys=0.07, real=2.94 secs]
> > > 2017-02-17T02:44:41.232+1100: 2067.273: [GC (CMS Final Remark) [YG
> > > occupancy: 75740 K (131008 K)]2017-02-17T02:44:41.232+1100: 2067.273:
> > > [Rescan (parallel) , 0.0185411 secs]2017-02-17T02:44:41.251+1100:
> > > 2067.292:
> > > [weak refs processing, 0.0161160 secs]2017-02-17T02:44:41.267+1100:
> > > 2067.308: [class unloading, 0.0620000 secs]2017-02-17T02:44:41.329+
> 1100:
> > > 2067.370: [scrub symbol table, 0.0471891 secs]2017-02-17T02:44:41.376+
> > > 1100:
> > > 2067.417: [scrub string table, 0.0029885 secs][1 CMS-remark:
> > > 805184K(1966080K)] 880925K(2097088K), 0.1471620 secs] [Times: user=0.21
> > > sys=0.01, real=0.14 secs]
> > > 2017-02-17T02:44:41.379+1100: 2067.421: [CMS-concurrent-sweep-start]
> > > 2017-02-17T02:44:41.521+1100: 2067.562: [GC (Allocation Failure)
> > > 2017-02-17T02:44:41.521+1100: 2067.562: [ParNew: 130944K->0K(131008K),
> > > 0.0275124 secs] 879741K->762742K(2097088K), 0.0277784 secs] [Times:
> > > user=0.12 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:41.893+1100: 2067.934: [CMS-concurrent-sweep:
> > 0.479/0.513
> > > secs] [Times: user=1.67 sys=0.04, real=0.52 secs]
> > > 2017-02-17T02:44:41.893+1100: 2067.934: [CMS-concurrent-reset-start]
> > > 2017-02-17T02:44:41.896+1100: 2067.938: [CMS-concurrent-reset:
> > 0.004/0.004
> > > secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:44:41.933+1100: 2067.975: [GC (Allocation Failure)
> > > 2017-02-17T02:44:41.934+1100: 2067.975: [ParNew: 130944K->0K(131008K),
> > > 0.0225040 secs] 753799K->632471K(2097088K), 0.0231169 secs] [Times:
> > > user=0.09 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:46.357+1100: 2072.399: [GC (Allocation Failure)
> > > 2017-02-17T02:44:46.358+1100: 2072.399: [ParNew: 130944K->0K(131008K),
> > > 0.0233062 secs] 763415K->648794K(2097088K), 0.0235657 secs] [Times:
> > > user=0.11 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:46.693+1100: 2072.734: [GC (Allocation Failure)
> > > 2017-02-17T02:44:46.693+1100: 2072.734: [ParNew: 130944K->0K(131008K),
> > > 0.0204649 secs] 779738K->658469K(2097088K), 0.0207512 secs] [Times:
> > > user=0.07 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:49.622+1100: 2075.664: [GC (Allocation Failure)
> > > 2017-02-17T02:44:49.623+1100: 2075.664: [ParNew: 130944K->0K(131008K),
> > > 0.0261480 secs] 789413K->669895K(2097088K), 0.0264612 secs] [Times:
> > > user=0.09 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:50.683+1100: 2076.724: [GC (Allocation Failure)
> > > 2017-02-17T02:44:50.683+1100: 2076.725: [ParNew: 130944K->0K(131008K),
> > > 0.0304973 secs] 800839K->682648K(2097088K), 0.0308284 secs] [Times:
> > > user=0.11 sys=0.01, real=0.03 secs]
> > > 2017-02-17T02:44:52.917+1100: 2078.958: [GC (Allocation Failure)
> > > 2017-02-17T02:44:52.917+1100: 2078.958: [ParNew: 130944K->0K(131008K),
> > > 0.0199548 secs] 813592K->691321K(2097088K), 0.0202226 secs] [Times:
> > > user=0.08 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:44:53.254+1100: 2079.296: [GC (Allocation Failure)
> > > 2017-02-17T02:44:53.254+1100: 2079.296: [ParNew: 130944K->0K(131008K),
> > > 0.0288800 secs] 822265K->702344K(2097088K), 0.0292182 secs] [Times:
> > > user=0.10 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:56.103+1100: 2082.145: [GC (Allocation Failure)
> > > 2017-02-17T02:44:56.103+1100: 2082.145: [ParNew: 130944K->0K(131008K),
> > > 0.0306146 secs] 833288K->714654K(2097088K), 0.0310109 secs] [Times:
> > > user=0.12 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:44:57.011+1100: 2083.052: [GC (Allocation Failure)
> > > 2017-02-17T02:44:57.011+1100: 2083.053: [ParNew: 130944K->0K(131008K),
> > > 0.0438056 secs] 845598K->729259K(2097088K), 0.0443198 secs] [Times:
> > > user=0.15 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:44:58.467+1100: 2084.509: [GC (Allocation Failure)
> > > 2017-02-17T02:44:58.467+1100: 2084.509: [ParNew: 130944K->0K(131008K),
> > > 0.0106478 secs] 860203K->731810K(2097088K), 0.0109459 secs] [Times:
> > > user=0.03 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:44:59.134+1100: 2085.176: [GC (Allocation Failure)
> > > 2017-02-17T02:44:59.134+1100: 2085.176: [ParNew: 130915K->0K(131008K),
> > > 0.0057411 secs] 862725K->732521K(2097088K), 0.0059370 secs] [Times:
> > > user=0.02 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:44:59.657+1100: 2085.698: [GC (Allocation Failure)
> > > 2017-02-17T02:44:59.657+1100: 2085.698: [ParNew: 130944K->0K(131008K),
> > > 0.0262399 secs] 863465K->743741K(2097088K), 0.0265018 secs] [Times:
> > > user=0.11 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:45:00.112+1100: 2086.153: [GC (Allocation Failure)
> > > 2017-02-17T02:45:00.112+1100: 2086.153: [ParNew: 130944K->0K(131008K),
> > > 0.1237185 secs] 874685K->779466K(2097088K), 0.1242109 secs] [Times:
> > > user=0.29 sys=0.00, real=0.12 secs]
> > > 2017-02-17T02:45:04.750+1100: 2090.791: [GC (Allocation Failure)
> > > 2017-02-17T02:45:04.750+1100: 2090.791: [ParNew: 130944K->0K(131008K),
> > > 0.0165329 secs] 910410K->787929K(2097088K), 0.0168275 secs] [Times:
> > > user=0.07 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:45:04.768+1100: 2090.809: [GC (CMS Initial Mark) [1
> > > CMS-initial-mark: 787929K(1966080K)] 788776K(2097088K), 0.0040991 secs]
> > > [Times: user=0.01 sys=0.01, real=0.00 secs]
> > > 2017-02-17T02:45:04.772+1100: 2090.814: [CMS-concurrent-mark-start]
> > > 2017-02-17T02:45:04.990+1100: 2091.032: [CMS-concurrent-mark:
> 0.218/0.218
> > > secs] [Times: user=1.40 sys=0.00, real=0.22 secs]
> > > 2017-02-17T02:45:04.991+1100: 2091.032: [CMS-concurrent-preclean-
> start]
> > > 2017-02-17T02:45:04.996+1100: 2091.038: [CMS-concurrent-preclean:
> > > 0.006/0.006 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:45:04.996+1100: 2091.038:
> > > [CMS-concurrent-abortable-preclean-start]
> > > 2017-02-17T02:45:05.109+1100: 2091.151: [CMS-concurrent-abortable-
> > > preclean:
> > > 0.013/0.113 secs] [Times: user=0.25 sys=0.01, real=0.12 secs]
> > > 2017-02-17T02:45:05.111+1100: 2091.153: [GC (CMS Final Remark) [YG
> > > occupancy: 81420 K (131008 K)]2017-02-17T02:45:05.112+1100: 2091.153:
> > > [Rescan (parallel) , 0.0170368 secs]2017-02-17T02:45:05.129+1100:
> > > 2091.170:
> > > [weak refs processing, 0.0160407 secs]2017-02-17T02:45:05.145+1100:
> > > 2091.186: [class unloading, 0.0761075 secs]2017-02-17T02:45:05.221+
> 1100:
> > > 2091.262: [scrub symbol table, 0.0461117 secs]2017-02-17T02:45:05.267+
> > > 1100:
> > > 2091.308: [scrub string table, 0.0027865 secs][1 CMS-remark:
> > > 787929K(1966080K)] 869350K(2097088K), 0.1584396 secs] [Times: user=0.23
> > > sys=0.00, real=0.16 secs]
> > > 2017-02-17T02:45:05.270+1100: 2091.312: [CMS-concurrent-sweep-start]
> > > 2017-02-17T02:45:05.309+1100: 2091.350: [GC (Allocation Failure)
> > > 2017-02-17T02:45:05.309+1100: 2091.350: [ParNew: 130944K->0K(131008K),
> > > 0.0256950 secs] 909451K->791427K(2097088K), 0.0259124 secs] [Times:
> > > user=0.10 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:45:05.664+1100: 2091.705: [CMS-concurrent-sweep:
> > 0.363/0.394
> > > secs] [Times: user=1.26 sys=0.00, real=0.39 secs]
> > > 2017-02-17T02:45:05.664+1100: 2091.706: [CMS-concurrent-reset-start]
> > > 2017-02-17T02:45:05.670+1100: 2091.711: [CMS-concurrent-reset:
> > 0.005/0.005
> > > secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:45:09.948+1100: 2095.990: [GC (Allocation Failure)
> > > 2017-02-17T02:45:09.948+1100: 2095.990: [ParNew: 130944K->0K(131008K),
> > > 0.0347194 secs] 728922K->612136K(2097088K), 0.0350136 secs] [Times:
> > > user=0.12 sys=0.01, real=0.03 secs]
> > > 2017-02-17T02:45:10.346+1100: 2096.388: [GC (Allocation Failure)
> > > 2017-02-17T02:45:10.347+1100: 2096.388: [ParNew: 130944K->0K(131008K),
> > > 0.0421117 secs] 743080K->623894K(2097088K), 0.0427087 secs] [Times:
> > > user=0.11 sys=0.00, real=0.05 secs]
> > > 2017-02-17T02:45:14.076+1100: 2100.118: [GC (Allocation Failure)
> > > 2017-02-17T02:45:14.076+1100: 2100.118: [ParNew: 130944K->0K(131008K),
> > > 0.0383561 secs] 754838K->633484K(2097088K), 0.0386263 secs] [Times:
> > > user=0.09 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:45:14.516+1100: 2100.557: [GC (Allocation Failure)
> > > 2017-02-17T02:45:14.516+1100: 2100.557: [ParNew: 130944K->0K(131008K),
> > > 0.0469385 secs] 764428K->645002K(2097088K), 0.0472950 secs] [Times:
> > > user=0.11 sys=0.00, real=0.05 secs]
> > > 2017-02-17T02:45:18.610+1100: 2104.651: [GC (Allocation Failure)
> > > 2017-02-17T02:45:18.610+1100: 2104.651: [ParNew: 130944K->0K(131008K),
> > > 0.0438649 secs] 775946K->659657K(2097088K), 0.0444299 secs] [Times:
> > > user=0.11 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:45:19.016+1100: 2105.058: [GC (Allocation Failure)
> > > 2017-02-17T02:45:19.016+1100: 2105.058: [ParNew: 130944K->0K(131008K),
> > > 0.0507684 secs] 790601K->671909K(2097088K), 0.0511395 secs] [Times:
> > > user=0.12 sys=0.01, real=0.05 secs]
> > > 2017-02-17T02:45:22.558+1100: 2108.600: [GC (Allocation Failure)
> > > 2017-02-17T02:45:22.558+1100: 2108.600: [ParNew: 130944K->0K(131008K),
> > > 0.0372261 secs] 802853K->680749K(2097088K), 0.0376654 secs] [Times:
> > > user=0.09 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:45:23.046+1100: 2109.087: [GC (Allocation Failure)
> > > 2017-02-17T02:45:23.046+1100: 2109.087: [ParNew: 130944K->0K(131008K),
> > > 0.0351447 secs] 811693K->691789K(2097088K), 0.0354445 secs] [Times:
> > > user=0.09 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:45:26.053+1100: 2112.095: [GC (Allocation Failure)
> > > 2017-02-17T02:45:26.053+1100: 2112.095: [ParNew: 130944K->0K(131008K),
> > > 0.0656059 secs] 822733K->708014K(2097088K), 0.0659827 secs] [Times:
> > > user=0.14 sys=0.00, real=0.06 secs]
> > > 2017-02-17T02:45:41.925+1100: 2127.967: [GC (Allocation Failure)
> > > 2017-02-17T02:45:41.925+1100: 2127.967: [ParNew: 130944K->0K(131008K),
> > > 0.0155199 secs] 838958K->711744K(2097088K), 0.0158258 secs] [Times:
> > > user=0.05 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:46:00.038+1100: 2146.079: [GC (Allocation Failure)
> > > 2017-02-17T02:46:00.038+1100: 2146.079: [ParNew: 130944K->0K(131008K),
> > > 0.0400212 secs] 842688K->728169K(2097088K), 0.0402518 secs] [Times:
> > > user=0.10 sys=0.00, real=0.04 secs]
> > > 2017-02-17T02:46:11.916+1100: 2157.958: [GC (Allocation Failure)
> > > 2017-02-17T02:46:11.917+1100: 2157.958: [ParNew: 130944K->0K(131008K),
> > > 0.0289077 secs] 859113K->744463K(2097088K), 0.0291609 secs] [Times:
> > > user=0.13 sys=0.00, real=0.03 secs]
> > > 2017-02-17T02:46:31.907+1100: 2177.949: [GC (Allocation Failure)
> > > 2017-02-17T02:46:31.908+1100: 2177.949: [ParNew: 130944K->0K(131008K),
> > > 0.0112924 secs] 875407K->747899K(2097088K), 0.0115952 secs] [Times:
> > > user=0.02 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:46:51.900+1100: 2197.941: [GC (Allocation Failure)
> > > 2017-02-17T02:46:51.900+1100: 2197.942: [ParNew: 130944K->0K(131008K),
> > > 0.0045572 secs] 878843K->750985K(2097088K), 0.0048081 secs] [Times:
> > > user=0.02 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:47:01.930+1100: 2207.971: [GC (Allocation Failure)
> > > 2017-02-17T02:47:01.930+1100: 2207.971: [ParNew: 130944K->0K(131008K),
> > > 0.0086248 secs] 881929K->755528K(2097088K), 0.0088485 secs] [Times:
> > > user=0.04 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:47:21.928+1100: 2227.970: [GC (Allocation Failure)
> > > 2017-02-17T02:47:21.929+1100: 2227.970: [ParNew: 130944K->0K(131008K),
> > > 0.0077591 secs] 886472K->758584K(2097088K), 0.0082467 secs] [Times:
> > > user=0.03 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:47:41.948+1100: 2247.989: [GC (Allocation Failure)
> > > 2017-02-17T02:47:41.948+1100: 2247.990: [ParNew: 130126K->0K(131008K),
> > > 0.0102145 secs] 888711K->760882K(2097088K), 0.0108365 secs] [Times:
> > > user=0.04 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:48:01.923+1100: 2267.964: [GC (Allocation Failure)
> > > 2017-02-17T02:48:01.923+1100: 2267.965: [ParNew: 130944K->0K(131008K),
> > > 0.0107592 secs] 891826K->764669K(2097088K), 0.0110117 secs] [Times:
> > > user=0.04 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:48:21.917+1100: 2287.958: [GC (Allocation Failure)
> > > 2017-02-17T02:48:21.917+1100: 2287.958: [ParNew: 130944K->0K(131008K),
> > > 0.0090583 secs] 895613K->768273K(2097088K), 0.0092679 secs] [Times:
> > > user=0.03 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:48:41.904+1100: 2307.945: [GC (Allocation Failure)
> > > 2017-02-17T02:48:41.904+1100: 2307.945: [ParNew: 130944K->0K(131008K),
> > > 0.0078590 secs] 899217K->773317K(2097088K), 0.0081014 secs] [Times:
> > > user=0.04 sys=0.01, real=0.01 secs]
> > > 2017-02-17T02:49:00.029+1100: 2326.070: [GC (Allocation Failure)
> > > 2017-02-17T02:49:00.029+1100: 2326.070: [ParNew: 130944K->0K(131008K),
> > > 0.0087433 secs] 904261K->777092K(2097088K), 0.0090668 secs] [Times:
> > > user=0.03 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:49:11.929+1100: 2337.970: [GC (Allocation Failure)
> > > 2017-02-17T02:49:11.929+1100: 2337.970: [ParNew: 130944K->0K(131008K),
> > > 0.0084035 secs] 908036K->780961K(2097088K), 0.0086772 secs] [Times:
> > > user=0.04 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:49:31.924+1100: 2357.965: [GC (Allocation Failure)
> > > 2017-02-17T02:49:31.924+1100: 2357.965: [ParNew: 130944K->0K(131008K),
> > > 0.0067438 secs] 911905K->786009K(2097088K), 0.0069780 secs] [Times:
> > > user=0.02 sys=0.01, real=0.01 secs]
> > > 2017-02-17T02:49:51.920+1100: 2377.961: [GC (Allocation Failure)
> > > 2017-02-17T02:49:51.920+1100: 2377.962: [ParNew: 130944K->0K(131008K),
> > > 0.0077132 secs] 916953K->790678K(2097088K), 0.0079584 secs] [Times:
> > > user=0.04 sys=0.01, real=0.01 secs]
> > > 2017-02-17T02:49:51.929+1100: 2377.971: [GC (CMS Initial Mark) [1
> > > CMS-initial-mark: 790678K(1966080K)] 791582K(2097088K), 0.0041258 secs]
> > > [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:49:51.934+1100: 2377.975: [CMS-concurrent-mark-start]
> > > 2017-02-17T02:49:52.152+1100: 2378.193: [CMS-concurrent-mark:
> 0.218/0.218
> > > secs] [Times: user=1.40 sys=0.00, real=0.22 secs]
> > > 2017-02-17T02:49:52.152+1100: 2378.193: [CMS-concurrent-preclean-
> start]
> > > 2017-02-17T02:49:52.158+1100: 2378.200: [CMS-concurrent-preclean:
> > > 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:49:52.159+1100: 2378.200:
> > > [CMS-concurrent-abortable-preclean-start]
> > >  CMS: abort preclean due to time 2017-02-17T02:49:57.255+1100:
> 2383.297:
> > > [CMS-concurrent-abortable-preclean: 0.251/5.097 secs] [Times:
> user=5.46
> > > sys=0.01, real=5.10 secs]
> > > 2017-02-17T02:49:57.257+1100: 2383.299: [GC (CMS Final Remark) [YG
> > > occupancy: 32717 K (131008 K)]2017-02-17T02:49:57.258+1100: 2383.299:
> > > [Rescan (parallel) , 0.0059087 secs]2017-02-17T02:49:57.263+1100:
> > > 2383.305:
> > > [weak refs processing, 0.0087868 secs]2017-02-17T02:49:57.272+1100:
> > > 2383.314: [class unloading, 0.0610022 secs]2017-02-17T02:49:57.333+
> 1100:
> > > 2383.375: [scrub symbol table, 0.0349937 secs]2017-02-17T02:49:57.368+
> > > 1100:
> > > 2383.410: [scrub string table, 0.0020473 secs][1 CMS-remark:
> > > 790678K(1966080K)] 823395K(2097088K), 0.1130339 secs] [Times: user=0.14
> > > sys=0.00, real=0.12 secs]
> > > 2017-02-17T02:49:57.371+1100: 2383.412: [CMS-concurrent-sweep-start]
> > > 2017-02-17T02:49:57.643+1100: 2383.685: [CMS-concurrent-sweep:
> > 0.272/0.272
> > > secs] [Times: user=0.81 sys=0.01, real=0.27 secs]
> > > 2017-02-17T02:49:57.643+1100: 2383.685: [CMS-concurrent-reset-start]
> > > 2017-02-17T02:49:57.647+1100: 2383.688: [CMS-concurrent-reset:
> > 0.003/0.003
> > > secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:50:11.909+1100: 2397.950: [GC (Allocation Failure)
> > > 2017-02-17T02:50:11.909+1100: 2397.950: [ParNew: 130944K->0K(131008K),
> > > 0.0080014 secs] 750096K->624619K(2097088K), 0.0083174 secs] [Times:
> > > user=0.03 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:50:31.913+1100: 2417.955: [GC (Allocation Failure)
> > > 2017-02-17T02:50:31.913+1100: 2417.955: [ParNew: 130944K->0K(131008K),
> > > 0.0055607 secs] 755563K->628586K(2097088K), 0.0058577 secs] [Times:
> > > user=0.03 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:50:51.903+1100: 2437.944: [GC (Allocation Failure)
> > > 2017-02-17T02:50:51.903+1100: 2437.945: [ParNew: 130944K->0K(131008K),
> > > 0.0069750 secs] 759530K->632225K(2097088K), 0.0074119 secs] [Times:
> > > user=0.03 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:51:01.931+1100: 2447.972: [GC (Allocation Failure)
> > > 2017-02-17T02:51:01.931+1100: 2447.972: [ParNew: 130944K->0K(131008K),
> > > 0.0052841 secs] 763169K->637260K(2097088K), 0.0054611 secs] [Times:
> > > user=0.02 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:51:21.928+1100: 2467.969: [GC (Allocation Failure)
> > > 2017-02-17T02:51:21.928+1100: 2467.969: [ParNew: 130944K->0K(131008K),
> > > 0.0091373 secs] 768204K->640807K(2097088K), 0.0093986 secs] [Times:
> > > user=0.04 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:51:41.936+1100: 2487.977: [GC (Allocation Failure)
> > > 2017-02-17T02:51:41.936+1100: 2487.977: [ParNew: 130152K->0K(131008K),
> > > 0.0099106 secs] 770959K->645792K(2097088K), 0.0101119 secs] [Times:
> > > user=0.04 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:52:01.928+1100: 2507.970: [GC (Allocation Failure)
> > > 2017-02-17T02:52:01.928+1100: 2507.970: [ParNew: 130944K->0K(131008K),
> > > 0.0096195 secs] 776736K->650814K(2097088K), 0.0102844 secs] [Times:
> > > user=0.04 sys=0.00, real=0.00 secs]
> > > 2017-02-17T02:52:21.913+1100: 2527.955: [GC (Allocation Failure)
> > > 2017-02-17T02:52:21.913+1100: 2527.955: [ParNew: 130944K->0K(131008K),
> > > 0.0176493 secs] 781758K->656556K(2097088K), 0.0179549 secs] [Times:
> > > user=0.05 sys=0.00, real=0.02 secs]
> > > 2017-02-17T02:52:41.904+1100: 2547.945: [GC (Allocation Failure)
> > > 2017-02-17T02:52:41.904+1100: 2547.945: [ParNew: 130944K->0K(131008K),
> > > 0.0072279 secs] 787500K->660929K(2097088K), 0.0075509 secs] [Times:
> > > user=0.02 sys=0.00, real=0.01 secs]
> > > 2017-02-17T02:52:52.300+1100: 2558.341: [GC (Allocation Failure)
> > > 2017-02-17T02:52:52.300+1100: 2558.341: [ParNew: 130944K->0K(131008K),
> > > 0.0064136 secs] 791873K->664124K(2097088K), 0.0065792 secs] [Times:
> > > user=0.02 sys=0.00, real=0.01 secs]
> > >
> > > *[ignite logs]*
> > >
> > >    30064 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Failed to wait for partition map exchange
> > > [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0],
> > > node=54047017-02fb-4885-8586-25799b9c382e]. Dumping pending objects
> that
> > > might be the cause:
> > >    30064 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Ready affinity version:
> > > AffinityTopologyVersion [topVer=-1, minorTopVer=0]
> > >    30071 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Last exchange future:
> > > GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> > > reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
> > > [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53],
> > > sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3,
> > intOrder=3,
> > > lastExchangeTime=1487259937134, loc=true, ver=1.8.1#20161208-sha1:
> > > a8fcb7b2,
> > > isClient=false], topVer=3, nodeId8=54047017, msg=null,
> type=NODE_JOINED,
> > > tstamp=1487259925888], crd=TcpDiscoveryNode
> > > [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51],
> > > sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1,
> > intOrder=1,
> > > lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> > > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> > > [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED],
> > added=false,
> > > initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487259928142,
> > > endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true,
> > > topSnapshot=null, 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=1487259928142, centralizedAff=false,
> > > evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode
> > > [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51],
> > > sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1,
> > intOrder=1,
> > > lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52],
> > > sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2,
> > intOrder=2,
> > > lastExchangeTime=1487259925667, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53],
> > > sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3,
> > intOrder=3,
> > > lastExchangeTime=1487259937134, loc=true, ver=1.8.1#20161208-sha1:
> > > a8fcb7b2,
> > > isClient=false]], super=GridFutureAdapter [resFlag=0, res=null,
> > > startTime=1487259928142, endTime=0, ignoreInterrupts=false,
> state=INIT]]
> > >    30071 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending exchange futures:
> > >    30072 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Last 10 exchange futures (total: 1):
> > >    30073 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] >>> GridDhtPartitionsExchangeFuture
> > > [dummy=false, forcePreload=false, reassign=false,
> discoEvt=DiscoveryEvent
> > > [evtNode=TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e,
> > > addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500],
> > discPort=47500,
> > > order=3, intOrder=3, lastExchangeTime=1487259937134, loc=true,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=3,
> > > nodeId8=54047017, msg=null, type=NODE_JOINED, tstamp=1487259925888],
> > > crd=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500],
> > discPort=47500,
> > > order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> > > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> > > [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED],
> > added=false,
> > > initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487259928142,
> > > endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true,
> > > topSnapshot=null, 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=1487259928142, centralizedAff=false,
> > > evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode
> > > [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51],
> > > sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1,
> > intOrder=1,
> > > lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52],
> > > sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2,
> > intOrder=2,
> > > lastExchangeTime=1487259925667, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53],
> > > sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3,
> > intOrder=3,
> > > lastExchangeTime=1487259937134, loc=true, ver=1.8.1#20161208-sha1:
> > > a8fcb7b2,
> > > isClient=false]], super=GridFutureAdapter [resFlag=0, res=null,
> > > startTime=1487259928142, endTime=0, ignoreInterrupts=false,
> state=INIT]]
> > >    30073 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending transactions:
> > >    30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending explicit locks:
> > >    30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending cache futures:
> > >    30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending atomic cache futures:
> > >    30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending data streamer futures:
> > >    30074 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending transaction deadlock detection
> > > futures:
> > >    30084 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > [exchange-worker-#24%webapp%]
> > > Communication SPI recovery descriptors:
> > >     [key=ClientKey [nodeId=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > order=1],
> > > msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272, lastAcked=272,
> > > reserveCnt=1, descIdHash=703751156]
> > > Communication SPI clients:
> > >     [node=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
> > > [selectorIdx=0, queueSize=0, writeBuf=java.nio.DirectByteBuffer[pos=0
> > > lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0
> lim=32768
> > > cap=32768], recovery=GridNioRecoveryDescriptor [acked=272,
> resendCnt=0,
> > > rcvCnt=272, sentCnt=272, reserved=true, lastAck=272, nodeLeft=false,
> > > node=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500],
> > discPort=47500,
> > > order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], connected=true,
> > > connectCnt=0, queueLimit=5120, reserveCnt=1], super=GridNioSessionImpl
> > > [locAddr=/192.168.0.53:47100, rmtAddr=/192.168.0.53:33596,
> > > createTime=1487259926038, closeTime=0, bytesSent=13367,
> > bytesRcvd=1172506,
> > > sndSchedTime=1487259928672, lastSndTime=1487259928672,
> > > lastRcvTime=1487259928682, readsPaused=false,
> > > filterChain=FilterChain[filters=[GridNioCodecFilter
> > > [parser=o.a.i.i.util.nio.GridDirectParser@375e6c31, directMode=true],
> > > GridConnectionBytesVerifyFilter], accepted=true]],
> > > super=GridAbstractCommunicationClient [lastUsed=1487259926138,
> > > reserves=0]]]
> > >
> > >    30086 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-1-#10%webapp%]
> > > >> Selector info [idx=1, keysCnt=0]
> > >
> > >    30086 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-0-#9%webapp%]
> > > >> Selector info [idx=0, keysCnt=1]
> > >     Connection info [rmtAddr=/192.168.0.53:33596, locAddr=/
> > > 192.168.0.53:47100, msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272,
> > > descIdHash=703751156, bytesRcvd=1172506, bytesSent=13367,
> opQueueSize=0,
> > > msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
> > > stack=[StateItem [stream=DirectByteBufferStreamImplV2
> > > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
> > > baseOff=140318527729152, 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=140318527729152, 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=140318527729152, 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=140318527729152, 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=140318527761936, 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=140318527761936, 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=140318527761936, 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]]
> > >
> > >    30086 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-2-#11%webapp%]
> > > >> Selector info [idx=2, keysCnt=0]
> > >
> > >    30086 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-3-#12%webapp%]
> > > >> Selector info [idx=3, keysCnt=0]
> > >
> > >    40086 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Failed to wait for partition map exchange
> > > [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=0],
> > > node=54047017-02fb-4885-8586-25799b9c382e]. Dumping pending objects
> that
> > > might be the cause:
> > >    40087 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Ready affinity version:
> > > AffinityTopologyVersion [topVer=-1, minorTopVer=0]
> > >    40088 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Last exchange future:
> > > GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> > > reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode
> > > [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53],
> > > sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3,
> > intOrder=3,
> > > lastExchangeTime=1487259947169, loc=true, ver=1.8.1#20161208-sha1:
> > > a8fcb7b2,
> > > isClient=false], topVer=3, nodeId8=54047017, msg=null,
> type=NODE_JOINED,
> > > tstamp=1487259925888], crd=TcpDiscoveryNode
> > > [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51],
> > > sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1,
> > intOrder=1,
> > > lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> > > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> > > [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED],
> > added=false,
> > > initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487259928142,
> > > endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true,
> > > topSnapshot=null, 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=1487259928142, centralizedAff=false,
> > > evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode
> > > [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51],
> > > sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1,
> > intOrder=1,
> > > lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52],
> > > sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2,
> > intOrder=2,
> > > lastExchangeTime=1487259925667, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53],
> > > sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3,
> > intOrder=3,
> > > lastExchangeTime=1487259947169, loc=true, ver=1.8.1#20161208-sha1:
> > > a8fcb7b2,
> > > isClient=false]], super=GridFutureAdapter [resFlag=0, res=null,
> > > startTime=1487259928142, endTime=0, ignoreInterrupts=false,
> state=INIT]]
> > >    40088 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending exchange futures:
> > >    40088 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Last 10 exchange futures (total: 1):
> > >    40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] >>> GridDhtPartitionsExchangeFuture
> > > [dummy=false, forcePreload=false, reassign=false,
> discoEvt=DiscoveryEvent
> > > [evtNode=TcpDiscoveryNode [id=54047017-02fb-4885-8586-25799b9c382e,
> > > addrs=[192.168.0.53], sockAddrs=[devc/192.168.0.53:47500],
> > discPort=47500,
> > > order=3, intOrder=3, lastExchangeTime=1487259947169, loc=true,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=3,
> > > nodeId8=54047017, msg=null, type=NODE_JOINED, tstamp=1487259925888],
> > > crd=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500],
> > discPort=47500,
> > > order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> > > exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> > > [topVer=3, minorTopVer=0], nodeId=54047017, evt=NODE_JOINED],
> > added=false,
> > > initFut=GridFutureAdapter [resFlag=2, res=true,
> startTime=1487259928142,
> > > endTime=1487259928672, ignoreInterrupts=false, state=DONE], init=true,
> > > topSnapshot=null, 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=1487259928142, centralizedAff=false,
> > > evtLatch=0, remaining=[f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > 564179a0-e184-4c82-aafc-2355993b8f30], srvNodes=[TcpDiscoveryNode
> > > [id=f931e110-ac37-43ba-b54a-faa79c9ac34b, addrs=[192.168.0.51],
> > > sockAddrs=[deva/192.168.0.51:47500], discPort=47500, order=1,
> > intOrder=1,
> > > lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=564179a0-e184-4c82-aafc-2355993b8f30, addrs=[192.168.0.52],
> > > sockAddrs=[devb/192.168.0.52:47500], discPort=47500, order=2,
> > intOrder=2,
> > > lastExchangeTime=1487259925667, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], TcpDiscoveryNode
> > > [id=54047017-02fb-4885-8586-25799b9c382e, addrs=[192.168.0.53],
> > > sockAddrs=[devc/192.168.0.53:47500], discPort=47500, order=3,
> > intOrder=3,
> > > lastExchangeTime=1487259947169, loc=true, ver=1.8.1#20161208-sha1:
> > > a8fcb7b2,
> > > isClient=false]], super=GridFutureAdapter [resFlag=0, res=null,
> > > startTime=1487259928142, endTime=0, ignoreInterrupts=false,
> state=INIT]]
> > >    40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending transactions:
> > >    40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending explicit locks:
> > >    40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending cache futures:
> > >    40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending atomic cache futures:
> > >    40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending data streamer futures:
> > >    40089 W o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > [exchange-worker-#24%webapp%] Pending transaction deadlock detection
> > > futures:
> > >    40090 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > [exchange-worker-#24%webapp%]
> > > Communication SPI recovery descriptors:
> > >     [key=ClientKey [nodeId=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > order=1],
> > > msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272, lastAcked=272,
> > > reserveCnt=1, descIdHash=703751156]
> > > Communication SPI clients:
> > >     [node=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > client=GridTcpNioCommunicationClient [ses=GridSelectorNioSessionImpl
> > > [selectorIdx=0, queueSize=0, writeBuf=java.nio.DirectByteBuffer[pos=0
> > > lim=32768 cap=32768], readBuf=java.nio.DirectByteBuffer[pos=0
> lim=32768
> > > cap=32768], recovery=GridNioRecoveryDescriptor [acked=272,
> resendCnt=0,
> > > rcvCnt=272, sentCnt=272, reserved=true, lastAck=272, nodeLeft=false,
> > > node=TcpDiscoveryNode [id=f931e110-ac37-43ba-b54a-faa79c9ac34b,
> > > addrs=[192.168.0.51], sockAddrs=[deva/192.168.0.51:47500],
> > discPort=47500,
> > > order=1, intOrder=1, lastExchangeTime=1487259925656, loc=false,
> > > ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], connected=true,
> > > connectCnt=0, queueLimit=5120, reserveCnt=1], super=GridNioSessionImpl
> > > [locAddr=/192.168.0.53:47100, rmtAddr=/192.168.0.53:33596,
> > > createTime=1487259926038, closeTime=0, bytesSent=13367,
> > bytesRcvd=1172506,
> > > sndSchedTime=1487259928672, lastSndTime=1487259928672,
> > > lastRcvTime=1487259928682, readsPaused=false,
> > > filterChain=FilterChain[filters=[GridNioCodecFilter
> > > [parser=o.a.i.i.util.nio.GridDirectParser@375e6c31, directMode=true],
> > > GridConnectionBytesVerifyFilter], accepted=true]],
> > > super=GridAbstractCommunicationClient [lastUsed=1487259926138,
> > > reserves=0]]]
> > >
> > >    40090 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-2-#11%webapp%]
> > > >> Selector info [idx=2, keysCnt=0]
> > >
> > >    40091 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-0-#9%webapp%]
> > > >> Selector info [idx=0, keysCnt=1]
> > >     Connection info [rmtAddr=/192.168.0.53:33596, locAddr=/
> > > 192.168.0.53:47100, msgsSent=272, msgsAckedByRmt=272, msgsRcvd=272,
> > > descIdHash=703751156, bytesRcvd=1172506, bytesSent=13367,
> opQueueSize=0,
> > > msgWriter=DirectMessageWriter [state=DirectMessageState [pos=0,
> > > stack=[StateItem [stream=DirectByteBufferStreamImplV2
> > > [buf=java.nio.DirectByteBuffer[pos=0 lim=32768 cap=32768],
> > > baseOff=140318527729152, 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=140318527729152, 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=140318527729152, 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=140318527729152, 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=140318527761936, 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=140318527761936, 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=140318527761936, 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]]
> > >
> > >    40091 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-1-#10%webapp%]
> > > >> Selector info [idx=1, keysCnt=0]
> > >
> > >    40091 W o.a.i.s.c.tcp.TcpCommunicationSpi
> > > [grid-nio-worker-3-#12%webapp%]
> > > >> Selector info [idx=3, keysCnt=0]
> > >
> > >
> > >
> > >
> > > On Thu, 16 Feb 2017 at 22:05 Andrey Mashenkov <
> > andrey.mashenkov@gmail.com>
> > > wrote:
> > >
> > > Hi Cameron,
> > >
> > > Ignite does not have 1.8.x versions.
> > >
> > > It look like you use IPv6 on some of you nodes.
> > > At first, check if either -Djava.net.preferIPv6Addresses=true or
> > > -Djava.net.preferIPv4Addresses=true java option is set for all of your
> > > nodes
> > > and communication port is set properly.
> > >
> > > On Thu, Feb 16, 2017 at 1:29 AM, Cameron Braid <cameron@braid.com.au>
> > > wrote:
> > >
> > > > Hi,
> > > >
> > > > I am getting the following error in Ignite version 1.8.1 :
> > > >
> > > > "Failed to wait for partition release future"
> > > >
> > > > The related logs lines are at the bottom.
> > > >
> > > > I was curious if it could be related to
> > > > https://issues.apache.org/jira/browse/IGNITE-3212 which has fix for
> > > > version
> > > > 1.9.  Could this be the case ?
> > > >
> > > > Otherwise, is this likely to be a bug in ignite, or something
> specific
> > to
> > > > my environment?
> > > >
> > > > Cheers
> > > >
> > > > Cameron
> > > >
> > > >
> > > >    - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287661 WARN
> > > >    o.a.i.i.p.c.d.d.p.GridDhtPartitionsExchangeFuture
> > > >    [exchange-worker-#26%webapp%] Failed to wait for partition release
> > > > future
> > > >    [topVer=AffinityTopologyVersion [topVer=21, minorTopVer=2],
> > > >    node=79d74dfa-9903-42e3-af94-524ab08c1f97]. Dumping pending
> objects
> > > > that
> > > >    might be the cause:
> > > >    - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287661 WARN
> > > >    o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > >    [exchange-worker-#26%webapp%] Ready affinity version:
> > > >    AffinityTopologyVersion [topVer=21, minorTopVer=1]
> > > >    - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287667 WARN
> > > >    o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > >    [exchange-worker-#26%webapp%] Last exchange future:
> > > >    GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> > > >    reassign=false, discoEvt=DiscoveryCustomEvent
> > > >    [customMsg=DynamicCacheChangeBatch [reqs=[
> DynamicCacheChangeRequest
> > > >    [deploymentId=3f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9,
> > > >    startCfg=CacheConfiguration [name=userTable.
> cmsDataVehicles.query,
> > > >    storeConcurrentLoadAllThreshold=5, rebalancePoolSize=2,
> > > >    rebalanceTimeout=10000, evictPlc=null, evictSync=false,
> > > >    evictKeyBufSize=1024, evictSyncConcurrencyLvl=4,
> > > evictSyncTimeout=10000,
> > > >    evictFilter=null, evictMaxOverflowRatio=10.0, eagerTtl=true,
> > > >    dfltLockTimeout=0, startSize=1500000, nearCfg=null,
> > > > writeSync=PRIMARY_SYNC,
> > > >    storeFactory=null, storeKeepBinary=false, loadPrevVal=false,
> > > >    aff=o.a.i.cache.affinity.rendezvous.RendezvousAffinityFunction@
> > > 7e1c4f4,
> > > >    cacheMode=REPLICATED, atomicityMode=ATOMIC,
> > > > atomicWriteOrderMode=PRIMARY,
> > > >    backups=2147483647 <(214)%20748-3647> <(214)%20748-3647>,
> > invalidate=false,
> > > tmLookupClsName=null,
> > > >    rebalanceMode=ASYNC, rebalanceOrder=0, rebalanceBatchSize=524288,
> > > >    rebalanceBatchesPrefetchCount=2, offHeapMaxMem=-1,
> > swapEnabled=false,
> > > >    maxConcurrentAsyncOps=500, writeBehindEnabled=false,
> > > >    writeBehindFlushSize=10240, writeBehindFlushFreq=5000,
> > > >    writeBehindFlushThreadCnt=1, writeBehindBatchSize=512,
> > > > maxQryIterCnt=1024,
> > > >    memMode=ONHEAP_TIERED,
> > > >    affMapper=o.a.i.i.processors.cache.CacheDefaultBinaryAffinityKeyM
> > > > apper@6ca896dd,
> > > >    rebalanceDelay=0, rebalanceThrottle=0, interceptor=null,
> > > >    longQryWarnTimeout=3000, qryDetailMetricsSz=0,
> readFromBackup=true,
> > > >    nodeFilter=o.a.i.configuration.CacheConfiguration$
> > > > IgniteAllNodesPredicate@db2015b,
> > > >    sqlSchema=null, sqlEscapeAll=false, sqlOnheapRowCacheSize=10240,
> > > >    snapshotableIdx=false, cpOnRead=true, topValidator=null],
> > > > cacheType=USER,
> > > >    initiatingNodeId=79d74dfa-9903-42e3-af94-524ab08c1f97,
> > > > nearCacheCfg=null,
> > > >    clientStartOnly=false, stop=false, close=false, failIfExists=true,
> > > >    template=false, rcvdFrom=null, exchangeNeeded=true,
> > > cacheFutTopVer=null,
> > > >    cacheName=userTable.cmsDataVehicles.query]], clientNodes=null,
> > > >    id=4f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9,
> > > >    clientReconnect=false], affTopVer=AffinityTopologyVersion
> > [topVer=21,
> > > >    minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> > > >    [id=79d74dfa-9903-42e3-af94-524ab08c1f97,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/
> > 10.130.1.43:47500
> > > ,
> > > >    /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500,
> > > order=21,
> > > >    intOrder=12, lastExchangeTime=1487193806549, loc=true,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=21,
> > > >    nodeId8=79d74dfa, msg=null, type=DISCOVERY_CUSTOM_EVT,
> > > >    tstamp=1487193798024]], crd=TcpDiscoveryNode
> > > >    [id=659ea029-ca80-4413-af47-67b446ffd3e7,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /
> > > >    127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18,
> > > >    intOrder=10, lastExchangeTime=1487178534506, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> > > >    exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> > > >    [topVer=21, minorTopVer=2], nodeId=79d74dfa,
> > > evt=DISCOVERY_CUSTOM_EVT],
> > > >    added=true, initFut=GridFutureAdapter [resFlag=0, res=null,
> > > >    startTime=1487193798024, endTime=0, ignoreInterrupts=false,
> > > state=INIT],
> > > >    init=false, topSnapshot=null, lastVer=null,
> > > >    partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
> > lsnrCalls=3,
> > > >    done=false, cancelled=false, err=null, futs=[true, true, false,
> > > true]],
> > > >    affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
> > > >    initTs=1487193798024, centralizedAff=false, evtLatch=0,
> > > >    remaining=[0940d968-a901-4c78-8354-8171628d41aa,
> > > >    659ea029-ca80-4413-af47-67b446ffd3e7], srvNodes=[TcpDiscoveryNode
> > > >    [id=659ea029-ca80-4413-af47-67b446ffd3e7,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /
> > > >    127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18,
> > > >    intOrder=10, lastExchangeTime=1487178534506, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> TcpDiscoveryNode
> > > >    [id=0940d968-a901-4c78-8354-8171628d41aa,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500,
> > > >    /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500,
> > > order=20,
> > > >    intOrder=11, lastExchangeTime=1487178534516, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> TcpDiscoveryNode
> > > >    [id=79d74dfa-9903-42e3-af94-524ab08c1f97,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/
> > 10.130.1.43:47500
> > > ,
> > > >    /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500,
> > > order=21,
> > > >    intOrder=12, lastExchangeTime=1487193806549, loc=true,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]],
> > > > super=GridFutureAdapter
> > > >    [resFlag=0, res=null, startTime=1487193798024, endTime=0,
> > > >    ignoreInterrupts=false, state=INIT]]
> > > >    - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287667 WARN
> > > >    o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > >    [exchange-worker-#26%webapp%] Pending exchange futures:
> > > >    - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287668 WARN
> > > >    o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > >    [exchange-worker-#26%webapp%] Last 10 exchange futures (total: 3):
> > > >    - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287668 WARN
> > > >    o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > >    [exchange-worker-#26%webapp%] >>> GridDhtPartitionsExchangeFuture
> > > >    [dummy=false, forcePreload=false, reassign=false,
> > > >    discoEvt=DiscoveryCustomEvent [customMsg=DynamicCacheChangeBatch
> > > >    [reqs=[DynamicCacheChangeRequest
> > > >    [deploymentId=3f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9,
> > > >    startCfg=CacheConfiguration [name=userTable.
> cmsDataVehicles.query,
> > > >    storeConcurrentLoadAllThreshold=5, rebalancePoolSize=2,
> > > >    rebalanceTimeout=10000, evictPlc=null, evictSync=false,
> > > >    evictKeyBufSize=1024, evictSyncConcurrencyLvl=4,
> > > evictSyncTimeout=10000,
> > > >    evictFilter=null, evictMaxOverflowRatio=10.0, eagerTtl=true,
> > > >    dfltLockTimeout=0, startSize=1500000, nearCfg=null,
> > > > writeSync=PRIMARY_SYNC,
> > > >    storeFactory=null, storeKeepBinary=false, loadPrevVal=false,
> > > >    aff=o.a.i.cache.affinity.rendezvous.RendezvousAffinityFunction@
> > > 7e1c4f4,
> > > >    cacheMode=REPLICATED, atomicityMode=ATOMIC,
> > > > atomicWriteOrderMode=PRIMARY,
> > > >    backups=2147483647 <(214)%20748-3647> <(214)%20748-3647>,
> > invalidate=false,
> > > tmLookupClsName=null,
> > > >    rebalanceMode=ASYNC, rebalanceOrder=0, rebalanceBatchSize=524288,
> > > >    rebalanceBatchesPrefetchCount=2, offHeapMaxMem=-1,
> > swapEnabled=false,
> > > >    maxConcurrentAsyncOps=500, writeBehindEnabled=false,
> > > >    writeBehindFlushSize=10240, writeBehindFlushFreq=5000,
> > > >    writeBehindFlushThreadCnt=1, writeBehindBatchSize=512,
> > > > maxQryIterCnt=1024,
> > > >    memMode=ONHEAP_TIERED,
> > > >    affMapper=o.a.i.i.processors.cache.CacheDefaultBinaryAffinityKeyM
> > > > apper@6ca896dd,
> > > >    rebalanceDelay=0, rebalanceThrottle=0, interceptor=null,
> > > >    longQryWarnTimeout=3000, qryDetailMetricsSz=0,
> readFromBackup=true,
> > > >    nodeFilter=o.a.i.configuration.CacheConfiguration$
> > > > IgniteAllNodesPredicate@db2015b,
> > > >    sqlSchema=null, sqlEscapeAll=false, sqlOnheapRowCacheSize=10240,
> > > >    snapshotableIdx=false, cpOnRead=true, topValidator=null],
> > > > cacheType=USER,
> > > >    initiatingNodeId=79d74dfa-9903-42e3-af94-524ab08c1f97,
> > > > nearCacheCfg=null,
> > > >    clientStartOnly=false, stop=false, close=false, failIfExists=true,
> > > >    template=false, rcvdFrom=null, exchangeNeeded=true,
> > > cacheFutTopVer=null,
> > > >    cacheName=userTable.cmsDataVehicles.query]], clientNodes=null,
> > > >    id=4f757f24a51-ee74fcc5-5cea-4548-9cd6-8a201c29fdf9,
> > > >    clientReconnect=false], affTopVer=AffinityTopologyVersion
> > [topVer=21,
> > > >    minorTopVer=2], super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> > > >    [id=79d74dfa-9903-42e3-af94-524ab08c1f97,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/
> > 10.130.1.43:47500
> > > ,
> > > >    /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500,
> > > order=21,
> > > >    intOrder=12, lastExchangeTime=1487193806549, loc=true,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=21,
> > > >    nodeId8=79d74dfa, msg=null, type=DISCOVERY_CUSTOM_EVT,
> > > >    tstamp=1487193798024]], crd=TcpDiscoveryNode
> > > >    [id=659ea029-ca80-4413-af47-67b446ffd3e7,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /
> > > >    127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18,
> > > >    intOrder=10, lastExchangeTime=1487178534506, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> > > >    exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> > > >    [topVer=21, minorTopVer=2], nodeId=79d74dfa,
> > > evt=DISCOVERY_CUSTOM_EVT],
> > > >    added=true, initFut=GridFutureAdapter [resFlag=0, res=null,
> > > >    startTime=1487193798024, endTime=0, ignoreInterrupts=false,
> > > state=INIT],
> > > >    init=false, topSnapshot=null, lastVer=null,
> > > >    partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
> > lsnrCalls=3,
> > > >    done=false, cancelled=false, err=null, futs=[true, true, false,
> > > true]],
> > > >    affChangeMsg=null, skipPreload=false, clientOnlyExchange=false,
> > > >    initTs=1487193798024, centralizedAff=false, evtLatch=0,
> > > >    remaining=[0940d968-a901-4c78-8354-8171628d41aa,
> > > >    659ea029-ca80-4413-af47-67b446ffd3e7], srvNodes=[TcpDiscoveryNode
> > > >    [id=659ea029-ca80-4413-af47-67b446ffd3e7,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /
> > > >    127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18,
> > > >    intOrder=10, lastExchangeTime=1487178534506, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> TcpDiscoveryNode
> > > >    [id=0940d968-a901-4c78-8354-8171628d41aa,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500,
> > > >    /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500,
> > > order=20,
> > > >    intOrder=11, lastExchangeTime=1487178534516, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> TcpDiscoveryNode
> > > >    [id=79d74dfa-9903-42e3-af94-524ab08c1f97,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.130.1.43, 127.0.0.1], sockAddrs=[webapp-92-50ik3/
> > 10.130.1.43:47500
> > > ,
> > > >    /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500,
> > > order=21,
> > > >    intOrder=12, lastExchangeTime=1487193806549, loc=true,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false]],
> > > > super=GridFutureAdapter
> > > >    [resFlag=0, res=null, startTime=1487193798024, endTime=0,
> > > >    ignoreInterrupts=false, state=INIT]]
> > > >    - Feb 16 08:23:28 webapp-92-50ik3 webapp 15287669 WARN
> > > >    o.a.i.i.p.c.GridCachePartitionExchangeManager
> > > >    [exchange-worker-#26%webapp%] >>> GridDhtPartitionsExchangeFuture
> > > >    [dummy=false, forcePreload=false, reassign=false,
> > > >    discoEvt=DiscoveryCustomEvent [customMsg=null,
> > > >    affTopVer=AffinityTopologyVersion [topVer=21, minorTopVer=1],
> > > >    super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> > > >    [id=659ea029-ca80-4413-af47-67b446ffd3e7,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /
> > > >    127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18,
> > > >    intOrder=10, lastExchangeTime=1487178534506, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false], topVer=21,
> > > >    nodeId8=79d74dfa, msg=null, type=DISCOVERY_CUSTOM_EVT,
> > > >    tstamp=1487178539604]], crd=TcpDiscoveryNode
> > > >    [id=659ea029-ca80-4413-af47-67b446ffd3e7,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /
> > > >    127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18,
> > > >    intOrder=10, lastExchangeTime=1487178534506, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> > > >    exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion
> > > >    [topVer=21, minorTopVer=1], nodeId=659ea029,
> > > evt=DISCOVERY_CUSTOM_EVT],
> > > >    added=true, initFut=GridFutureAdapter [resFlag=2, res=true,
> > > >    startTime=1487178539604, endTime=1487178539762,
> > > ignoreInterrupts=false,
> > > >    state=DONE], init=true, topSnapshot=null, lastVer=null,
> > > >    partReleaseFut=GridCompoundFuture [rdc=null, initFlag=1,
> > lsnrCalls=4,
> > > >    done=true, cancelled=false, err=null, futs=[true, true, true,
> > true]],
> > > >    affChangeMsg=CacheAffinityChangeMessage
> > > >    [id=426bdb24a51-0943897a-92a2-454f-8ce0-2cfc43f893df,
> > > >    topVer=AffinityTopologyVersion [topVer=21, minorTopVer=0],
> > > exchId=null,
> > > >    partsMsg=null, exchangeNeeded=true], skipPreload=false,
> > > >    clientOnlyExchange=false, initTs=1487178539604,
> > centralizedAff=false,
> > > >    evtLatch=0, remaining=[0940d968-a901-4c78-8354-8171628d41aa,
> > > >    659ea029-ca80-4413-af47-67b446ffd3e7], srvNodes=[TcpDiscoveryNode
> > > >    [id=659ea029-ca80-4413-af47-67b446ffd3e7,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.128.1.11, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1%lo:47500, /
> > > >    127.0.0.1:47500, /10.128.1.11:47500], discPort=47500, order=18,
> > > >    intOrder=10, lastExchangeTime=1487178534506, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> TcpDiscoveryNode
> > > >    [id=0940d968-a901-4c78-8354-8171628d41aa,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.129.1.129, 127.0.0.1], sockAddrs=[/10.129.1.129:47500,
> > > >    /0:0:0:0:0:0:0:1%lo:47500, /127.0.0.1:47500], discPort=47500,
> > > order=20,
> > > >    intOrder=11, lastExchangeTime=1487178534516, loc=false,
> > > >    ver=1.8.1#20161208-sha1:a8fcb7b2, isClient=false],
> TcpDiscoveryNode
> > > >    [id=79d74dfa-9903-42e3-af94-524ab08c1f97,
> addrs=[0:0:0:0:0:0:0:1%lo,
> > > >    10.130.1.43, 127.0.0.1], sockAd...
>
> [Message clipped]




-- 
Best regards,
Andrey V. Mashenkov

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message