[
https://issues.apache.org/jira/browse/CLOUDSTACK-4962?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
shweta agarwal closed CLOUDSTACK-4962.
--------------------------------------
Verified .fixed.
> router VM failed to start on KVM
> ---------------------------------
>
> Key: CLOUDSTACK-4962
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4962
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: KVM, Virtual Router
> Affects Versions: 4.2.1
> Environment: have a advance zone with KVM
> KVM on centos6.4
> MS on centos6.4
> SystemVM templete seeded
> http://nfs1.lab.vmops.com/templates/campo_qa/systemvmtemplate-2013-06-12-master-kvm.qcow2.bz2
> Build :
> CloudPlatform-4.2.1-22-rhel6.4.tar.gz
> Reporter: shweta agarwal
> Assignee: Kishan Kavala
> Priority: Blocker
> Fix For: 4.2.1
>
> Attachments: agent.log, management-server.log.tar.gz
>
>
> Repro steps:
> Setup an advance zone and try to create a VM
> Bug: Router VM failed to start
> MS shows :
> 2013-10-25 15:48:11,672 DEBUG [agent.transport.Request]
> (AgentManager-Handler-1:null) Seq 1-580780059: Processing: { Ans: , MgmtId:
> 233845177509810, via: 1, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":4,"name":"r-4-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian
> GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-4-VM
> eth2ip=10.147.51.12 eth2mask=255.255.255.0 gateway=10.147.51.1
> eth0ip=10.1.1.1 eth0mask=255.255.255.0 domain=cs2cloud.internal
> dhcprange=10.1.1.1 eth1ip=169.254.1.72 eth1mask=255.255.0.0 type=router
> disable_rp_filter=true
> dns1=10.103.128.16","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"942ed47654205cb4","vncAddr":"10.147.40.27","params":{},"uuid":"065375b6-d32d-4bfe-8b6e-e4dcc23f158e","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cf634689-b1f5-45d6-807e-9b78689612b1","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"96cdf130-10ea-3765-9017-315b02d94ec4","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/shweta/dixon.kvm.primary","port":2049}},"name":"ROOT-4","size":276162048,"path":"148d97cd-c173-4904-a7ff-e6dafc7420bd","volumeId":5,"vmName":"r-4-VM","accountId":2,"format":"QCOW2","id":5,"hypervisorType":"KVM"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"223a9278-ba80-4271-81cd-55f0bffd6852","ip":"10.147.51.12","netmask":"255.255.255.0","gateway":"10.147.51.1","mac":"06:6c:be:00:00:0d","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://51","isolationUri":"vlan://51","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"f73b4717-680c-4c78-833e-f79c355d4229","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:13:c1:00:02","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1049","isolationUri":"vlan://1049","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"0ceaa1a8-31ab-49bd-94a3-414603c5fca2","ip":"169.254.1.72","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:01:48","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"com.cloud.agent.api.check.CheckSshAnswer":{"result":true,"wait":0}},{"com.cloud.agent.api.GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersionCmd
>
> failed","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped
> by previous
> failure","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped
> by previous failure","wait":0}}] }
> 2013-10-25 15:48:11,673 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-1:null) Seq 1-580780059: No more commands found
> 2013-10-25 15:48:11,673 DEBUG [agent.transport.Request]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Seq
> 1-580780059: Received: { Ans: , MgmtId: 233845177509810, via: 1, Ver: v1,
> Flags: 110, { StartAnswer, CheckSshAnswer, GetDomRVersionAnswer, Answer,
> Answer } }
> 2013-10-25 15:48:11,721 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null)
> ===END=== 10.146.0.132 -- GET
> command=queryAsyncJobResult&jobId=2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4&response=json&sessionkey=C9YivQ93YtZ4O2Bi53wlAMx9E5Q%3D&_=1382696291074
> 2013-10-25 15:48:11,788 WARN
> [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-1:job-13 =
> [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Unable to get the template/scripts
> version of router r-4-VM due to: GetDomRVersionCmd failed
> 2013-10-25 15:48:11,788 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) The guru
> did not like the answers so stopping VM[DomainRouter|r-4-VM]
> 2013-10-25 15:48:11,791 DEBUG [agent.transport.Request]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Seq
> 1-580780062: Sending { Cmd , MgmtId: 233845177509810, via: 1, Ver: v1,
> Flags: 100111,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"r-4-VM","wait":0}}]
> }
> 2013-10-25 15:48:13,175 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-2:null) SeqA 2-110: Processing Seq 2-110: { Cmd ,
> MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2013-10-25 15:48:13,243 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-2:null) SeqA 2-110: Sending Seq 2-110: { Ans: ,
> MgmtId: 233845177509810, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-10-25 15:48:14,650 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null)
> ===START=== 10.146.0.132 -- GET
> command=queryAsyncJobResult&jobId=2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4&response=json&sessionkey=C9YivQ93YtZ4O2Bi53wlAMx9E5Q%3D&_=1382696294076
> 2013-10-25 15:48:14,706 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null)
> ===END=== 10.146.0.132 -- GET
> command=queryAsyncJobResult&jobId=2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4&response=json&sessionkey=C9YivQ93YtZ4O2Bi53wlAMx9E5Q%3D&_=1382696294076
> 2013-10-25 15:48:17,650 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null)
> ===START=== 10.146.0.132 -- GET
> command=queryAsyncJobResult&jobId=2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4&response=json&sessionkey=C9YivQ93YtZ4O2Bi53wlAMx9E5Q%3D&_=1382696297076
> 2013-10-25 15:48:17,707 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null)
> ===END=== 10.146.0.132 -- GET
> command=queryAsyncJobResult&jobId=2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4&response=json&sessionkey=C9YivQ93YtZ4O2Bi53wlAMx9E5Q%3D&_=1382696297076
> 2013-10-25 15:48:18,371 DEBUG [agent.transport.Request]
> (AgentManager-Handler-3:null) Seq 1-580780062: Processing: { Ans: , MgmtId:
> 233845177509810, via: 1, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
> 2013-10-25 15:48:18,371 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-3:null) Seq 1-580780062: No more commands found
> 2013-10-25 15:48:18,371 DEBUG [agent.transport.Request]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Seq
> 1-580780062: Received: { Ans: , MgmtId: 233845177509810, via: 1, Ver: v1,
> Flags: 110, { StopAnswer } }
> 2013-10-25 15:48:18,372 ERROR [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Failed to
> start instance VM[DomainRouter|r-4-VM]
> com.cloud.utils.exception.ExecutionException: Unable to start
> VM[DomainRouter|r-4-VM] due to error in finalizeStart, not retrying
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:966)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2764)
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1896)
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1996)
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1974)
> at
> com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:189)
> at
> com.cloud.network.NetworkManagerImpl.implementNetworkElementsAndResources(NetworkManagerImpl.java:2043)
> at
> com.cloud.network.NetworkManagerImpl.implementNetwork(NetworkManagerImpl.java:1948)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2129)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
> 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:3425)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2985)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2971)
> 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:1146)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> 2013-10-25 15:48:18,421 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Cleaning
> up resources for the vm VM[DomainRouter|r-4-VM] in Starting state
> 2013-10-25 15:48:18,423 DEBUG [agent.transport.Request]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Seq
> 1-580780063: Sending { Cmd , MgmtId: 233845177509810, via: 1, Ver: v1,
> Flags: 100111,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"r-4-VM","wait":0}}]
> }
> 2013-10-25 15:48:18,530 DEBUG [agent.transport.Request]
> (AgentManager-Handler-4:null) Seq 1-580780063: Processing: { Ans: , MgmtId:
> 233845177509810, via: 1, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
> 2013-10-25 15:48:18,530 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-4:null) Seq 1-580780063: No more commands found
> 2013-10-25 15:48:18,531 DEBUG [agent.transport.Request]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Seq
> 1-580780063: Received: { Ans: , MgmtId: 233845177509810, via: 1, Ver: v1,
> Flags: 110, { StopAnswer } }
> 2013-10-25 15:48:18,536 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-1:job-13 =
> [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Successfully updated user
> statistics as a part of domR VM[DomainRouter|r-4-VM] reboot/stop
> 2013-10-25 15:48:18,570 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Service
> SecurityGroup is not supported in the network id=204
> 2013-10-25 15:48:18,623 DEBUG [cloud.network.NetworkManagerImpl]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Asking
> VirtualRouter to release
> Nic[9-4-a62f97ac-b662-4fca-bfa0-913290b7ff56-10.1.1.1]
> 2013-10-25 15:48:18,626 DEBUG [network.guru.ControlNetworkGuru]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ]) Released
> nic: NicProfile[10-4-null-null-null
> 2013-10-25 15:48:18,722 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-1:job-13 = [ 2d4992a5-4bc1-4dc2-8640-dfb0ed16c4a4 ])
> Successfully released network resources for the vm VM[DomainRouter|r-4-VM]
--
This message was sent by Atlassian JIRA
(v6.1#6144)
