Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 7044E200C22 for ; Tue, 21 Feb 2017 13:37:52 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 6ECD3160B68; Tue, 21 Feb 2017 12:37:52 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 6DB68160B3E for ; Tue, 21 Feb 2017 13:37:51 +0100 (CET) Received: (qmail 11593 invoked by uid 500); 21 Feb 2017 12:37:50 -0000 Mailing-List: contact dev-help@ignite.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@ignite.apache.org Delivered-To: mailing list dev@ignite.apache.org Received: (qmail 11582 invoked by uid 99); 21 Feb 2017 12:37:50 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 21 Feb 2017 12:37:50 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id 0AE7D1A7AAD for ; Tue, 21 Feb 2017 12:37:50 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -1.199 X-Spam-Level: X-Spam-Status: No, score=-1.199 tagged_above=-999 required=6.31 tests=[KAM_ASCII_DIVIDERS=0.8, KAM_LAZY_DOMAIN_SECURITY=1, RP_MATCHES_RCVD=-2.999] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id veoJzgiJ-xqz for ; Tue, 21 Feb 2017 12:37:46 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTP id 2940B5F286 for ; Tue, 21 Feb 2017 12:37:46 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id 8164BE02F1 for ; Tue, 21 Feb 2017 12:37:45 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id D54D42411F for ; Tue, 21 Feb 2017 12:37:44 +0000 (UTC) Date: Tue, 21 Feb 2017 12:37:44 +0000 (UTC) From: "Ksenia Rybakova (JIRA)" To: dev@ignite.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (IGNITE-4734) Sporadic GridServiceNotFoundException in ServiceExample MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Tue, 21 Feb 2017 12:37:52 -0000 Ksenia Rybakova created IGNITE-4734: --------------------------------------- Summary: Sporadic GridServiceNotFoundException in ServiceExamp= le 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=3D2= , servers=3D1, clients=3D1, CPUs=3D4, heap=3D2.0GB] >>> >>> Starting service proxy example. >>> [10:50:31,768][SEVERE][sys-#32%null%][GridTaskWorker] Failed to obtain remo= te job result policy for result from ComputeTask.result(..) method (will fa= il the whole task): GridJobResultImpl [job=3DC2V2 [c=3DServiceProxyCallable= [mtdName=3Dput, svcName=3DmyNodeSingletonService, ignite=3Dnull]], sib=3DG= ridJobSiblingImpl [sesId=3Db2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d= , jobId=3Dd2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d, nodeId=3D01aea3= a3-0981-4760-a26b-732afc4a8a27, isJobDone=3Dfalse], jobCtx=3DGridJobContext= Impl [jobId=3Dd2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d, timeoutObj= =3Dnull, attrs=3D{}], node=3DTcpDiscoveryNode [id=3D01aea3a3-0981-4760-a26b= -732afc4a8a27, addrs=3D[127.0.0.1, 172.25.2.17], sockAddrs=3D[/172.25.2.17:= 47500, /127.0.0.1:47500], discPort=3D47500, order=3D1, intOrder=3D1, lastEx= changeTime=3D1487663430926, loc=3Dfalse, ver=3D1.7.8#20170220-sha1:6112bce9= , isClient=3Dfalse], ex=3Dclass o.a.i.IgniteException: Service not found: m= yNodeSingletonService, hasRes=3Dtrue, isCancelled=3Dfalse, isOccupied=3Dtru= e] class org.apache.ignite.IgniteException: Remote job threw user exception (o= verride or implement ComputeTask.result(..) method if you would like to hav= e automatic failover for this exception). =09at org.apache.ignite.compute.ComputeTaskAdapter.result(ComputeTaskAdapte= r.java:101) =09at org.apache.ignite.internal.processors.task.GridTaskWorker$5.apply(Gri= dTaskWorker.java:1031) =09at org.apache.ignite.internal.processors.task.GridTaskWorker$5.apply(Gri= dTaskWorker.java:1024) =09at org.apache.ignite.internal.util.IgniteUtils.wrapThreadLoader(IgniteUt= ils.java:6596) =09at org.apache.ignite.internal.processors.task.GridTaskWorker.result(Grid= TaskWorker.java:1024) =09at org.apache.ignite.internal.processors.task.GridTaskWorker.onResponse(= GridTaskWorker.java:842) =09at org.apache.ignite.internal.processors.task.GridTaskProcessor.processJ= obExecuteResponse(GridTaskProcessor.java:996) =09at org.apache.ignite.internal.processors.task.GridTaskProcessor$JobMessa= geListener.onMessage(GridTaskProcessor.java:1221) =09at org.apache.ignite.internal.managers.communication.GridIoManager.invok= eListener(GridIoManager.java:1082) =09at org.apache.ignite.internal.managers.communication.GridIoManager.proce= ssRegularMessage0(GridIoManager.java:710) =09at org.apache.ignite.internal.managers.communication.GridIoManager.acces= s$1700(GridIoManager.java:102) =09at org.apache.ignite.internal.managers.communication.GridIoManager$5.run= (GridIoManager.java:673) =09at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.= java:1145) =09at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor= .java:615) =09at java.lang.Thread.run(Thread.java:745) Caused by: class org.apache.ignite.IgniteException: Service not found: myNo= deSingletonService =09at org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2= V2.execute(GridClosureProcessor.java:2059) =09at org.apache.ignite.internal.processors.job.GridJobWorker$2.call(GridJo= bWorker.java:560) =09at org.apache.ignite.internal.util.IgniteUtils.wrapThreadLoader(IgniteUt= ils.java:6564) =09at org.apache.ignite.internal.processors.job.GridJobWorker.execute0(Grid= JobWorker.java:554) =09at org.apache.ignite.internal.processors.job.GridJobWorker.body(GridJobW= orker.java:483) =09at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java= :110) =09at org.apache.ignite.internal.processors.job.GridJobProcessor.processJob= ExecuteRequest(GridJobProcessor.java:1180) =09at org.apache.ignite.internal.processors.job.GridJobProcessor$JobExecuti= onListener.onMessage(GridJobProcessor.java:1894) =09... 7 more Caused by: class org.apache.ignite.internal.processors.service.GridServiceN= otFoundException: Service not found: myNodeSingletonService =09at org.apache.ignite.internal.processors.service.GridServiceProxy$Servic= eProxyCallable.call(GridServiceProxy.java:397) =09at org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2= V2.execute(GridClosureProcessor.java:2056) =09... 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$SimpleClosur= e Closure execution result: [10] [10:50:32,035][INFO][main][GridCacheProcessor] Stopped cache: ignite-marsha= ller-sys-cache [10:50:32,035][INFO][main][GridCacheProcessor] Stopped cache: ignite-sys-ca= che [10:50:32,035][INFO][main][GridCacheProcessor] Stopped cache: ignite-atomic= s-sys-cache [10:50:32,037][INFO][main][GridDeploymentLocalStore] Removed undeployed cla= ss: GridDeployment [ts=3D1487663431355, depMode=3DSHARED, clsLdr=3Dsun.misc= .Launcher$AppClassLoader@10b28f30, clsLdrId=3D80c66af5a51-87f5f92a-d9ee-411= 9-90a5-35659bd7e50d, userVer=3D0, loc=3Dtrue, sampleClsName=3Dorg.apache.ig= nite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFu= llMap, pendingUndeploy=3Dfalse, undeployed=3Dtrue, usage=3D0] [10:50:32,041][INFO][main][IgniteKernal]=20 >>> +----------------------------------------------------------------------= -----------+ >>> Ignite ver. 1.7.8#20170220-sha1:6112bce906c417c0c4723f42281616c667347a6= 5 stopped OK >>> +----------------------------------------------------------------------= -----------+ {noformat} Server node log: {noformat} [10:50:30,916][INFO][disco-event-worker-#22%null%][GridDiscoveryManager] To= pology snapshot [ver=3D2, servers=3D1, clients=3D1, CPUs=3D4, heap=3D2.0GB] [10:50:30,944][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (nothing scheduled) [top=3DAffinityTopologyVer= sion [topVer=3D2, minorTopVer=3D0], evt=3DNODE_JOINED, node=3D87f5f92a-d9ee= -4119-90a5-35659bd7e50d] [10:50:31,622][INFO][exchange-worker-#25%null%][GridCacheProcessor] Started= cache [name=3DmyClusterSingletonService, mode=3DPARTITIONED] Service was initialized: myClusterSingletonService [10:50:31,662][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting = service instance [name=3DmyClusterSingletonService, execId=3Db6895479-ad51-= 44f4-9109-5a2e290168e9] Executing distributed service: myClusterSingletonService [10:50:31,679][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (nothing scheduled) [top=3DAffinityTopologyVer= sion [topVer=3D2, minorTopVer=3D1], evt=3DDISCOVERY_CUSTOM_EVT, node=3D01ae= a3a3-0981-4760-a26b-732afc4a8a27] [10:50:31,701][INFO][exchange-worker-#25%null%][GridCacheProcessor] Started= cache [name=3DmyNodeSingletonService, mode=3DPARTITIONED] [10:50:31,750][SEVERE][pub-#45%null%][GridJobWorker] Failed to execute job = [jobId=3Dd2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d, ses=3DGridJobSes= sionImpl [ses=3DGridTaskSessionImpl [taskName=3Do.a.i.i.processors.service.= GridServiceProxy$ServiceProxyCallable, dep=3DGridDeployment [ts=3D148766343= 1313, depMode=3DSHARED, clsLdr=3Dsun.misc.Launcher$AppClassLoader@10b28f30,= clsLdrId=3D74936af5a51-01aea3a3-0981-4760-a26b-732afc4a8a27, userVer=3D0, = loc=3Dtrue, sampleClsName=3Do.a.i.i.processors.cache.distributed.dht.preloa= der.GridDhtPartitionMap2, pendingUndeploy=3Dfalse, undeployed=3Dfalse, usag= e=3D1], taskClsName=3Do.a.i.i.processors.service.GridServiceProxy$ServicePr= oxyCallable, sesId=3Db2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50d, star= tTime=3D1487663431738, endTime=3D9223372036854775807, taskNodeId=3D87f5f92a= -d9ee-4119-90a5-35659bd7e50d, clsLdr=3Dsun.misc.Launcher$AppClassLoader@10b= 28f30, closed=3Dfalse, cpSpi=3Dnull, failSpi=3Dnull, loadSpi=3Dnull, usage= =3D1, fullSup=3Dfalse, internal=3Dfalse, subjId=3D87f5f92a-d9ee-4119-90a5-3= 5659bd7e50d, mapFut=3DIgniteFuture [orig=3DGridFutureAdapter [resFlag=3D0, = res=3Dnull, startTime=3D1487663431738, endTime=3D0, ignoreInterrupts=3Dfals= e, state=3DINIT]]], jobId=3Dd2c66af5a51-87f5f92a-d9ee-4119-90a5-35659bd7e50= d]] class org.apache.ignite.IgniteException: Service not found: myNodeSingleton= Service =09at org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2= V2.execute(GridClosureProcessor.java:2059) =09at org.apache.ignite.internal.processors.job.GridJobWorker$2.call(GridJo= bWorker.java:560) =09at org.apache.ignite.internal.util.IgniteUtils.wrapThreadLoader(IgniteUt= ils.java:6564) =09at org.apache.ignite.internal.processors.job.GridJobWorker.execute0(Grid= JobWorker.java:554) =09at org.apache.ignite.internal.processors.job.GridJobWorker.body(GridJobW= orker.java:483) =09at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java= :110) =09at org.apache.ignite.internal.processors.job.GridJobProcessor.processJob= ExecuteRequest(GridJobProcessor.java:1180) =09at org.apache.ignite.internal.processors.job.GridJobProcessor$JobExecuti= onListener.onMessage(GridJobProcessor.java:1894) =09at org.apache.ignite.internal.managers.communication.GridIoManager.invok= eListener(GridIoManager.java:1082) =09at org.apache.ignite.internal.managers.communication.GridIoManager.proce= ssRegularMessage0(GridIoManager.java:710) =09at org.apache.ignite.internal.managers.communication.GridIoManager.acces= s$1700(GridIoManager.java:102) =09at org.apache.ignite.internal.managers.communication.GridIoManager$5.run= (GridIoManager.java:673) =09at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.= java:1145) =09at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor= .java:615) =09at java.lang.Thread.run(Thread.java:745) Caused by: class org.apache.ignite.internal.processors.service.GridServiceN= otFoundException: Service not found: myNodeSingletonService =09at org.apache.ignite.internal.processors.service.GridServiceProxy$Servic= eProxyCallable.call(GridServiceProxy.java:397) =09at org.apache.ignite.internal.processors.closure.GridClosureProcessor$C2= V2.execute(GridClosureProcessor.java:2056) =09... 14 more Service was initialized: myNodeSingletonService [10:50:31,758][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting = service instance [name=3DmyNodeSingletonService, execId=3D42a2cebc-da76-414= 6-9f99-9c9b044e485b] [10:50:31,773][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (obsolete exchange ID) [top=3DAffinityTopology= Version [topVer=3D2, minorTopVer=3D2], evt=3DDISCOVERY_CUSTOM_EVT, node=3D0= 1aea3a3-0981-4760-a26b-732afc4a8a27] [10:50:31,782][INFO][exchange-worker-#25%null%][GridCacheProcessor] Started= cache [name=3DmyMultiService, mode=3DPARTITIONED] Executing distributed service: myNodeSingletonService Service was initialized: myMultiService [10:50:31,812][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting = service instance [name=3DmyMultiService, execId=3Dcfacf805-7c54-4769-b853-9= 6b7194425c0] Service was initialized: myMultiService [10:50:31,812][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Starting = service instance [name=3DmyMultiService, execId=3D3094db41-35da-4a32-9fec-5= 1bff2508d40] Executing distributed service: myMultiService Executing distributed service: myMultiService [10:50:31,826][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (nothing scheduled) [top=3DAffinityTopologyVer= sion [topVer=3D2, minorTopVer=3D3], evt=3DDISCOVERY_CUSTOM_EVT, node=3D01ae= a3a3-0981-4760-a26b-732afc4a8a27] [10:50:31,925][INFO][pub-#57%null%][GridDeploymentLocalStore] Class locally= deployed: class org.apache.ignite.examples.servicegrid.ServicesExample$Sim= pleClosure Executing closure [mapSize=3D10] [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=3DmyNodeSingletonService, execId=3D42a2cebc-da76-41= 46-9f99-9c9b044e485b] [10:50:31,970][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (obsolete exchange ID) [top=3DAffinityTopology= Version [topVer=3D2, minorTopVer=3D4], evt=3DDISCOVERY_CUSTOM_EVT, node=3D0= 1aea3a3-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=3DmyClusterSingletonService, execId=3Db6895479-ad51= -44f4-9109-5a2e290168e9] [10:50:31,976][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (nothing scheduled) [top=3DAffinityTopologyVer= sion [topVer=3D2, minorTopVer=3D5], evt=3DDISCOVERY_CUSTOM_EVT, node=3D01ae= a3a3-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=3DmyMultiService, execId=3Dcfacf805-7c54-4769-b853-= 96b7194425c0] Service was cancelled: myMultiService [10:50:32,020][INFO][srvc-deploy-#26%null%][GridServiceProcessor] Cancelled= service instance [name=3DmyMultiService, execId=3D3094db41-35da-4a32-9fec-= 51bff2508d40] [10:50:32,020][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (nothing scheduled) [top=3DAffinityTopologyVer= sion [topVer=3D2, minorTopVer=3D6], evt=3DDISCOVERY_CUSTOM_EVT, node=3D01ae= a3a3-0981-4760-a26b-732afc4a8a27] [10:50:32,030][INFO][disco-event-worker-#22%null%][GridDiscoveryManager] No= de left topology: TcpDiscoveryNode [id=3D87f5f92a-d9ee-4119-90a5-35659bd7e5= 0d, addrs=3D[127.0.0.1, 172.25.2.17], sockAddrs=3D[/172.25.2.17:0, /127.0.0= .1:0], discPort=3D0, order=3D2, intOrder=3D2, lastExchangeTime=3D1487663430= 876, loc=3Dfalse, ver=3D1.7.8#20170220-sha1:6112bce9, isClient=3Dtrue] [10:50:32,031][INFO][disco-event-worker-#22%null%][GridDiscoveryManager] To= pology snapshot [ver=3D3, servers=3D1, clients=3D0, CPUs=3D4, heap=3D1.0GB] [10:50:32,033][INFO][exchange-worker-#25%null%][GridCachePartitionExchangeM= anager] Skipping rebalancing (nothing scheduled) [top=3DAffinityTopologyVer= sion [topVer=3D3, minorTopVer=3D0], evt=3DNODE_LEFT, node=3D87f5f92a-d9ee-4= 119-90a5-35659bd7e50d] {noformat} -- This message was sent by Atlassian JIRA (v6.3.15#6346)