You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ignite.apache.org by "Ksenia Rybakova (JIRA)" <ji...@apache.org> on 2017/02/21 12:37:44 UTC
[jira] [Created] (IGNITE-4734) Sporadic
GridServiceNotFoundException in ServiceExample
Ksenia Rybakova created IGNITE-4734:
---------------------------------------
Summary: 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)