[
https://issues.apache.org/jira/browse/IGNITE-4181?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16098485#comment-16098485
]
Dmitriy Sorokin commented on IGNITE-4181:
-----------------------------------------
This issue was caused by mechanics which uses GridCacheProcessor's cache
descriptors map concurrently by event handlers at TCP discovery workers and
exchange processors at exchange worker. Cache creation event puts newly created
cache descriptor into GCP's cache descriptors map, then emits exchange, and
processing of one try take cache descriptor, which already can be removed by
cache deletion event, processed later then cache creation event but earlier
then cache creation exchange.
> The several runs of ServicesExample causes NPE
> ----------------------------------------------
>
> Key: IGNITE-4181
> URL: https://issues.apache.org/jira/browse/IGNITE-4181
> Project: Ignite
> Issue Type: Bug
> Components: general
> Affects Versions: 1.6, 1.7, 2.0
> Environment: Windows 10, Oracle JDK 7
> Reporter: Sergey Kozlov
> Assignee: Andrey Kuznetsov
> Labels: newbie
> Fix For: 2.2
>
>
> 0. Open example project in IDEA
> 1. Start 2-3 {{ExampleNodeStartup}}
> 2. Run {{ServicesExample}} several times.
> Sometimes it causes NullPointerException:
> {noformat}
> Executing closure [mapSize=10]
> Service was cancelled: myNodeSingletonService
> [15:37:20,020][INFO ][srvc-deploy-#24%null%][GridServiceProcessor] Cancelled
> service instance [name=myNodeSingletonService,
> execId=88a92a4d-c1cb-4a9b-8930-c67ac7f42bf3]
> [15:37:20,032][INFO ][sys-#33%null%][GridCacheProcessor] Stopped cache:
> myNodeSingletonService
> [15:37:20,033][INFO
> ][exchange-worker-#23%null%][GridCachePartitionExchangeManager] Skipping
> rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=10,
> minorTopVer=4], evt=DISCOVERY_CUSTOM_EVT,
> node=5faac72a-72ab-4277-9643-0e962973b3f4]
> [15:37:20,045][INFO ][sys-#39%null%][GridCacheProcessor] Stopped cache:
> myClusterSingletonService
> [15:37:20,046][INFO
> ][exchange-worker-#23%null%][GridCachePartitionExchangeManager] Skipping
> rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=10,
> minorTopVer=5], evt=DISCOVERY_CUSTOM_EVT,
> node=478f1752-fdce-42c6-aef6-55a5f4c08d90]
> [15:37:20,062][INFO ][disco-event-worker-#20%null%][GridDiscoveryManager]
> Node left topology: TcpDiscoveryNode
> [id=4f9cbc67-d756-4c25-9ee4-aee6528da024, addrs=[0:0:0:0:0:0:0:1, 127.0.0.1,
> 172.25.4.107, 2001:0:9d38:6ab8:34b2:9f3e:3c6f:269],
> sockAddrs=[/2001:0:9d38:6ab8:34b2:9f3e:3c6f:269:0, /127.0.0.1:0,
> /0:0:0:0:0:0:0:1:0, work-pc/172.25.4.107:0], discPort=0, order=10,
> intOrder=7, lastExchangeTime=1478522239236, loc=false,
> ver=1.7.3#20161107-sha1:5132ac87, isClient=true]
> [15:37:20,063][INFO ][disco-event-worker-#20%null%][GridDiscoveryManager]
> Topology snapshot [ver=11, servers=3, clients=0, CPUs=8, heap=11.0GB]
> [15:37:20,064][INFO ][sys-#44%null%][GridCacheProcessor] Stopped cache:
> myMultiService
> [15:37:20,066][INFO
> ][exchange-worker-#23%null%][GridCachePartitionExchangeManager] Skipping
> rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=10,
> minorTopVer=6], evt=DISCOVERY_CUSTOM_EVT,
> node=5faac72a-72ab-4277-9643-0e962973b3f4]
> [15:37:20,076][INFO ][exchange-worker-#23%null%][GridCacheProcessor] Started
> cache [name=myClusterSingletonService, mode=PARTITIONED]
> [15:37:20,115][INFO
> ][exchange-worker-#23%null%][GridCachePartitionExchangeManager] Skipping
> rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=10,
> minorTopVer=7], evt=DISCOVERY_CUSTOM_EVT,
> node=478f1752-fdce-42c6-aef6-55a5f4c08d90]
> [15:37:20,121][INFO
> ][exchange-worker-#23%null%][GridCachePartitionExchangeManager] Skipping
> rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=11,
> minorTopVer=0], evt=NODE_LEFT, node=4f9cbc67-d756-4c25-9ee4-aee6528da024]
> [15:37:20,133][INFO ][exchange-worker-#23%null%][GridCacheProcessor] Started
> cache [name=myMultiService, mode=PARTITIONED]
> [15:37:20,135][ERROR][exchange-worker-#23%null%][GridDhtPartitionsExchangeFuture]
> Failed to reinitialize local partitions (preloading will be stopped):
> GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=11,
> minorTopVer=1], nodeId=5faac72a, evt=DISCOVERY_CUSTOM_EVT]
> java.lang.NullPointerException
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.initStartedCacheOnCoordinator(CacheAffinitySharedManager.java:743)
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:413)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:565)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:448)
> at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:1447)
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
> at java.lang.Thread.run(Thread.java:745)
> [15:37:20,142][ERROR][exchange-worker-#23%null%][GridCachePartitionExchangeManager]
> Failed to wait for completion of partition map exchange (preloading will not
> start): GridDhtPartitionsExchangeFuture [dummy=false, forcePreload=false,
> reassign=false, discoEvt=DiscoveryCustomEvent [customMsg=null,
> affTopVer=AffinityTopologyVersion [topVer=11, minorTopVer=1],
> super=DiscoveryEvent [evtNode=TcpDiscoveryNode
> [id=5faac72a-72ab-4277-9643-0e962973b3f4, addrs=[0:0:0:0:0:0:0:1, 127.0.0.1,
> 172.25.4.107, 2001:0:9d38:6ab8:34b2:9f3e:3c6f:269],
> sockAddrs=[work-pc/172.25.4.107:47501, /127.0.0.1:47501,
> /0:0:0:0:0:0:0:1:47501, /2001:0:9d38:6ab8:34b2:9f3e:3c6f:269:47501],
> discPort=47501, order=3, intOrder=3, lastExchangeTime=1478522196962,
> loc=false, ver=1.7.3#20161107-sha1:5132ac87, isClient=false], topVer=11,
> nodeId8=bbcf9d48, msg=null, type=DISCOVERY_CUSTOM_EVT,
> tstamp=1478522240108]], crd=TcpDiscoveryNode
> [id=bbcf9d48-980f-43a1-9219-2456baf49262, addrs=[0:0:0:0:0:0:0:1, 127.0.0.1,
> 172.25.4.107, 2001:0:9d38:6ab8:34b2:9f3e:3c6f:269],
> sockAddrs=[/2001:0:9d38:6ab8:34b2:9f3e:3c6f:269:47500, /127.0.0.1:47500,
> /0:0:0:0:0:0:0:1:47500, work-pc/172.25.4.107:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1478522240139, loc=true,
> ver=1.7.3#20161107-sha1:5132ac87, isClient=false],
> exchId=GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=11,
> minorTopVer=1], nodeId=5faac72a, evt=DISCOVERY_CUSTOM_EVT], added=true,
> initFut=GridFutureAdapter [resFlag=2, res=false, startTime=1478522240108,
> endTime=1478522240128, ignoreInterrupts=false, state=DONE], init=false,
> topSnapshot=null, lastVer=null, partReleaseFut=null, affChangeMsg=null,
> skipPreload=false, clientOnlyExchange=false, initTs=1478522240118,
> centralizedAff=false, evtLatch=0,
> remaining=[478f1752-fdce-42c6-aef6-55a5f4c08d90,
> 5faac72a-72ab-4277-9643-0e962973b3f4], srvNodes=[TcpDiscoveryNode
> [id=bbcf9d48-980f-43a1-9219-2456baf49262, addrs=[0:0:0:0:0:0:0:1, 127.0.0.1,
> 172.25.4.107, 2001:0:9d38:6ab8:34b2:9f3e:3c6f:269],
> sockAddrs=[/2001:0:9d38:6ab8:34b2:9f3e:3c6f:269:47500, /127.0.0.1:47500,
> /0:0:0:0:0:0:0:1:47500, work-pc/172.25.4.107:47500], discPort=47500, order=1,
> intOrder=1, lastExchangeTime=1478522240139, loc=true,
> ver=1.7.3#20161107-sha1:5132ac87, isClient=false], TcpDiscoveryNode
> [id=478f1752-fdce-42c6-aef6-55a5f4c08d90, addrs=[0:0:0:0:0:0:0:1, 127.0.0.1,
> 172.25.4.107, 2001:0:9d38:6ab8:34b2:9f3e:3c6f:269],
> sockAddrs=[work-pc/172.25.4.107:47502,
> /2001:0:9d38:6ab8:34b2:9f3e:3c6f:269:47502, /127.0.0.1:47502,
> /0:0:0:0:0:0:0:1:47502], discPort=47502, order=2, intOrder=2,
> lastExchangeTime=1478522194286, loc=false, ver=1.7.3#20161107-sha1:5132ac87,
> isClient=false], TcpDiscoveryNode [id=5faac72a-72ab-4277-9643-0e962973b3f4,
> addrs=[0:0:0:0:0:0:0:1, 127.0.0.1, 172.25.4.107,
> 2001:0:9d38:6ab8:34b2:9f3e:3c6f:269], sockAddrs=[work-pc/172.25.4.107:47501,
> /127.0.0.1:47501, /0:0:0:0:0:0:0:1:47501,
> /2001:0:9d38:6ab8:34b2:9f3e:3c6f:269:47501], discPort=47501, order=3,
> intOrder=3, lastExchangeTime=1478522196962, loc=false,
> ver=1.7.3#20161107-sha1:5132ac87, isClient=false]], super=GridFutureAdapter
> [resFlag=1, res=java.lang.NullPointerException, startTime=1478522240108,
> endTime=1478522240128, ignoreInterrupts=false, state=DONE]]
> class org.apache.ignite.IgniteCheckedException: null
> at
> org.apache.ignite.internal.util.IgniteUtils.cast(IgniteUtils.java:7154)
> at
> org.apache.ignite.internal.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:196)
> at
> org.apache.ignite.internal.util.future.GridFutureAdapter.get(GridFutureAdapter.java:137)
> at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:1453)
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.NullPointerException
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.initStartedCacheOnCoordinator(CacheAffinitySharedManager.java:743)
> at
> org.apache.ignite.internal.processors.cache.CacheAffinitySharedManager.onCacheChangeRequest(CacheAffinitySharedManager.java:413)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.onCacheChangeRequest(GridDhtPartitionsExchangeFuture.java:565)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:448)
> at
> org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:1447)
> ... 2 more
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
