Sanjeev N created CLOUDSTACK-3489:
-------------------------------------
Summary: Failed to start VR due to error in finalizeStart with KVM
hypervisor
Key: CLOUDSTACK-3489
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3489
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server
Affects Versions: 4.2.0
Environment: Latest build from ACS 4.2 branch.
Zone: Advanced with KVM cluster
Stoarage: S3 and Local storage
Reporter: Sanjeev N
Priority: Blocker
Fix For: 4.2.0
Attachments: management-server.rar
Failed to start VR due to error in finalizeStart with KVM hypervisor:
KVM routing template being used:
systemvmtemplate-2013-06-25-master-kvm.qcow2.bz2
Steps to Reproduce:
================
1.Bring up CS in advanced zone with KVM cluster
2.Use s3 as the secondary storage and Local storage as the primary storage
3.Use default cent os template to deploy guest vm
Observations:
===========
VR was started as part of vm deployment process and it remained in starting
state for a while. However later it was stopped with following exceptions:
com.cloud.exception.AgentUnavailableException: Resource [Host:4] is
unreachable: Host 4: Unable to start instance due to Unable to start
VM[DomainRouter|r-13-VM] due to error in finalizeStart, not retrying
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:944)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:557)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2727)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1867)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouter(VirtualNetworkApplianceManagerImpl.java:3124)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouter(VirtualNetworkApplianceManagerImpl.java:3074)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.admin.router.StartRouterCmd.execute(StartRouterCmd.java:110)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
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)
Caused by: com.cloud.utils.exception.ExecutionException: Unable to start
VM[DomainRouter|r-13-VM] due to error in finalizeStart, not retrying
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:911)
... 19 more
2013-07-12 02:38:24,430 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-8:job-32 = [ c1b6d349-4797-484e-a2e0-dfacce3c6209 ]) Complete
async job-32 = [ c1b6d349-4797-484e-a2e0-dfacce3c6209 ], jobStatus: 2,
resultCode: 530, result: Error Code: 530 Error text: Resource [Host:4] is
unreachable: Host 4: Unable to start instance due to Unable to start
VM[DomainRouter|r-13-VM] due to error in finalizeStart, not retrying
Few more log snippets from mgmt server log file:
2013-07-12 02:36:21,128 DEBUG [agent.transport.Request]
(AgentManager-Handler-4:null) Seq 4-691668978: Processing: { Ans: , MgmtId:
6615759585382, via: 4, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":13,"name":"r-13-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-13-VM
eth2ip=10.147.48.5 eth2mask=255.255.255.0 gateway=10.147.48.1 eth0ip=10.1.1.1
eth0mask=255.255.255.0 domain=cs2cloud.internal dhcprange=10.1.1.1
eth1ip=169.254.1.161 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":"2ef0b4b5e400c38","vncAddr":"10.147.40.14","params":{},"uuid":"9da5edbc-d99e-4a86-ac08-cc3772d7a31c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"494baea3-d999-4baf-9f6a-9649e700fdc3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"cd48bacb-ebb7-41a9-8617-67567c1bce71","id":2,"poolType":"Filesystem","host":"10.147.40.14","path":"/var/lib/libvirt/images","port":0}},"name":"ROOT-13","size":139264,"path":"c4b7fbc2-6d4c-4563-a8cc-04143cf8f32a","volumeId":17,"vmName":"r-13-VM","accountId":2,"format":"QCOW2","id":17}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"65ab14e3-cf65-44cf-acd0-9844f40356a3","ip":"10.147.48.5","netmask":"255.255.255.0","gateway":"10.147.48.1","mac":"06:e7:5e:00:00:0d","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://48","isolationUri":"vlan://48","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"82208773-d2f9-497e-94b1-fadee1e99e7b","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:0c:54:00:07","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://982","isolationUri":"vlan://982","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"997e83af-2f9f-4b75-bf50-b2437c904146","ip":"169.254.1.161","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:01:a1","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"com.cloud.agent.api.check.CheckSshAnswer":{"result":false,"details":"Can
not ping System vm r-13-VMdue to:Unable to
connect","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}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped
by previous failure","wait":0}}] }
2013-07-12 02:36:21,129 DEBUG [agent.transport.Request] (Job-Executor-8:job-32
= [ c1b6d349-4797-484e-a2e0-dfacce3c6209 ]) Seq 4-691668978: Received: { Ans:
, MgmtId: 6615759585382, via: 4, Ver: v1, Flags: 10, { StartAnswer,
CheckSshAnswer, Answer, Answer, Answer } }
2013-07-12 02:36:21,143 WARN
[network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-8:job-32 = [
c1b6d349-4797-484e-a2e0-dfacce3c6209 ]) Unable to ssh to the VM: Can not ping
System vm r-13-VMdue to:Unable to connect
2013-07-12 02:36:21,144 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-8:job-32 = [ c1b6d349-4797-484e-a2e0-dfacce3c6209 ]) The guru did
not like the answers so stopping VM[DomainRouter|r-13-VM]
2013-07-12 02:36:21,149 DEBUG [agent.transport.Request] (Job-Executor-8:job-32
= [ c1b6d349-4797-484e-a2e0-dfacce3c6209 ]) Seq 4-691668995: Sending { Cmd ,
MgmtId: 6615759585382, via: 4, Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-13-VM","wait":0}}]
}
When startCommand was executed to start VR , I could see the VR in running
state on KVM host. However console access to VR using "virsh console r-13-VM"
didn't show anything.
I don't see any issue with SSVM and CPVM.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
