[
https://issues.apache.org/jira/browse/IGNITE-4734?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15875928#comment-15875928
]
Dmitriy Govorukhin edited comment on IGNITE-4734 at 2/21/17 1:11 PM:
---------------------------------------------------------------------
i think i know what the problem. We have race between creation context and
inject service in context. Context create and put in to context map (context
avalible for receipt) but service not inject in context. i think we must
discuss it, because if we change it, changed public api behavior.
was (Author: dmitriygovorukhin):
i think i know what the problem. We have race between creation context and
inject service in context. Context create and put it to context map (context
avalible for receipt) but service not inject in context. i think we must
discuss it, because if we change it, changed public api behavior.
> Sporadic GridServiceNotFoundException in ServiceExample
> -------------------------------------------------------
>
> Key: IGNITE-4734
> URL: https://issues.apache.org/jira/browse/IGNITE-4734
> Project: Ignite
> Issue Type: Bug
> Components: general
> Affects Versions: 1.7
> Reporter: Ksenia Rybakova
>
> Sometimes ServiceExample thows GridServiceNotFoundException
> Configs might be different - 1 node/3 nodes, linux/windows
> Driver node log:
> {noformat}
> [10:50:31,428][INFO][main][GridDiscoveryManager] Topology snapshot [ver=2,
> servers=1, clients=1, CPUs=4, heap=2.0GB]
> >>>
> >>> Starting service proxy example.
> >>>
> [10:50:31,768][SEVERE][sys-#32%null%][GridTaskWorker] Failed to obtain remote
> job result policy for result from ComputeTask.result(..) method (will fail
> the whole task): GridJobResultImpl [job=C2V2 [c=ServiceProxyCallable
> [mtdName=put, svcName=myNodeSingletonService, ignite=null]],
> sib=GridJobSiblingImpl
> [sesId=b2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d,
> jobId=d2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d,
> nodeId=01aea3a3-0981-4760-a26b-732afc4a8a27, isJobDone=false],
> jobCtx=GridJobContextImpl
> [jobId=d2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d, timeoutObj=null,
> attrs={}], node=TcpDiscoveryNode [id=01aea3a3-0981-4760-a26b-732afc4a8a27,
> addrs=[127.0.0.1, 172.25.2.17], sockAddrs=[/172.25.2.17:47500,
> /127.0.0.1:47500], discPort=47500, order=1, intOrder=1,
> lastExchangeTime=1487663430926, loc=false, ver=1.7.8#20170220-sha1:6112bce9,
> isClient=false], ex=class o.a.i.IgniteException: Service not found:
> myNodeSingletonService, hasRes=true, isCancelled=false, isOccupied=true]
> class org.apache.ignite.IgniteException: Remote job threw user exception
> (override or implement ComputeTask.result(..) method if you would like to
> have automatic failover for this exception).
> at
> org.apache.ignite.compute.ComputeTaskAdapter.result(ComputeTaskAdapter.java:101)
> at
> org.apache.ignite.internal.processors.task.GridTaskWorker$5.apply(GridTaskWorker.java:1031)
> at
> org.apache.ignite.internal.processors.task.GridTaskWorker$5.apply(GridTaskWorker.java:1024)
> at
> org.apache.ignite.internal.util.IgniteUtils.wrapThreadLoader(IgniteUtils.java:6596)
> at
> org.apache.ignite.internal.processors.task.GridTaskWorker.result(GridTaskWorker.java:1024)
> at
> org.apache.ignite.internal.processors.task.GridTaskWorker.onResponse(GridTaskWorker.java:842)
> at
> org.apache.ignite.internal.processors.task.GridTaskProcessor.processJobExecuteResponse(GridTaskProcessor.java:996)
> at
> org.apache.ignite.internal.processors.task.GridTaskProcessor$JobMessageListener.onMessage(GridTaskProcessor.java:1221)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1082)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:710)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager.access$1700(GridIoManager.java:102)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager$5.run(GridIoManager.java:673)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: class org.apache.ignite.IgniteException: Service not found:
> myNodeSingletonService
> at
> org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2V2.execute(GridClosureProcessor.java:2059)
> at
> org.apache.ignite.internal.processors.job.GridJobWorker$2.call(GridJobWorker.java:560)
> at
> org.apache.ignite.internal.util.IgniteUtils.wrapThreadLoader(IgniteUtils.java:6564)
> at
> org.apache.ignite.internal.processors.job.GridJobWorker.execute0(GridJobWorker.java:554)
> at
> org.apache.ignite.internal.processors.job.GridJobWorker.body(GridJobWorker.java:483)
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
> at
> org.apache.ignite.internal.processors.job.GridJobProcessor.processJobExecuteRequest(GridJobProcessor.java:1180)
> at
> org.apache.ignite.internal.processors.job.GridJobProcessor$JobExecutionListener.onMessage(GridJobProcessor.java:1894)
> ... 7 more
> Caused by: class
> org.apache.ignite.internal.processors.service.GridServiceNotFoundException:
> Service not found: myNodeSingletonService
> at
> org.apache.ignite.internal.processors.service.GridServiceProxy$ServiceProxyCallable.call(GridServiceProxy.java:397)
> at
> org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2V2.execute(GridClosureProcessor.java:2056)
> ... 14 more
> Map service size: 10
> >>>
> >>> Starting service injection example.
> >>>
> [10:50:31,905][INFO][main][GridDeploymentLocalStore] Class locally deployed:
> class org.apache.ignite.examples.servicegrid.ServicesExample$SimpleClosure
> Closure execution result: [10]
> [10:50:32,035][INFO][main][GridCacheProcessor] Stopped cache:
> ignite-marshaller-sys-cache
> [10:50:32,035][INFO][main][GridCacheProcessor] Stopped cache: ignite-sys-cache
> [10:50:32,035][INFO][main][GridCacheProcessor] Stopped cache:
> ignite-atomics-sys-cache
> [10:50:32,037][INFO][main][GridDeploymentLocalStore] Removed undeployed
> class: GridDeployment [ts=1487663431355, depMode=SHARED,
> clsLdr=sun.misc.Launcher$AppClassLoader@10b28f30,
> clsLdrId=80c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d, userVer=0,
> loc=true,
> sampleClsName=org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap,
> pendingUndeploy=false, undeployed=true, usage=0]
> [10:50:32,041][INFO][main][IgniteKernal]
> >>> +---------------------------------------------------------------------------------+
> >>> Ignite ver. 1.7.8#20170220-sha1:6112bce906c417c0c4723f42281616c667347a65
> >>> stopped OK
> >>> +---------------------------------------------------------------------------------+
> {noformat}
> Server node log:
> {noformat}
> [10:50:30,916][INFO][disco-event-worker-#22%null%][GridDiscoveryManager]
> Topology snapshot [ver=2, servers=1, clients=1, CPUs=4, heap=2.0GB]
> [10:50:30,944][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
> [topVer=2, minorTopVer=0], evt=NODE_JOINED,
> node=87f5f92a-d9ee-4119-90a5-35659bd7e50d]
> [10:50:31,622][INFO][exchange-worker-#25%null%][GridCacheProcessor] Started
> cache [name=myClusterSingletonService, mode=PARTITIONED]
> Service was initialized: myClusterSingletonService
> [10:50:31,662][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting
> service instance [name=myClusterSingletonService,
> execId=b6895479-ad51-44f4-9109-5a2e290168e9]
> Executing distributed service: myClusterSingletonService
> [10:50:31,679][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
> [topVer=2, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
> node=01aea3a3-0981-4760-a26b-732afc4a8a27]
> [10:50:31,701][INFO][exchange-worker-#25%null%][GridCacheProcessor] Started
> cache [name=myNodeSingletonService, mode=PARTITIONED]
> [10:50:31,750][SEVERE][pub-#45%null%][GridJobWorker] Failed to execute job
> [jobId=d2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d,
> ses=GridJobSessionImpl [ses=GridTaskSessionImpl
> [taskName=o.a.i.i.processors.service.GridServiceProxy$ServiceProxyCallable,
> dep=GridDeployment [ts=1487663431313, depMode=SHARED,
> clsLdr=sun.misc.Launcher$AppClassLoader@10b28f30,
> clsLdrId=74936af5a51-01aea3a3-0981-4760-a26b-732afc4a8a27, userVer=0,
> loc=true,
> sampleClsName=o.a.i.i.processors.cache.distributed.dht.preloader.GridDhtPartitionMap2,
> pendingUndeploy=false, undeployed=false, usage=1],
> taskClsName=o.a.i.i.processors.service.GridServiceProxy$ServiceProxyCallable,
> sesId=b2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d,
> startTime=1487663431738, endTime=9223372036854775807,
> taskNodeId=87f5f92a-d9ee-4119-90a5-35659bd7e50d,
> clsLdr=sun.misc.Launcher$AppClassLoader@10b28f30, closed=false, cpSpi=null,
> failSpi=null, loadSpi=null, usage=1, fullSup=false, internal=false,
> subjId=87f5f92a-d9ee-4119-90a5-35659bd7e50d, mapFut=IgniteFuture
> [orig=GridFutureAdapter [resFlag=0, res=null, startTime=1487663431738,
> endTime=0, ignoreInterrupts=false, state=INIT]]],
> jobId=d2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d]]
> class org.apache.ignite.IgniteException: Service not found:
> myNodeSingletonService
> at
> org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2V2.execute(GridClosureProcessor.java:2059)
> at
> org.apache.ignite.internal.processors.job.GridJobWorker$2.call(GridJobWorker.java:560)
> at
> org.apache.ignite.internal.util.IgniteUtils.wrapThreadLoader(IgniteUtils.java:6564)
> at
> org.apache.ignite.internal.processors.job.GridJobWorker.execute0(GridJobWorker.java:554)
> at
> org.apache.ignite.internal.processors.job.GridJobWorker.body(GridJobWorker.java:483)
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
> at
> org.apache.ignite.internal.processors.job.GridJobProcessor.processJobExecuteRequest(GridJobProcessor.java:1180)
> at
> org.apache.ignite.internal.processors.job.GridJobProcessor$JobExecutionListener.onMessage(GridJobProcessor.java:1894)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1082)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:710)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager.access$1700(GridIoManager.java:102)
> at
> org.apache.ignite.internal.managers.communication.GridIoManager$5.run(GridIoManager.java:673)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: class
> org.apache.ignite.internal.processors.service.GridServiceNotFoundException:
> Service not found: myNodeSingletonService
> at
> org.apache.ignite.internal.processors.service.GridServiceProxy$ServiceProxyCallable.call(GridServiceProxy.java:397)
> at
> org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2V2.execute(GridClosureProcessor.java:2056)
> ... 14 more
> Service was initialized: myNodeSingletonService
> [10:50:31,758][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting
> service instance [name=myNodeSingletonService,
> execId=42a2cebc-da76-4146-9f99-9c9b044e485b]
> [10:50:31,773][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion
> [topVer=2, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT,
> node=01aea3a3-0981-4760-a26b-732afc4a8a27]
> [10:50:31,782][INFO][exchange-worker-#25%null%][GridCacheProcessor] Started
> cache [name=myMultiService, mode=PARTITIONED]
> Executing distributed service: myNodeSingletonService
> Service was initialized: myMultiService
> [10:50:31,812][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting
> service instance [name=myMultiService,
> execId=cfacf805-7c54-4769-b853-96b7194425c0]
> Service was initialized: myMultiService
> [10:50:31,812][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting
> service instance [name=myMultiService,
> execId=3094db41-35da-4a32-9fec-51bff2508d40]
> Executing distributed service: myMultiService
> Executing distributed service: myMultiService
> [10:50:31,826][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
> [topVer=2, minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT,
> node=01aea3a3-0981-4760-a26b-732afc4a8a27]
> [10:50:31,925][INFO][pub-#57%null%][GridDeploymentLocalStore] Class locally
> deployed: class
> org.apache.ignite.examples.servicegrid.ServicesExample$SimpleClosure
> Executing closure [mapSize=10]
> [10:50:31,955][INFO][exchange-worker-#25%null%][GridCacheProcessor] Stopped
> cache: myNodeSingletonService
> Service was cancelled: myNodeSingletonService
> [10:50:31,955][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Cancelled
> service instance [name=myNodeSingletonService,
> execId=42a2cebc-da76-4146-9f99-9c9b044e485b]
> [10:50:31,970][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (obsolete exchange ID) [top=AffinityTopologyVersion
> [topVer=2, minorTopVer=4], evt=DISCOVERY_CUSTOM_EVT,
> node=01aea3a3-0981-4760-a26b-732afc4a8a27]
> [10:50:31,972][INFO][exchange-worker-#25%null%][GridCacheProcessor] Stopped
> cache: myClusterSingletonService
> Service was cancelled: myClusterSingletonService
> [10:50:31,973][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Cancelled
> service instance [name=myClusterSingletonService,
> execId=b6895479-ad51-44f4-9109-5a2e290168e9]
> [10:50:31,976][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
> [topVer=2, minorTopVer=5], evt=DISCOVERY_CUSTOM_EVT,
> node=01aea3a3-0981-4760-a26b-732afc4a8a27]
> [10:50:32,019][INFO][exchange-worker-#25%null%][GridCacheProcessor] Stopped
> cache: myMultiService
> Service was cancelled: myMultiService
> [10:50:32,020][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Cancelled
> service instance [name=myMultiService,
> execId=cfacf805-7c54-4769-b853-96b7194425c0]
> Service was cancelled: myMultiService
> [10:50:32,020][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Cancelled
> service instance [name=myMultiService,
> execId=3094db41-35da-4a32-9fec-51bff2508d40]
> [10:50:32,020][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
> [topVer=2, minorTopVer=6], evt=DISCOVERY_CUSTOM_EVT,
> node=01aea3a3-0981-4760-a26b-732afc4a8a27]
> [10:50:32,030][INFO][disco-event-worker-#22%null%][GridDiscoveryManager] Node
> left topology: TcpDiscoveryNode [id=87f5f92a-d9ee-4119-90a5-35659bd7e50d,
> addrs=[127.0.0.1, 172.25.2.17], sockAddrs=[/172.25.2.17:0, /127.0.0.1:0],
> discPort=0, order=2, intOrder=2, lastExchangeTime=1487663430876, loc=false,
> ver=1.7.8#20170220-sha1:6112bce9, isClient=true]
> [10:50:32,031][INFO][disco-event-worker-#22%null%][GridDiscoveryManager]
> Topology snapshot [ver=3, servers=1, clients=0, CPUs=4, heap=1.0GB]
> [10:50:32,033][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeManager]
> Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
> [topVer=3, minorTopVer=0], evt=NODE_LEFT,
> node=87f5f92a-d9ee-4119-90a5-35659bd7e50d]
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
