[
https://issues.apache.org/jira/browse/IGNITE-4734?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16194602#comment-16194602
]
Denis Mekhanikov commented on IGNITE-4734:
------------------------------------------
I think, the reason is IGNITE-6571. When it's fixed, the problem with example
will go away.
> 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.4.14#64029)
