Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id E16AF10949 for ; Wed, 3 Dec 2014 06:55:13 +0000 (UTC) Received: (qmail 18518 invoked by uid 500); 3 Dec 2014 06:55:12 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 18482 invoked by uid 500); 3 Dec 2014 06:55:12 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 18472 invoked by uid 500); 3 Dec 2014 06:55:12 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 18469 invoked by uid 99); 3 Dec 2014 06:55:12 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 03 Dec 2014 06:55:12 +0000 Date: Wed, 3 Dec 2014 06:55:12 +0000 (UTC) From: "Jayapal Reddy (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CLOUDSTACK-7997) [Automation] Deployment of VM is failing on Basic Zone in Few Cases - Unable to apply dhcp entry on router MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-7997?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14232687#comment-14232687 ] Jayapal Reddy commented on CLOUDSTACK-7997: ------------------------------------------- Hi Chandhan, Can you please send the agent logs ? For the exception like 'ResourceUnavailableException: Resource [Pod:1] is unreachable: Unable to apply dhcp entry on router ' there are two reasons. 1. Router is not reachable to due some reason (host down, network issue or keys issue in the router) 2. Script failure. For this exceptions only MS logs will not help. Needs agents logs also. If setup is available I would recommend QA to run the script on the VR with args and find the script failures if any. > [Automation] Deployment of VM is failing on Basic Zone in Few Cases - Unable to apply dhcp entry on router > ---------------------------------------------------------------------------------------------------------- > > Key: CLOUDSTACK-7997 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7997 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the default.) > Components: Automation > Affects Versions: 4.5.0 > Reporter: Chandan Purushothama > Assignee: Jayapal Reddy > Priority: Critical > Fix For: 4.5.0 > > Attachments: management-server.zip > > > VM Deployment failure occurred multiple times. Posting the details from one such occurrence below: > ============================= > Unable to apply dhcp entry on router: > ============================= > {noformat} > 2014-12-01 18:57:12,396 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Asking VirtualRouter to prepare for Nic[132-125-5e3877b8-7029-4029-be70-429a6e47d568-10.219.197.222] > 2014-12-01 18:57:12,405 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Lock is acquired for network id 204 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(2)-Storage(Volume(152|ROOT-->Pool(1))] > 2014-12-01 18:57:12,408 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Lock is released for network id 204 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(2)-Storage(Volume(152|ROOT-->Pool(1))] > 2014-12-01 18:57:12,431 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Applying dhcp entry in network Ntwk[204|Guest|6] > 2014-12-01 18:57:12,446 DEBUG [c.c.a.t.Request] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Seq 2-1882786119217578814: Sending { Cmd , MgmtId: 195740251462904, via: 2(technetium), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:26:ea:00:00:37","vmIpAddress":"10.219.197.222","vmName":"VM-2656bcb0-f793-4248-8256-1754ebe2c2ef","defaultRouter":"10.219.192.1","defaultDns":"10.219.197.221","duid":"00:03:00:01:06:26:ea:00:00:37","isDefault":true,"executeInSequence":false,"accessDetails":{"router.guest.ip":"10.219.197.221","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.3.164"},"wait":0}}] } > 2014-12-01 18:57:12,447 DEBUG [c.c.a.t.Request] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Seq 2-1882786119217578814: Executing: { Cmd , MgmtId: 195740251462904, via: 2(technetium), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"06:26:ea:00:00:37","vmIpAddress":"10.219.197.222","vmName":"VM-2656bcb0-f793-4248-8256-1754ebe2c2ef","defaultRouter":"10.219.192.1","defaultDns":"10.219.197.221","duid":"00:03:00:01:06:26:ea:00:00:37","isDefault":true,"executeInSequence":false,"accessDetails":{"router.guest.ip":"10.219.197.221","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.3.164"},"wait":0}}] } > 2014-12-01 18:57:12,447 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-239:ctx-e27e7d7a) (logid:312cfd5b) Seq 2-1882786119217578814: Executing request > 2014-12-01 18:57:12,447 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-239:ctx-e27e7d7a) (logid:a7cfe505) Executing command in VR: /opt/cloud/bin/router_proxy.sh edithosts.sh 169.254.3.164 -m 06:26:ea:00:00:37 -4 10.219.197.222 -h VM-2656bcb0-f793-4248-8256-1754ebe2c2ef -d 10.219.192.1 -n 10.219.197.221 > 2014-12-01 18:57:12,448 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-239:ctx-e27e7d7a) (logid:a7cfe505) Seq 2-1882786119217578814: Response Received: > 2014-12-01 18:57:12,449 DEBUG [c.c.a.t.Request] (DirectAgent-239:ctx-e27e7d7a) (logid:a7cfe505) Seq 2-1882786119217578814: Processing: { Ans: , MgmtId: 195740251462904, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"There was a problem while connecting to 10.219.195.58:22","wait":0}}] } > 2014-12-01 18:57:12,449 DEBUG [c.c.a.t.Request] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Seq 2-1882786119217578814: Received: { Ans: , MgmtId: 195740251462904, via: 2, Ver: v1, Flags: 10, { Answer } } > 2014-12-01 18:57:12,449 INFO [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Unable to contact resource. > com.cloud.exception.ResourceUnavailableException: Resource [Pod:1] is unreachable: Unable to apply dhcp entry on router > at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:4086) > at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:3205) > at sun.reflect.GeneratedMethodAccessor399.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:601) > at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) > at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) > at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) > at $Proxy191.applyDhcpEntry(Unknown Source) > at com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:920) > at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareElement(NetworkOrchestrator.java:1242) > at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareNic(NetworkOrchestrator.java:1367) > at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1303) > at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:983) > at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4439) > at sun.reflect.GeneratedMethodAccessor387.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:601) > at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) > at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4595) > at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:103) > at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:546) > at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) > at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53) > at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46) > at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:497) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:722) > 2014-12-01 18:57:12,463 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Cleaning up resources for the vm VM[User|i-179-125-VM] in Starting state > 2014-12-01 18:57:12,466 DEBUG [c.c.a.t.Request] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Seq 2-1882786119217578815: Sending { Cmd , MgmtId: 195740251462904, via: 2(technetium), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-179-125-VM","wait":0}}] } > 2014-12-01 18:57:12,466 DEBUG [c.c.a.t.Request] (Work-Job-Executor-98:ctx-eb573b61 job-1170/job-1171 ctx-4477fe15) (logid:a7cfe505) Seq 2-1882786119217578815: Executing: { Cmd , MgmtId: 195740251462904, via: 2(technetium), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-179-125-VM","wait":0}}] } > 2014-12-01 18:57:12,466 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-475:ctx-cdced4ad) (logid:fd6ea3f2) Seq 2-1882786119217578815: Executing request > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)