[CLOUDSTACK-4542] [Automation] Failed to apply DHCP entry in VR and deployment failed

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Cannot Reproduce
• Affects Version/s: 4.2.0
• Fix Version/s: 4.3.0
• Component/s: Automation
• Security Level: Public (Anyone can view this level - this is the default.)
• Environment: 4.2-forward ; Automation environment on KVM
• Assignee: Sheng Yang
• Reporter: Rayees Namathponnan
• Created: 28/Aug/13 21:33
• Updated: 19/Dec/13 00:25
• Resolved: 09/Dec/13 22:57

Description

This issue found in automation run, observed while running the test case

integration.component.test_vpc_vms_deployment.TestVMDeployVPC.test_02_deploy_vms_delete_network

Router failed to apply DHCP entry then router deployment reported as failed

Observed below error in MS log, attached log search for "r-183-QA"

2013-08-27 22:56:30,877 DEBUG [agent.transport.Request] (AgentManager-Handler-4:null) Seq 2-654837610: Processing: { Ans: , MgmtId: 29066118877352, via: 2, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":false,"details":"ssh: connect to host 169.254.1.219 port 3922: Connection timed out","wait":0}}] }
2013-08-27 22:56:30,877 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-4:null) Seq 2-654837611: Sending now. is current sequence.
2013-08-27 22:56:30,877 DEBUG [agent.transport.Request] (Job-Executor-84:job-806 = [ 558e7c87-b3fb-444e-b5e9-85c3789a1318 ]) Seq 2-654837610: Received: { Ans: , MgmtId: 29066118877352, via: 2, Ver: v1, Flags: 110,

{ Answer }

}
2013-08-27 22:56:30,878 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-84:job-806 = [ 558e7c87-b3fb-444e-b5e9-85c3789a1318 ]) Unable to contact resource.
com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1] is unreachable: Unable to apply dhcp entry on router
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3808)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2919)
at com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:898)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2070)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2191)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
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:679)
2013-08-27 22:56:30,882 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-84:job-806 = [ 558e7c87-b3fb-444e-b5e9-85c3789a1318 ]) Cleaning up resources for the vm VM[User|df06b516-d40a-4dfa-9b77-4612bed9660e] in Starting state
2013-08-27 22:56:30,883 DEBUG [agent.transport.Request] (Job-Executor-84:job-806 = [ 558e7c87-b3fb-444e-b5e9-85c3789a1318 ]) Seq 1-1854540449: Waiting for Seq 1854540444 Scheduling: { Cmd , MgmtId: 29066118877352, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-119-186-QA","wait":0}}] }

Please see the attached agent log; router r-183-QA created successfully, then failed during network configuration on the router