ignite-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dmitriy Govorukhin (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (IGNITE-4734) Sporadic GridServiceNotFoundException in ServiceExample
Date Tue, 21 Feb 2017 13:11:44 GMT

    [ 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)

Mime
View raw message