You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Sergey Kozlov (JIRA)" <ji...@apache.org> on 2015/06/02 16:30:18 UTC
[jira] [Updated] (IGNITE-981) NPE in GridDhtPartitionDemandPool
[ https://issues.apache.org/jira/browse/IGNITE-981?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sergey Kozlov updated IGNITE-981:
---------------------------------
Description:
I following scenario (in IDEA):
1. Start node via ExampleNodeStartup
2. Start node via CacheClientDiscoStartStopClientNodeExample (see attached files). It start server node and then creates and drops the cache in loop.
3. Start node via CacheClientDiscoStartStopCacheExample (see attached files). It starts and stops client node in loop.
1st node output
{noformat}
[17:09:04] Topology snapshot [ver=1, nodes=1, CPUs=8, heap=1.0GB]
[17:09:48] Topology snapshot [ver=2, nodes=2, CPUs=8, heap=2.8GB]
[17:10:05,048][ERROR][preloader-demand-worker-#581%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1480700191, interrupted=true, runner=preloader-demand-worker-#581%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:05,063][ERROR][preloader-demand-worker-#580%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=57144460, interrupted=true, runner=preloader-demand-worker-#580%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:05,327][ERROR][preloader-demand-worker-#591%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1362442118, interrupted=true, runner=preloader-demand-worker-#591%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:05,334][ERROR][preloader-demand-worker-#590%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1122922196, interrupted=true, runner=preloader-demand-worker-#590%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:06,864][ERROR][preloader-demand-worker-#645%null%][GridDhtPartitionDemandPool] <server_cache116> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=231], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=231], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=476077678, interrupted=true, runner=preloader-demand-worker-#645%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:17] Topology snapshot [ver=3, nodes=3, CPUs=8, heap=3.8GB]
[17:10:18] Topology snapshot [ver=4, nodes=2, CPUs=8, heap=2.8GB]
[17:10:22] Topology snapshot [ver=5, nodes=3, CPUs=8, heap=3.8GB]
[17:10:23] Topology snapshot [ver=6, nodes=2, CPUs=8, heap=2.8GB]
[17:10:27] Topology snapshot [ver=7, nodes=3, CPUs=8, heap=3.8GB]
[17:10:28] Topology snapshot [ver=8, nodes=2, CPUs=8, heap=2.8GB]
[17:10:33] Topology snapshot [ver=9, nodes=3, CPUs=8, heap=3.8GB]
[17:10:33] Topology snapshot [ver=10, nodes=2, CPUs=8, heap=2.8GB]
[17:10:36] Topology snapshot [ver=11, nodes=3, CPUs=8, heap=3.8GB]
[17:10:36] Topology snapshot [ver=12, nodes=2, CPUs=8, heap=2.8GB]
[17:10:37] Topology snapshot [ver=13, nodes=3, CPUs=8, heap=3.8GB]
[17:10:37] Topology snapshot [ver=14, nodes=2, CPUs=8, heap=2.8GB]
[17:10:39] Topology snapshot [ver=15, nodes=3, CPUs=8, heap=3.8GB]
[17:10:39] Topology snapshot [ver=16, nodes=2, CPUs=8, heap=2.8GB]
[17:10:39] Topology snapshot [ver=17, nodes=3, CPUs=8, heap=3.8GB]
[17:10:39] Topology snapshot [ver=18, nodes=2, CPUs=8, heap=2.8GB]
[17:10:43] Topology snapshot [ver=19, nodes=3, CPUs=8, heap=3.8GB]
[17:10:43] (err) Failed to notify listener: o.a.i.i.processors.cache.GridCachePartitionExchangeManager$5@3287f0e2java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtPartitionTopologyImpl.partitionMap(GridDhtPartitionTopologyImpl.java:747)
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.sendAllPartitions(GridDhtPartitionsExchangeFuture.java:906)
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceive(GridDhtPartitionsExchangeFuture.java:1066)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:883)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:880)
at org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:241)
at org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:204)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processSinglePartitionUpdate(GridCachePartitionExchangeManager.java:880)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.access$1100(GridCachePartitionExchangeManager.java:57)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:223)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:221)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1255)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1237)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:531)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:235)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:158)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$000(GridCacheIoManager.java:48)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:127)
at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:690)
at org.apache.ignite.internal.managers.communication.GridIoManager.access$1500(GridIoManager.java:58)
at org.apache.ignite.internal.managers.communication.GridIoManager$5.run(GridIoManager.java:653)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
[17:10:43,319][ERROR][ignite-#21%sys-null%][GridCacheIoManager] Failed processing message [senderId=6e82392b-8c49-496b-9ffe-ae3e2be27459, msg=GridDhtPartitionsSingleMessage [parts={-2100569601=GridDhtPartitionMap [nodeId=6e82392b-8c49-496b-9ffe-ae3e2be27459, updateSeq=1, size=0], 689859866=GridDhtPartitionMap [nodeId=6e82392b-8c49-496b-9ffe-ae3e2be27459, updateSeq=1, size=0], 1325947219=GridDhtPartitionMap [nodeId=6e82392b-8c49-496b-9ffe-ae3e2be27459, updateSeq=1, size=0]}, client=true, super=GridDhtPartitionsAbstractMessage [exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], lastVer=GridCacheVersion [topVer=0, nodeOrderDrId=0, globalTime=0, order=1433254241119], super=GridCacheMessage [msgId=30, depInfo=null, err=null, skipPrepare=false]]]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtPartitionTopologyImpl.partitionMap(GridDhtPartitionTopologyImpl.java:747)
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.sendAllPartitions(GridDhtPartitionsExchangeFuture.java:906)
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceive(GridDhtPartitionsExchangeFuture.java:1066)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:883)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:880)
at org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:241)
at org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:204)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processSinglePartitionUpdate(GridCachePartitionExchangeManager.java:880)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.access$1100(GridCachePartitionExchangeManager.java:57)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:223)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:221)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1255)
at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1237)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:531)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:235)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:158)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$000(GridCacheIoManager.java:48)
at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:127)
at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:690)
at org.apache.ignite.internal.managers.communication.GridIoManager.access$1500(GridIoManager.java:58)
at org.apache.ignite.internal.managers.communication.GridIoManager$5.run(GridIoManager.java:653)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
[17:11:04,117][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License bursting ==> Maximum number of nodes (2) is exceeded.
[17:11:04,117][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] ^-- Contact sales@gridgain.com for further assistance. Make sure to include your license ID: 14177F1A-5B5A-4F9C-BC55-F7335715F311
[17:11:04,117][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License grace/burst period - left 1 hour.
[17:12:04,115][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License grace/burst period - left 59 mins.
[17:13:04,116][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License grace/burst period - left 58 mins.
[17:13:32] Topology snapshot [ver=20, nodes=2, CPUs=8, heap=2.0GB]
[17:13:33] Topology snapshot [ver=21, nodes=1, CPUs=8, heap=1.0GB]
{noformat}
2nd node output:
{noformat}
131 msec, Iteration 10
510 msec, Iteration 20
611 msec, Iteration 30
690 msec, Iteration 40
416 msec, Iteration 50
548 msec, Iteration 60
560 msec, Iteration 70
345 msec, Iteration 80
400 msec, Iteration 90
506 msec, Iteration 100
[17:10:04,985][ERROR][preloader-demand-worker-#580%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=207259141, interrupted=true, runner=preloader-demand-worker-#580%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:04,986][ERROR][preloader-demand-worker-#579%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1273481579, interrupted=true, runner=preloader-demand-worker-#579%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:05,328][ERROR][preloader-demand-worker-#590%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1515054848, interrupted=true, runner=preloader-demand-worker-#590%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
[17:10:05,342][ERROR][preloader-demand-worker-#589%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1925032748, interrupted=true, runner=preloader-demand-worker-#589%null%]]
java.lang.NullPointerException
at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
at java.lang.Thread.run(Thread.java:745)
851 msec, Iteration 110
441 msec, Iteration 120
407 msec, Iteration 130
374 msec, Iteration 140
288 msec, Iteration 150
267 msec, Iteration 160
293 msec, Iteration 170
272 msec, Iteration 180
279 msec, Iteration 190
320 msec, Iteration 200
[17:10:17] Topology snapshot [ver=3, nodes=3, CPUs=8, heap=3.8GB]
[17:10:18] Topology snapshot [ver=4, nodes=2, CPUs=8, heap=2.8GB]
507 msec, Iteration 210
282 msec, Iteration 220
275 msec, Iteration 230
310 msec, Iteration 240
[17:10:22] Topology snapshot [ver=5, nodes=3, CPUs=8, heap=3.8GB]
[17:10:23] Topology snapshot [ver=6, nodes=2, CPUs=8, heap=2.8GB]
{noformat}
3rd node output:
{noformat}
[17:11:13,308][WARN ][main][GridCachePartitionExchangeManager] Failed to wait for initial partition map exchange. Possible reasons are:
^-- Transactions in deadlock.
^-- Long running transactions (ignore if this is the case).
^-- Unreleased explicit locks.
[17:11:43,312][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
[17:12:13,313][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
[17:12:43,313][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
[17:13:13,315][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
[17:13:32,184][WARN ][disco-event-worker-#462%null%][GridDiscoveryManager] Node FAILED: TcpDiscoveryNode [id=3bb3b6d0-edcf-464e-ae15-e83b51368e11, addrs=[192.168.56.1, 127.0.0.1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 0:0:0:0:0:0:0:1], sockAddrs=[rr/192.168.56.1:47501, /192.168.56.1:47501, /127.0.0.1:47501, rr/192.168.56.1:47501, /2001:db8:85a3:0:0:8a2e:370:7334:47501, rr/192.168.56.1:47501, /10.0.0.5:47501, /0:0:0:0:0:0:0:1:47501], discPort=47501, order=2, intOrder=2, loc=false, ver=1.1.1#20150602-sha1:82cfb47c, isClient=false]
[17:13:32,188][INFO ][disco-event-worker-#462%null%][GridDiscoveryManager] Topology snapshot [ver=20, nodes=2, CPUs=8, heap=2.0GB]
{noformat}
was:
I following scenario (in IDEA):
1. Start node via ExampleNodeStartup
2. Start node via CacheClientDiscoStartStopClientNodeExample (see attached files). It start server node and then creates and drops the cache in loop.
3. Start node via CacheClientDiscoStartStopCacheExample (see attached files). It starts and stops client node in loop.
> NPE in GridDhtPartitionDemandPool
> ---------------------------------
>
> Key: IGNITE-981
> URL: https://issues.apache.org/jira/browse/IGNITE-981
> Project: Ignite
> Issue Type: Bug
> Components: general
> Affects Versions: sprint-5
> Reporter: Sergey Kozlov
> Assignee: Semen Boikov
> Priority: Critical
> Fix For: sprint-5
>
>
> I following scenario (in IDEA):
> 1. Start node via ExampleNodeStartup
> 2. Start node via CacheClientDiscoStartStopClientNodeExample (see attached files). It start server node and then creates and drops the cache in loop.
> 3. Start node via CacheClientDiscoStartStopCacheExample (see attached files). It starts and stops client node in loop.
> 1st node output
> {noformat}
> [17:09:04] Topology snapshot [ver=1, nodes=1, CPUs=8, heap=1.0GB]
> [17:09:48] Topology snapshot [ver=2, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:05,048][ERROR][preloader-demand-worker-#581%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1480700191, interrupted=true, runner=preloader-demand-worker-#581%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:05,063][ERROR][preloader-demand-worker-#580%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=57144460, interrupted=true, runner=preloader-demand-worker-#580%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:05,327][ERROR][preloader-demand-worker-#591%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1362442118, interrupted=true, runner=preloader-demand-worker-#591%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:05,334][ERROR][preloader-demand-worker-#590%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1122922196, interrupted=true, runner=preloader-demand-worker-#590%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:06,864][ERROR][preloader-demand-worker-#645%null%][GridDhtPartitionDemandPool] <server_cache116> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=231], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=231], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=476077678, interrupted=true, runner=preloader-demand-worker-#645%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:17] Topology snapshot [ver=3, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:18] Topology snapshot [ver=4, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:22] Topology snapshot [ver=5, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:23] Topology snapshot [ver=6, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:27] Topology snapshot [ver=7, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:28] Topology snapshot [ver=8, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:33] Topology snapshot [ver=9, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:33] Topology snapshot [ver=10, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:36] Topology snapshot [ver=11, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:36] Topology snapshot [ver=12, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:37] Topology snapshot [ver=13, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:37] Topology snapshot [ver=14, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:39] Topology snapshot [ver=15, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:39] Topology snapshot [ver=16, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:39] Topology snapshot [ver=17, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:39] Topology snapshot [ver=18, nodes=2, CPUs=8, heap=2.8GB]
> [17:10:43] Topology snapshot [ver=19, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:43] (err) Failed to notify listener: o.a.i.i.processors.cache.GridCachePartitionExchangeManager$5@3287f0e2java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtPartitionTopologyImpl.partitionMap(GridDhtPartitionTopologyImpl.java:747)
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.sendAllPartitions(GridDhtPartitionsExchangeFuture.java:906)
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceive(GridDhtPartitionsExchangeFuture.java:1066)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:883)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:880)
> at org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:241)
> at org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:204)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processSinglePartitionUpdate(GridCachePartitionExchangeManager.java:880)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.access$1100(GridCachePartitionExchangeManager.java:57)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:223)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:221)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1255)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1237)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:531)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:235)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:158)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$000(GridCacheIoManager.java:48)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:127)
> at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:690)
> at org.apache.ignite.internal.managers.communication.GridIoManager.access$1500(GridIoManager.java:58)
> at org.apache.ignite.internal.managers.communication.GridIoManager$5.run(GridIoManager.java:653)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:43,319][ERROR][ignite-#21%sys-null%][GridCacheIoManager] Failed processing message [senderId=6e82392b-8c49-496b-9ffe-ae3e2be27459, msg=GridDhtPartitionsSingleMessage [parts={-2100569601=GridDhtPartitionMap [nodeId=6e82392b-8c49-496b-9ffe-ae3e2be27459, updateSeq=1, size=0], 689859866=GridDhtPartitionMap [nodeId=6e82392b-8c49-496b-9ffe-ae3e2be27459, updateSeq=1, size=0], 1325947219=GridDhtPartitionMap [nodeId=6e82392b-8c49-496b-9ffe-ae3e2be27459, updateSeq=1, size=0]}, client=true, super=GridDhtPartitionsAbstractMessage [exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], lastVer=GridCacheVersion [topVer=0, nodeOrderDrId=0, globalTime=0, order=1433254241119], super=GridCacheMessage [msgId=30, depInfo=null, err=null, skipPrepare=false]]]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtPartitionTopologyImpl.partitionMap(GridDhtPartitionTopologyImpl.java:747)
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.sendAllPartitions(GridDhtPartitionsExchangeFuture.java:906)
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onReceive(GridDhtPartitionsExchangeFuture.java:1066)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:883)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$5.apply(GridCachePartitionExchangeManager.java:880)
> at org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:241)
> at org.apache.ignite.internal.util.future.GridFutureAdapter.listen(GridFutureAdapter.java:204)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.processSinglePartitionUpdate(GridCachePartitionExchangeManager.java:880)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager.access$1100(GridCachePartitionExchangeManager.java:57)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:223)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$2.onMessage(GridCachePartitionExchangeManager.java:221)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1255)
> at org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$MessageHandler.apply(GridCachePartitionExchangeManager.java:1237)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:531)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:235)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:158)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$000(GridCacheIoManager.java:48)
> at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:127)
> at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:690)
> at org.apache.ignite.internal.managers.communication.GridIoManager.access$1500(GridIoManager.java:58)
> at org.apache.ignite.internal.managers.communication.GridIoManager$5.run(GridIoManager.java:653)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> [17:11:04,117][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License bursting ==> Maximum number of nodes (2) is exceeded.
> [17:11:04,117][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] ^-- Contact sales@gridgain.com for further assistance. Make sure to include your license ID: 14177F1A-5B5A-4F9C-BC55-F7335715F311
> [17:11:04,117][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License grace/burst period - left 1 hour.
> [17:12:04,115][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License grace/burst period - left 59 mins.
> [17:13:04,116][ERROR][ignite-license-checker-null][GridEntLicenseProcessor] License grace/burst period - left 58 mins.
> [17:13:32] Topology snapshot [ver=20, nodes=2, CPUs=8, heap=2.0GB]
> [17:13:33] Topology snapshot [ver=21, nodes=1, CPUs=8, heap=1.0GB]
> {noformat}
> 2nd node output:
> {noformat}
> 131 msec, Iteration 10
> 510 msec, Iteration 20
> 611 msec, Iteration 30
> 690 msec, Iteration 40
> 416 msec, Iteration 50
> 548 msec, Iteration 60
> 560 msec, Iteration 70
> 345 msec, Iteration 80
> 400 msec, Iteration 90
> 506 msec, Iteration 100
> [17:10:04,985][ERROR][preloader-demand-worker-#580%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=207259141, interrupted=true, runner=preloader-demand-worker-#580%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:04,986][ERROR][preloader-demand-worker-#579%null%][GridDhtPartitionDemandPool] <server_cache103> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=205], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1273481579, interrupted=true, runner=preloader-demand-worker-#579%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:05,328][ERROR][preloader-demand-worker-#590%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=1, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1515054848, interrupted=true, runner=preloader-demand-worker-#590%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> [17:10:05,342][ERROR][preloader-demand-worker-#589%null%][GridDhtPartitionDemandPool] <server_cache105> Runtime error caught during grid runnable execution: DemandWorker [id=0, cntr=0, assignQ=[GridDhtPreloaderAssignments [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=2, minorTopVer=209], nodeId=3bb3b6d0, evt=DISCOVERY_CUSTOM_EVT], super={}]], msgQ=[SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null], SupplyMessage [sndId=null, supply=null]], super=GridWorker [name=preloader-demand-worker, gridName=null, finished=false, isCancelled=true, hashCode=1925032748, interrupted=true, runner=preloader-demand-worker-#589%null%]]
> java.lang.NullPointerException
> at org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemandPool$DemandWorker.body(GridDhtPartitionDemandPool.java:822)
> at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:108)
> at java.lang.Thread.run(Thread.java:745)
> 851 msec, Iteration 110
> 441 msec, Iteration 120
> 407 msec, Iteration 130
> 374 msec, Iteration 140
> 288 msec, Iteration 150
> 267 msec, Iteration 160
> 293 msec, Iteration 170
> 272 msec, Iteration 180
> 279 msec, Iteration 190
> 320 msec, Iteration 200
> [17:10:17] Topology snapshot [ver=3, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:18] Topology snapshot [ver=4, nodes=2, CPUs=8, heap=2.8GB]
> 507 msec, Iteration 210
> 282 msec, Iteration 220
> 275 msec, Iteration 230
> 310 msec, Iteration 240
> [17:10:22] Topology snapshot [ver=5, nodes=3, CPUs=8, heap=3.8GB]
> [17:10:23] Topology snapshot [ver=6, nodes=2, CPUs=8, heap=2.8GB]
> {noformat}
> 3rd node output:
> {noformat}
> [17:11:13,308][WARN ][main][GridCachePartitionExchangeManager] Failed to wait for initial partition map exchange. Possible reasons are:
> ^-- Transactions in deadlock.
> ^-- Long running transactions (ignore if this is the case).
> ^-- Unreleased explicit locks.
> [17:11:43,312][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
> [17:12:13,313][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
> [17:12:43,313][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
> [17:13:13,315][WARN ][main][GridCachePartitionExchangeManager] Still waiting for initial partition map exchange [fut=GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false, reassign=false, discoEvt=DiscoveryEvent [evtNode=TcpDiscoveryNode [id=6e82392b-8c49-496b-9ffe-ae3e2be27459, addrs=[0:0:0:0:0:0:0:1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 192.168.56.1, 127.0.0.1], sockAddrs=[/0:0:0:0:0:0:0:1:0, rr/192.168.56.1:0, /2001:db8:85a3:0:0:8a2e:370:7334:0, rr/192.168.56.1:0, /10.0.0.5:0, rr/192.168.56.1:0, /192.168.56.1:0, /127.0.0.1:0], discPort=0, order=19, intOrder=0, loc=true, ver=1.1.1#20150602-sha1:82cfb47c, isClient=true], topVer=19, nodeId8=6e82392b, msg=null, type=NODE_JOINED, tstamp=1433254243272], rcvdIds=GridConcurrentHashSet [elements=[]], rmtIds=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=19, minorTopVer=0], nodeId=6e82392b, evt=NODE_JOINED], init=true, ready=true, replied=false, added=true, initFut=GridFutureAdapter [resFlag=2, res=true, startTime=1433254243303, endTime=1433254243313, ignoreInterrupts=false, lsnr=null, state=DONE], topSnapshot=null, lastVer=null, partReleaseFut=null, skipPreload=true, oldest=8da532ad-56a4-473d-9ada-0b24cf074fd1, oldestOrder=1, evtLatch=0, remaining=[8da532ad-56a4-473d-9ada-0b24cf074fd1, 3bb3b6d0-edcf-464e-ae15-e83b51368e11], super=GridFutureAdapter [resFlag=0, res=null, startTime=1433254243303, endTime=0, ignoreInterrupts=false, lsnr=null, state=INIT]]]
> [17:13:32,184][WARN ][disco-event-worker-#462%null%][GridDiscoveryManager] Node FAILED: TcpDiscoveryNode [id=3bb3b6d0-edcf-464e-ae15-e83b51368e11, addrs=[192.168.56.1, 127.0.0.1, 2001:db8:85a3:0:0:8a2e:370:7334, 10.0.0.5, 0:0:0:0:0:0:0:1], sockAddrs=[rr/192.168.56.1:47501, /192.168.56.1:47501, /127.0.0.1:47501, rr/192.168.56.1:47501, /2001:db8:85a3:0:0:8a2e:370:7334:47501, rr/192.168.56.1:47501, /10.0.0.5:47501, /0:0:0:0:0:0:0:1:47501], discPort=47501, order=2, intOrder=2, loc=false, ver=1.1.1#20150602-sha1:82cfb47c, isClient=false]
> [17:13:32,188][INFO ][disco-event-worker-#462%null%][GridDiscoveryManager] Topology snapshot [ver=20, nodes=2, CPUs=8, heap=2.0GB]
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)