You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Asmita Vagyani <As...@sigma-systems.com> on 2013/01/23 10:04:42 UTC
Create Instance failure after re-install
Hi all,
I have re-installed the CS4 on RHEL server.
The cluster and its hosts are added properly, and in running state.
SSVMs area also in running state.
When I create an instance from console I get the following error in management console logs:
Any idea abt this issue? (I saw link http://bugs.cloudstack.org/browse/CS-14465 , but I don't see the /systemvm folder created on the /mnt/secondary folder)
2013-01-23 01:06:44,894 ERROR [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Unable to execute NetworkUsage command on DomR (10.0.100.182), domR may not be ready yet. failure due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
java.lang.Exception: Failed to authentication SSH user root on host 10.0.100.182
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at com.cloud.hypervisor.vmware.resource.VmwareResource.networkUsage(VmwareResource.java:4566)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1911)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:425)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Executing resource GetDomRVersionCmd: {"accessDetails":{"router.name":"r-5-VM","router.ip":"10.0.100.182"},"wait":0}
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Run command on domR 10.0.100.182, /opt/cloud/bin/get_template_version.sh
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Use router's private IP for SSH control. IP : 10.0.100.182
2013-01-23 01:06:45,138 ERROR [utils.ssh.SshHelper] (DirectAgent-108:torvms03lx.sigmasys.net) Failed to authentication SSH user root on host 10.0.100.182
2013-01-23 01:06:45,139 ERROR [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) GetDomRVersionCmd failed due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
java.lang.Exception: Failed to authentication SSH user root on host 10.0.100.182
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1753)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:433)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-108:null) Seq 2-2082210641: Cancelling because one of the answers is false and it is stop on error.
2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-108:null) Seq 2-2082210641: Response Received:
2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (DirectAgent-108:null) Seq 2-2082210641: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":5,"name":"r-5-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-5-VM eth0ip=10.0.100.182 eth0mask=255.255.255.0 gateway=10.0.100.1 domain=cs1cloud.internal dhcprange=10.0.100.1 eth1ip=0.0.0.0 eth1mask=0.0.0.0 sshonguest=true type=dhcpsrvr disable_rp_filter=true extra_pubnics=2 dns1=10.0.100.5 nic_macs=06:12:00:00:00:08|02:00:4f:6b:00:08","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"b8fdaa863d476636","params":{"nicAdapter":"E1000"},"uuid":"04ee40b9-bd06-4814-b01e-aa4928da5d96","disks":[{"id":6,"name":"ROOT-5","mountPoint":"/CloudStack/tormsa02-raid0-4","path":"ROOT-5","size":2097152000,"type":"ROOT","storagePoolType":"VMFS","storagePoolUuid":"3546bfef-40ed-3f8f-9484-b5cd712235f8","deviceId":0}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"e04d295a-e633-407d-96e0-aef8550df2d4","ip":"10.0.100.182","netmask":"255.255.255.0","gateway":"10.0.100.1","mac":"06:12:00:00:00:08","dns1":"10.0.100.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"31e1d523-79da-40f7-b909-47a0cce3e8cb","ip":"0.0.0.0","netmask":"0.0.0.0","gateway":"0.0.0.0","mac":"02:00:4f:6b:00:08","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"check.CheckSshAnswer":{"result":true,"wait":0}},{"GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersionCmd failed due to Exception: java.lang.Exception\nMessage: Failed to authentication SSH user root on host 10.0.100.182\n","wait":0}}] }
2013-01-23 01:06:45,144 DEBUG [agent.manager.AgentAttache] (DirectAgent-108:null) Seq 2-2082210641: No more commands found
2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210641: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StartAnswer, CheckSshAnswer, GetDomRVersionAnswer } }
2013-01-23 01:06:45,282 WARN [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-7:job-13) Unable to get the template/scripts version of router r-5-VM due to: GetDomRVersionCmd failed due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
2013-01-23 01:06:45,283 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) The guru did not like the answers so stopping VM[DomainRouter|r-5-VM]
2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:45,287 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 2-2082210644: Executing request
2013-01-23 01:06:45,288 INFO [vmware.resource.VmwareResource] (DirectAgent-182:torvms03lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-5-VM","wait":0}
2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-182:torvms03lx.sigmasys.net) find VM r-5-VM on host
2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-182:torvms03lx.sigmasys.net) load VM cache on host
2013-01-23 01:06:46,211 INFO [vmware.resource.VmwareResource] (DirectAgent-182:torvms03lx.sigmasys.net) Remove all snapshot before stopping VM r-5-VM
2013-01-23 01:06:46,595 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector is running...
2013-01-23 01:06:49,438 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers.
2013-01-23 01:06:53,877 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null) Ping from 6
2013-01-23 01:06:54,281 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 2-2082210644: Response Received:
2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (DirectAgent-182:null) Seq 2-2082210644: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"Stop VM r-5-VM Succeed","wait":0}}] }
2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentAttache] (DirectAgent-182:null) Seq 2-2082210644: No more commands found
2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-7:job-13) Details from executing class com.cloud.agent.api.StopCommand: Stop VM r-5-VM Succeed
2013-01-23 01:06:54,282 ERROR [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Failed to start instance VM[DomainRouter|r-5-VM]
com.cloud.utils.exception.ExecutionException: Unable to start VM[DomainRouter|r-5-VM] due to error in finalizeStart, not retrying
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:814)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
at com.cloud.api.commands.DeployVMCmd.execute(DeployVMCmd.java:330)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
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)
2013-01-23 01:06:54,797 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Cleaning up resources for the vm VM[DomainRouter|r-5-VM] in Starting state
2013-01-23 01:06:54,798 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:54,969 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:54,969 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-173:null) Seq 2-2082210645: Executing request
2013-01-23 01:06:54,969 INFO [vmware.resource.VmwareResource] (DirectAgent-173:torvms03lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-5-VM","wait":0}
2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-173:torvms03lx.sigmasys.net) find VM r-5-VM on host
2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-173:torvms03lx.sigmasys.net) load VM cache on host
2013-01-23 01:06:55,878 INFO [vmware.resource.VmwareResource] (DirectAgent-173:torvms03lx.sigmasys.net) VM r-5-VM is already in stopped state
2013-01-23 01:06:55,879 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-173:null) Seq 2-2082210645: Response Received:
2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (DirectAgent-173:null) Seq 2-2082210645: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM r-5-VM is already in stopped state","wait":0}}] }
2013-01-23 01:06:55,879 DEBUG [agent.manager.AgentAttache] (DirectAgent-173:null) Seq 2-2082210645: No more commands found
2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-7:job-13) release cpu from host: 2, old used: 1500,reserved: 0, actual total: 48000, total with overprovisioning: 48000; new used: 1000,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-7:job-13) release mem from host: 2, old used: 1476395008,reserved: 0, total: 34357202944; new used: 1342177280,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-23 01:06:56,986 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Unable to contact resource.
com.cloud.exception.AgentUnavailableException: Resource [Host:2] is unreachable: Host 2: Unable to start instance due to Unable to start VM[DomainRouter|r-5-VM] due to error in finalizeStart, not retrying
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
Thanks and Regards.
Asmita Patil Vagyani.
RE: Create Instance failure after re-install
Posted by Asmita Vagyani <As...@sigma-systems.com>.
I think we have figured it out.
I can successfully create a VM Instance now using the CentOS 32-bit template.
The first issue was that the tormsa02-raid0-4 datastore was not working.
Kept getting "java.lang.Exception: Unable to find datastore in vSphere" logs
I tried shutting down the SystemVMs and deleting and recreating our Primary Store - it seemed to successfully reconnect to tormsa02-raid0-4 but the errors were still happening.
When listing the datastores in the CloudStack data center on Vcenter - I could see that there were a number of other datastores already in existence that didn't seem to be being used.
I decided to try adding one of these as another Primary Data Store in CloudStack.
I picked tormsa02-raid0-5 and it was successfully added into CloudStack.
It worked - the Virtual Router VM was installed using the new datastore and it came up correctly.
At this point I was getting the issue about being unable to SSH to the System VMs.
I figured out that the iso template we needed to replace was mounted on the Cloudstack management server in /var/lib/cloud/mnt/
The exact file is /var/lib/cloud/mnt/VM/345051758635.793c975e/systemvm/systemvm-4.0.0.20121024012150.iso
I tried stopping the SystemVMs and copying the /usr/lib64/cloud/agent/vms/systemvm.iso over this file when they were down - but that didn't work.
In the end - I wanted to see if this iso was even being used at all - so I figured that if I renamed the file, and restarted things - I would at least get an error saying that the file couldn't be found.
What actually happened was that the file was recreated by CloudStack - and the new version of the file worked!
SSH to the VMs is now working again.
Then I tried creating an Instance of a VM using Cloudstack - it worked - using the CentOS 32-bit template.
If we try to use the 64 bit templates it fails with a Unable to find a compatible host.
Thanks and Regards.
Asmita
-----Original Message-----
From: Asmita Vagyani [mailto:Asmita.Vagyani@sigma-systems.com]
Sent: 24 January 2013 PM 02:53
To: 'cloudstack-users@incubator.apache.org'
Subject: RE: Create Instance failure after re-install
Hi all,
I am not able to create an instance vm on the CS4 RHEL deployment.
I get following err, any idea how it can be resolved:
2013-01-24 01:01:56,260 WARN [vmware.resource.VmwareResource] (DirectAgent-433:torvms04lx.sigmasys.net) StartCommand failed due to Exception: java.lang.Exception
Message: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8
java.lang.Exception: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8
at com.cloud.hypervisor.vmware.resource.VmwareResource.inferDatastoreDetailsFromDiskInfo(VmwareResource.java:2362)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1963)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:419)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-24 01:01:56,262 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-433:null) Seq 3-1934689601: Cancelling because one of the answers is false and it is stop on error.
2013-01-24 01:01:56,262 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-433:null) Seq 3-1934689601: Response Received:
2013-01-24 01:01:56,263 DEBUG [agent.transport.Request] (DirectAgent-433:null) Seq 3-1934689601: Processing: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":16,"name":"r-16-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-16-VM eth0ip=10.0.100.181 eth0mask=255.255.255.0 gateway=10.0.100.1 domain=cs1cloud.internal dhcprange=10.0.100.1 eth1ip=0.0.0.0 eth1mask=0.0.0.0 sshonguest=true type=dhcpsrvr disable_rp_filter=true extra_pubnics=2 dns1=10.0.100.5 nic_macs=06:b1:28:00:00:07|02:00:00:23:00:16","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"f465534e71f17d08","params":{"nicAdapter":"E1000"},"uuid":"ee7b02dd-31c3-4250-8ed9-70c261da95cf","disks":[{"id":19,"name":"ROOT-16","mountPoint":"/CloudStack/tormsa02-raid0-4","path":"ROOT-16","size":2097152000,"type":"ROOT","storagePoolType":"VMFS","storagePoolUuid":"3546bfef-40ed-3f8f-9484-b5cd712235f8","deviceId":0}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"4969e758-1ccd-4e42-8fbf-3d17955cc769","ip":"10.0.100.181","netmask":"255.255.255.0","gateway":"10.0.100.1","mac":"06:b1:28:00:00:07","dns1":"10.0.100.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"c9ef8289-f35d-47a9-8a7c-2cf0016d0440","ip":"0.0.0.0","netmask":"0.0.0.0","gateway":"0.0.0.0","mac":"02:00:00:23:00:16","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":false,"details":"StartCommand failed due to Exception: java.lang.Exception\nMessage: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8\n","wait":0}}] }
2013-01-24 01:01:56,263 DEBUG [agent.manager.AgentAttache] (DirectAgent-433:null) Seq 3-1934689601: No more commands found
2013-01-24 01:01:56,263 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689601: Received: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, { StartAnswer } }
2013-01-24 01:01:56,269 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Unable to start VM on Host[-3-Routing] due to StartCommand failed due to Exception: java.lang.Exception
Message: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8
2013-01-24 01:01:56,275 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Cleaning up resources for the vm VM[DomainRouter|r-16-VM] in Starting state
2013-01-24 01:01:56,276 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689602: Sending { Cmd , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-16-VM","wait":0}}] }
2013-01-24 01:01:56,277 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689602: Executing: { Cmd , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-16-VM","wait":0}}] }
2013-01-24 01:01:56,277 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-430:null) Seq 3-1934689602: Executing request
2013-01-24 01:01:56,277 INFO [vmware.resource.VmwareResource] (DirectAgent-430:torvms04lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-16-VM","wait":0}
2013-01-24 01:01:56,277 DEBUG [vmware.mo.HostMO] (DirectAgent-430:torvms04lx.sigmasys.net) find VM r-16-VM on host
2013-01-24 01:01:56,277 DEBUG [vmware.mo.HostMO] (DirectAgent-430:torvms04lx.sigmasys.net) load VM cache on host
2013-01-24 01:01:56,486 INFO [vmware.resource.VmwareResource] (DirectAgent-430:torvms04lx.sigmasys.net) VM r-16-VM is no longer in vSphere
2013-01-24 01:01:56,486 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-430:null) Seq 3-1934689602: Response Received:
2013-01-24 01:01:56,486 DEBUG [agent.transport.Request] (DirectAgent-430:null) Seq 3-1934689602: Processing: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM r-16-VM is no longer in vSphere","wait":0}}] }
2013-01-24 01:01:56,487 DEBUG [agent.manager.AgentAttache] (DirectAgent-430:null) Seq 3-1934689602: No more commands found
2013-01-24 01:01:56,487 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689602: Received: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-24 01:01:56,492 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-6:job-34) Successfully updated user statistics as a part of domR VM[DomainRouter|r-16-VM] reboot/stop
2013-01-24 01:01:56,523 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Service SecurityGroup is not supported in the network id=204
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking JuniperSRX to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Netscaler to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking F5BigIP to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VirtualRouter to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Ovs to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking ExternalDhcpServer to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking BareMetal to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking SecurityGroupProvider to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking CiscoNexus1000vVSM to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VpcVirtualRouter to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking NiciraNvp to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,553 DEBUG [network.guru.ControlNetworkGuru] (Job-Executor-6:job-34) Released nic: NicProfile[31-16-null-null-null
2013-01-24 01:01:56,568 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking JuniperSRX to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Netscaler to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking F5BigIP to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VirtualRouter to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Ovs to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking ExternalDhcpServer to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking BareMetal to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking SecurityGroupProvider to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking CiscoNexus1000vVSM to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VpcVirtualRouter to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking NiciraNvp to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Successfully released network resources for the vm VM[DomainRouter|r-16-VM]
2013-01-24 01:01:56,569 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Successfully cleanued up resources for the vm VM[DomainRouter|r-16-VM] in Starting state
2013-01-24 01:01:56,571 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Root volume is ready, need to place VM in volume's cluster
2013-01-24 01:01:56,571 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Vol[19|vm=16|ROOT] is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 13
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) DeploymentPlanner allocation algorithm: random
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:13, requested cpu: 500, requested ram: 134217728
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Is ROOT volume READY (pool already allocated)?: Yes
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Searching resources only under specified Cluster: 13
2013-01-24 01:01:56,579 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Checking resources in Cluster: 13 under Pod: 1
2013-01-24 01:01:56,579 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Calling HostAllocators to find suitable hosts
2013-01-24 01:01:56,579 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:13
2013-01-24 01:01:56,581 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-3-Routing]]
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-3-Routing]]
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=128
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Host name: torvms04lx.sigmasys.net, hostId: 3 is in avoid set, skipping this and trying other available hosts
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2013-01-24 01:01:56,584 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) No suitable hosts found
2013-01-24 01:01:56,584 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) No suitable hosts found under this Cluster: 13
2013-01-24 01:01:56,584 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) DeploymentPlanner allocation algorithm: random
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 134217728
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Is ROOT volume READY (pool already allocated)?: No
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Searching resources only under specified Pod: 1
2013-01-24 01:01:56,586 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2013-01-24 01:01:56,587 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) CPUOverprovisioningFactor considered: 1.0
2013-01-24 01:01:56,589 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Removing from the clusterId list these clusters from avoid set: [13]
2013-01-24 01:01:56,589 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2013-01-24 01:01:56,601 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 3
2013-01-24 01:01:56,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) Hosts's actual total CPU: 48000 and CPU after applying overprovisioning: 48000
2013-01-24 01:01:56,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) release cpu from host: 3, old used: 1000,reserved: 0, actual total: 48000, total with overprovisioning: 48000; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-24 01:01:56,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) release mem from host: 3, old used: 671088640,reserved: 0, total: 34357202944; new used: 536870912,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-24 01:01:56,611 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Insufficient capacity
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[DomainRouter|r-16-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:734)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
at com.cloud.api.commands.DeployVMCmd.execute(DeployVMCmd.java:330)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
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)
Thanks and Regards.
Asmita Patil Vagyani.
-----Original Message-----
From: Asmita Vagyani [mailto:Asmita.Vagyani@sigma-systems.com]
Sent: 23 January 2013 PM 02:35
To: 'cloudstack-users@incubator.apache.org'
Subject: Create Instance failure after re-install
Hi all,
I have re-installed the CS4 on RHEL server.
The cluster and its hosts are added properly, and in running state.
SSVMs area also in running state.
When I create an instance from console I get the following error in management console logs:
Any idea abt this issue? (I saw link http://bugs.cloudstack.org/browse/CS-14465 , but I don't see the /systemvm folder created on the /mnt/secondary folder)
2013-01-23 01:06:44,894 ERROR [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Unable to execute NetworkUsage command on DomR (10.0.100.182), domR may not be ready yet. failure due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
java.lang.Exception: Failed to authentication SSH user root on host 10.0.100.182
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at com.cloud.hypervisor.vmware.resource.VmwareResource.networkUsage(VmwareResource.java:4566)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1911)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:425)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Executing resource GetDomRVersionCmd: {"accessDetails":{"router.name":"r-5-VM","router.ip":"10.0.100.182"},"wait":0}
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Run command on domR 10.0.100.182, /opt/cloud/bin/get_template_version.sh
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Use router's private IP for SSH control. IP : 10.0.100.182
2013-01-23 01:06:45,138 ERROR [utils.ssh.SshHelper] (DirectAgent-108:torvms03lx.sigmasys.net) Failed to authentication SSH user root on host 10.0.100.182
2013-01-23 01:06:45,139 ERROR [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) GetDomRVersionCmd failed due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
java.lang.Exception: Failed to authentication SSH user root on host 10.0.100.182
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1753)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:433)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-108:null) Seq 2-2082210641: Cancelling because one of the answers is false and it is stop on error.
2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-108:null) Seq 2-2082210641: Response Received:
2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (DirectAgent-108:null) Seq 2-2082210641: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":5,"name":"r-5-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-5-VM eth0ip=10.0.100.182 eth0mask=255.255.255.0 gateway=10.0.100.1 domain=cs1cloud.internal dhcprange=10.0.100.1 eth1ip=0.0.0.0 eth1mask=0.0.0.0 sshonguest=true type=dhcpsrvr disable_rp_filter=true extra_pubnics=2 dns1=10.0.100.5 nic_macs=06:12:00:00:00:08|02:00:4f:6b:00:08","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"b8fdaa863d476636","params":{"nicAdapter":"E1000"},"uuid":"04ee40b9-bd06-4814-b01e-aa4928da5d96","disks":[{"id":6,"name":"ROOT-5","mountPoint":"/CloudStack/tormsa02-raid0-4","path":"ROOT-5","size":2097152000,"type":"ROOT","storagePoolType":"VMFS","storagePoolUuid":"3546bfef-40ed-3f8f-9484-b5cd712235f8","deviceId":0}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"e04d295a-e633-407d-96e0-aef8550df2d4","ip":"10.0.100.182","netmask":"255.255.255.0","gateway":"10.0.100.1","mac":"06:12:00:00:00:08","dns1":"10.0.100.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"31e1d523-79da-40f7-b909-47a0cce3e8cb","ip":"0.0.0.0","netmask":"0.0.0.0","gateway":"0.0.0.0","mac":"02:00:4f:6b:00:08","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"check.CheckSshAnswer":{"result":true,"wait":0}},{"GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersionCmd failed due to Exception: java.lang.Exception\nMessage: Failed to authentication SSH user root on host 10.0.100.182\n","wait":0}}] }
2013-01-23 01:06:45,144 DEBUG [agent.manager.AgentAttache] (DirectAgent-108:null) Seq 2-2082210641: No more commands found
2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210641: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StartAnswer, CheckSshAnswer, GetDomRVersionAnswer } }
2013-01-23 01:06:45,282 WARN [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-7:job-13) Unable to get the template/scripts version of router r-5-VM due to: GetDomRVersionCmd failed due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
2013-01-23 01:06:45,283 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) The guru did not like the answers so stopping VM[DomainRouter|r-5-VM]
2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:45,287 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 2-2082210644: Executing request
2013-01-23 01:06:45,288 INFO [vmware.resource.VmwareResource] (DirectAgent-182:torvms03lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-5-VM","wait":0}
2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-182:torvms03lx.sigmasys.net) find VM r-5-VM on host
2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-182:torvms03lx.sigmasys.net) load VM cache on host
2013-01-23 01:06:46,211 INFO [vmware.resource.VmwareResource] (DirectAgent-182:torvms03lx.sigmasys.net) Remove all snapshot before stopping VM r-5-VM
2013-01-23 01:06:46,595 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector is running...
2013-01-23 01:06:49,438 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers.
2013-01-23 01:06:53,877 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null) Ping from 6
2013-01-23 01:06:54,281 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 2-2082210644: Response Received:
2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (DirectAgent-182:null) Seq 2-2082210644: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"Stop VM r-5-VM Succeed","wait":0}}] }
2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentAttache] (DirectAgent-182:null) Seq 2-2082210644: No more commands found
2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-7:job-13) Details from executing class com.cloud.agent.api.StopCommand: Stop VM r-5-VM Succeed
2013-01-23 01:06:54,282 ERROR [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Failed to start instance VM[DomainRouter|r-5-VM]
com.cloud.utils.exception.ExecutionException: Unable to start VM[DomainRouter|r-5-VM] due to error in finalizeStart, not retrying
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:814)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
at com.cloud.api.commands.DeployVMCmd.execute(DeployVMCmd.java:330)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
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)
2013-01-23 01:06:54,797 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Cleaning up resources for the vm VM[DomainRouter|r-5-VM] in Starting state
2013-01-23 01:06:54,798 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:54,969 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:54,969 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-173:null) Seq 2-2082210645: Executing request
2013-01-23 01:06:54,969 INFO [vmware.resource.VmwareResource] (DirectAgent-173:torvms03lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-5-VM","wait":0}
2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-173:torvms03lx.sigmasys.net) find VM r-5-VM on host
2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-173:torvms03lx.sigmasys.net) load VM cache on host
2013-01-23 01:06:55,878 INFO [vmware.resource.VmwareResource] (DirectAgent-173:torvms03lx.sigmasys.net) VM r-5-VM is already in stopped state
2013-01-23 01:06:55,879 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-173:null) Seq 2-2082210645: Response Received:
2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (DirectAgent-173:null) Seq 2-2082210645: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM r-5-VM is already in stopped state","wait":0}}] }
2013-01-23 01:06:55,879 DEBUG [agent.manager.AgentAttache] (DirectAgent-173:null) Seq 2-2082210645: No more commands found
2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-7:job-13) release cpu from host: 2, old used: 1500,reserved: 0, actual total: 48000, total with overprovisioning: 48000; new used: 1000,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-7:job-13) release mem from host: 2, old used: 1476395008,reserved: 0, total: 34357202944; new used: 1342177280,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-23 01:06:56,986 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Unable to contact resource.
com.cloud.exception.AgentUnavailableException: Resource [Host:2] is unreachable: Host 2: Unable to start instance due to Unable to start VM[DomainRouter|r-5-VM] due to error in finalizeStart, not retrying
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
Thanks and Regards.
Asmita Patil Vagyani.
RE: Create Instance failure after re-install
Posted by Asmita Vagyani <As...@sigma-systems.com>.
Hi all,
I am not able to create an instance vm on the CS4 RHEL deployment.
I get following err, any idea how it can be resolved:
2013-01-24 01:01:56,260 WARN [vmware.resource.VmwareResource] (DirectAgent-433:torvms04lx.sigmasys.net) StartCommand failed due to Exception: java.lang.Exception
Message: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8
java.lang.Exception: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8
at com.cloud.hypervisor.vmware.resource.VmwareResource.inferDatastoreDetailsFromDiskInfo(VmwareResource.java:2362)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1963)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:419)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-24 01:01:56,262 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-433:null) Seq 3-1934689601: Cancelling because one of the answers is false and it is stop on error.
2013-01-24 01:01:56,262 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-433:null) Seq 3-1934689601: Response Received:
2013-01-24 01:01:56,263 DEBUG [agent.transport.Request] (DirectAgent-433:null) Seq 3-1934689601: Processing: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":16,"name":"r-16-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-16-VM eth0ip=10.0.100.181 eth0mask=255.255.255.0 gateway=10.0.100.1 domain=cs1cloud.internal dhcprange=10.0.100.1 eth1ip=0.0.0.0 eth1mask=0.0.0.0 sshonguest=true type=dhcpsrvr disable_rp_filter=true extra_pubnics=2 dns1=10.0.100.5 nic_macs=06:b1:28:00:00:07|02:00:00:23:00:16","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"f465534e71f17d08","params":{"nicAdapter":"E1000"},"uuid":"ee7b02dd-31c3-4250-8ed9-70c261da95cf","disks":[{"id":19,"name":"ROOT-16","mountPoint":"/CloudStack/tormsa02-raid0-4","path":"ROOT-16","size":2097152000,"type":"ROOT","storagePoolType":"VMFS","storagePoolUuid":"3546bfef-40ed-3f8f-9484-b5cd712235f8","deviceId":0}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"4969e758-1ccd-4e42-8fbf-3d17955cc769","ip":"10.0.100.181","netmask":"255.255.255.0","gateway":"10.0.100.1","mac":"06:b1:28:00:00:07","dns1":"10.0.100.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"c9ef8289-f35d-47a9-8a7c-2cf0016d0440","ip":"0.0.0.0","netmask":"0.0.0.0","gateway":"0.0.0.0","mac":"02:00:00:23:00:16","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":false,"details":"StartCommand failed due to Exception: java.lang.Exception\nMessage: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8\n","wait":0}}] }
2013-01-24 01:01:56,263 DEBUG [agent.manager.AgentAttache] (DirectAgent-433:null) Seq 3-1934689601: No more commands found
2013-01-24 01:01:56,263 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689601: Received: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, { StartAnswer } }
2013-01-24 01:01:56,269 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Unable to start VM on Host[-3-Routing] due to StartCommand failed due to Exception: java.lang.Exception
Message: Failed to get the mounted datastore for the volume's pool 3546bfef-40ed-3f8f-9484-b5cd712235f8
2013-01-24 01:01:56,275 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Cleaning up resources for the vm VM[DomainRouter|r-16-VM] in Starting state
2013-01-24 01:01:56,276 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689602: Sending { Cmd , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-16-VM","wait":0}}] }
2013-01-24 01:01:56,277 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689602: Executing: { Cmd , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-16-VM","wait":0}}] }
2013-01-24 01:01:56,277 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-430:null) Seq 3-1934689602: Executing request
2013-01-24 01:01:56,277 INFO [vmware.resource.VmwareResource] (DirectAgent-430:torvms04lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-16-VM","wait":0}
2013-01-24 01:01:56,277 DEBUG [vmware.mo.HostMO] (DirectAgent-430:torvms04lx.sigmasys.net) find VM r-16-VM on host
2013-01-24 01:01:56,277 DEBUG [vmware.mo.HostMO] (DirectAgent-430:torvms04lx.sigmasys.net) load VM cache on host
2013-01-24 01:01:56,486 INFO [vmware.resource.VmwareResource] (DirectAgent-430:torvms04lx.sigmasys.net) VM r-16-VM is no longer in vSphere
2013-01-24 01:01:56,486 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-430:null) Seq 3-1934689602: Response Received:
2013-01-24 01:01:56,486 DEBUG [agent.transport.Request] (DirectAgent-430:null) Seq 3-1934689602: Processing: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM r-16-VM is no longer in vSphere","wait":0}}] }
2013-01-24 01:01:56,487 DEBUG [agent.manager.AgentAttache] (DirectAgent-430:null) Seq 3-1934689602: No more commands found
2013-01-24 01:01:56,487 DEBUG [agent.transport.Request] (Job-Executor-6:job-34) Seq 3-1934689602: Received: { Ans: , MgmtId: 345051758635, via: 3, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-24 01:01:56,492 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-6:job-34) Successfully updated user statistics as a part of domR VM[DomainRouter|r-16-VM] reboot/stop
2013-01-24 01:01:56,523 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Service SecurityGroup is not supported in the network id=204
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking JuniperSRX to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Netscaler to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking F5BigIP to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VirtualRouter to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Ovs to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking ExternalDhcpServer to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking BareMetal to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking SecurityGroupProvider to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking CiscoNexus1000vVSM to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VpcVirtualRouter to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking NiciraNvp to release Nic[30-16-916040df-61a7-435f-8f04-c349657059b2-10.0.100.181]
2013-01-24 01:01:56,553 DEBUG [network.guru.ControlNetworkGuru] (Job-Executor-6:job-34) Released nic: NicProfile[31-16-null-null-null
2013-01-24 01:01:56,568 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking JuniperSRX to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Netscaler to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking F5BigIP to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VirtualRouter to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking Ovs to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking ExternalDhcpServer to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking BareMetal to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking SecurityGroupProvider to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking CiscoNexus1000vVSM to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking VpcVirtualRouter to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-6:job-34) Asking NiciraNvp to release Nic[31-16-916040df-61a7-435f-8f04-c349657059b2-null]
2013-01-24 01:01:56,569 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Successfully released network resources for the vm VM[DomainRouter|r-16-VM]
2013-01-24 01:01:56,569 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Successfully cleanued up resources for the vm VM[DomainRouter|r-16-VM] in Starting state
2013-01-24 01:01:56,571 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Root volume is ready, need to place VM in volume's cluster
2013-01-24 01:01:56,571 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Vol[19|vm=16|ROOT] is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 13
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) DeploymentPlanner allocation algorithm: random
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:13, requested cpu: 500, requested ram: 134217728
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Is ROOT volume READY (pool already allocated)?: Yes
2013-01-24 01:01:56,572 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Searching resources only under specified Cluster: 13
2013-01-24 01:01:56,579 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Checking resources in Cluster: 13 under Pod: 1
2013-01-24 01:01:56,579 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Calling HostAllocators to find suitable hosts
2013-01-24 01:01:56,579 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:13
2013-01-24 01:01:56,581 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-3-Routing]]
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-3-Routing]]
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=128
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Host name: torvms04lx.sigmasys.net, hostId: 3 is in avoid set, skipping this and trying other available hosts
2013-01-24 01:01:56,584 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-6:job-34 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2013-01-24 01:01:56,584 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) No suitable hosts found
2013-01-24 01:01:56,584 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) No suitable hosts found under this Cluster: 13
2013-01-24 01:01:56,584 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) DeploymentPlanner allocation algorithm: random
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 134217728
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Is ROOT volume READY (pool already allocated)?: No
2013-01-24 01:01:56,585 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Searching resources only under specified Pod: 1
2013-01-24 01:01:56,586 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2013-01-24 01:01:56,587 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) CPUOverprovisioningFactor considered: 1.0
2013-01-24 01:01:56,589 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) Removing from the clusterId list these clusters from avoid set: [13]
2013-01-24 01:01:56,589 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-6:job-34) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2013-01-24 01:01:56,601 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 3
2013-01-24 01:01:56,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) Hosts's actual total CPU: 48000 and CPU after applying overprovisioning: 48000
2013-01-24 01:01:56,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) release cpu from host: 3, old used: 1000,reserved: 0, actual total: 48000, total with overprovisioning: 48000; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-24 01:01:56,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-6:job-34) release mem from host: 3, old used: 671088640,reserved: 0, total: 34357202944; new used: 536870912,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-24 01:01:56,611 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-6:job-34) Insufficient capacity
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[DomainRouter|r-16-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:734)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
at com.cloud.api.commands.DeployVMCmd.execute(DeployVMCmd.java:330)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
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)
Thanks and Regards.
Asmita Patil Vagyani.
-----Original Message-----
From: Asmita Vagyani [mailto:Asmita.Vagyani@sigma-systems.com]
Sent: 23 January 2013 PM 02:35
To: 'cloudstack-users@incubator.apache.org'
Subject: Create Instance failure after re-install
Hi all,
I have re-installed the CS4 on RHEL server.
The cluster and its hosts are added properly, and in running state.
SSVMs area also in running state.
When I create an instance from console I get the following error in management console logs:
Any idea abt this issue? (I saw link http://bugs.cloudstack.org/browse/CS-14465 , but I don't see the /systemvm folder created on the /mnt/secondary folder)
2013-01-23 01:06:44,894 ERROR [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Unable to execute NetworkUsage command on DomR (10.0.100.182), domR may not be ready yet. failure due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
java.lang.Exception: Failed to authentication SSH user root on host 10.0.100.182
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at com.cloud.hypervisor.vmware.resource.VmwareResource.networkUsage(VmwareResource.java:4566)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1911)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:425)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Executing resource GetDomRVersionCmd: {"accessDetails":{"router.name":"r-5-VM","router.ip":"10.0.100.182"},"wait":0}
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Run command on domR 10.0.100.182, /opt/cloud/bin/get_template_version.sh
2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) Use router's private IP for SSH control. IP : 10.0.100.182
2013-01-23 01:06:45,138 ERROR [utils.ssh.SshHelper] (DirectAgent-108:torvms03lx.sigmasys.net) Failed to authentication SSH user root on host 10.0.100.182
2013-01-23 01:06:45,139 ERROR [vmware.resource.VmwareResource] (DirectAgent-108:torvms03lx.sigmasys.net) GetDomRVersionCmd failed due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
java.lang.Exception: Failed to authentication SSH user root on host 10.0.100.182
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1753)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:433)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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)
2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-108:null) Seq 2-2082210641: Cancelling because one of the answers is false and it is stop on error.
2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-108:null) Seq 2-2082210641: Response Received:
2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (DirectAgent-108:null) Seq 2-2082210641: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":5,"name":"r-5-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-5-VM eth0ip=10.0.100.182 eth0mask=255.255.255.0 gateway=10.0.100.1 domain=cs1cloud.internal dhcprange=10.0.100.1 eth1ip=0.0.0.0 eth1mask=0.0.0.0 sshonguest=true type=dhcpsrvr disable_rp_filter=true extra_pubnics=2 dns1=10.0.100.5 nic_macs=06:12:00:00:00:08|02:00:4f:6b:00:08","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"b8fdaa863d476636","params":{"nicAdapter":"E1000"},"uuid":"04ee40b9-bd06-4814-b01e-aa4928da5d96","disks":[{"id":6,"name":"ROOT-5","mountPoint":"/CloudStack/tormsa02-raid0-4","path":"ROOT-5","size":2097152000,"type":"ROOT","storagePoolType":"VMFS","storagePoolUuid":"3546bfef-40ed-3f8f-9484-b5cd712235f8","deviceId":0}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"e04d295a-e633-407d-96e0-aef8550df2d4","ip":"10.0.100.182","netmask":"255.255.255.0","gateway":"10.0.100.1","mac":"06:12:00:00:00:08","dns1":"10.0.100.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"31e1d523-79da-40f7-b909-47a0cce3e8cb","ip":"0.0.0.0","netmask":"0.0.0.0","gateway":"0.0.0.0","mac":"02:00:4f:6b:00:08","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"check.CheckSshAnswer":{"result":true,"wait":0}},{"GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersionCmd failed due to Exception: java.lang.Exception\nMessage: Failed to authentication SSH user root on host 10.0.100.182\n","wait":0}}] }
2013-01-23 01:06:45,144 DEBUG [agent.manager.AgentAttache] (DirectAgent-108:null) Seq 2-2082210641: No more commands found
2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210641: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StartAnswer, CheckSshAnswer, GetDomRVersionAnswer } }
2013-01-23 01:06:45,282 WARN [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-7:job-13) Unable to get the template/scripts version of router r-5-VM due to: GetDomRVersionCmd failed due to Exception: java.lang.Exception
Message: Failed to authentication SSH user root on host 10.0.100.182
2013-01-23 01:06:45,283 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) The guru did not like the answers so stopping VM[DomainRouter|r-5-VM]
2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:45,287 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 2-2082210644: Executing request
2013-01-23 01:06:45,288 INFO [vmware.resource.VmwareResource] (DirectAgent-182:torvms03lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-5-VM","wait":0}
2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-182:torvms03lx.sigmasys.net) find VM r-5-VM on host
2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-182:torvms03lx.sigmasys.net) load VM cache on host
2013-01-23 01:06:46,211 INFO [vmware.resource.VmwareResource] (DirectAgent-182:torvms03lx.sigmasys.net) Remove all snapshot before stopping VM r-5-VM
2013-01-23 01:06:46,595 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector is running...
2013-01-23 01:06:49,438 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers.
2013-01-23 01:06:53,877 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null) Ping from 6
2013-01-23 01:06:54,281 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-182:null) Seq 2-2082210644: Response Received:
2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (DirectAgent-182:null) Seq 2-2082210644: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"Stop VM r-5-VM Succeed","wait":0}}] }
2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentAttache] (DirectAgent-182:null) Seq 2-2082210644: No more commands found
2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210644: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-7:job-13) Details from executing class com.cloud.agent.api.StopCommand: Stop VM r-5-VM Succeed
2013-01-23 01:06:54,282 ERROR [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Failed to start instance VM[DomainRouter|r-5-VM]
com.cloud.utils.exception.ExecutionException: Unable to start VM[DomainRouter|r-5-VM] due to error in finalizeStart, not retrying
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:814)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
at com.cloud.api.commands.DeployVMCmd.execute(DeployVMCmd.java:330)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
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)
2013-01-23 01:06:54,797 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Cleaning up resources for the vm VM[DomainRouter|r-5-VM] in Starting state
2013-01-23 01:06:54,798 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:54,969 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2013-01-23 01:06:54,969 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-173:null) Seq 2-2082210645: Executing request
2013-01-23 01:06:54,969 INFO [vmware.resource.VmwareResource] (DirectAgent-173:torvms03lx.sigmasys.net) Executing resource StopCommand: {"isProxy":false,"vmName":"r-5-VM","wait":0}
2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-173:torvms03lx.sigmasys.net) find VM r-5-VM on host
2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-173:torvms03lx.sigmasys.net) load VM cache on host
2013-01-23 01:06:55,878 INFO [vmware.resource.VmwareResource] (DirectAgent-173:torvms03lx.sigmasys.net) VM r-5-VM is already in stopped state
2013-01-23 01:06:55,879 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-173:null) Seq 2-2082210645: Response Received:
2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (DirectAgent-173:null) Seq 2-2082210645: Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM r-5-VM is already in stopped state","wait":0}}] }
2013-01-23 01:06:55,879 DEBUG [agent.manager.AgentAttache] (DirectAgent-173:null) Seq 2-2082210645: No more commands found
2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (Job-Executor-7:job-13) Seq 2-2082210645: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-7:job-13) release cpu from host: 2, old used: 1500,reserved: 0, actual total: 48000, total with overprovisioning: 48000; new used: 1000,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-7:job-13) release mem from host: 2, old used: 1476395008,reserved: 0, total: 34357202944; new used: 1342177280,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-23 01:06:56,986 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-7:job-13) Unable to contact resource.
com.cloud.exception.AgentUnavailableException: Resource [Host:2] is unreachable: Host 2: Unable to start instance due to Unable to start VM[DomainRouter|r-5-VM] due to error in finalizeStart, not retrying
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2352)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1597)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1697)
at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
at com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.java:205)
at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2056)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2929)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2601)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2589)
at com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
Thanks and Regards.
Asmita Patil Vagyani.
Re: Create Instance failure after re-install
Posted by lokesh chanana <lo...@hcl.com>.
What was the solution to this??
Asmita Vagyani <As...@...> writes:
>
> Hi all,
>
> I have re-installed the CS4 on RHEL server.
> The cluster and its hosts are added properly, and in running state.
> SSVMs area also in running state.
>
> When I create an instance from console I get the following error in
management console logs:
> Any idea abt this issue? (I saw link http://bugs.cloudstack.org/browse/CS-
14465 , but I don't see the
> /systemvm folder created on the /mnt/secondary folder)
>
> 2013-01-23 01:06:44,894 ERROR [vmware.resource.VmwareResource]
> (DirectAgent-108:torvms03lx.sigmasys.net) Unable to execute NetworkUsage
command on DomR
> (10.0.100.182), domR may not be ready yet. failure due to Exception:
java.lang.Exception
> Message: Failed to authentication SSH user root on host 10.0.100.182
>
> java.lang.Exception: Failed to authentication SSH user root on host
10.0.100.182
> at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
> at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
> at
com.cloud.hypervisor.vmware.resource.VmwareResource.networkUsage(VmwareResou
rce.java:4566)
> at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.j
ava:1911)
> at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareRes
ource.java:425)
> at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:
191)
> 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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$
201(ScheduledThreadPoolExecutor.java:178)
> at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Sch
eduledThreadPoolExecutor.java:292)
> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:11
10)
> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6
03)
> at java.lang.Thread.run(Thread.java:722)
> 2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource]
> (DirectAgent-108:torvms03lx.sigmasys.net) Executing resource
GetDomRVersionCmd: {"accessDetails":{"router.name":"r-5-
VM","router.ip":"10.0.100.182"},"wait":0}
> 2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource]
> (DirectAgent-108:torvms03lx.sigmasys.net) Run command on domR
10.0.100.182, /opt/cloud/bin/get_template_version.sh
> 2013-01-23 01:06:44,899 DEBUG [vmware.resource.VmwareResource]
> (DirectAgent-108:torvms03lx.sigmasys.net) Use router's private IP for SSH
control. IP : 10.0.100.182
> 2013-01-23 01:06:45,138 ERROR [utils.ssh.SshHelper] (DirectAgent-
108:torvms03lx.sigmasys.net)
> Failed to authentication SSH user root on host 10.0.100.182
> 2013-01-23 01:06:45,139 ERROR [vmware.resource.VmwareResource]
> (DirectAgent-108:torvms03lx.sigmasys.net) GetDomRVersionCmd failed due to
Exception: java.lang.Exception
> Message: Failed to authentication SSH user root on host 10.0.100.182
>
> java.lang.Exception: Failed to authentication SSH user root on host
10.0.100.182
> at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
> at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
> at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.j
ava:1753)
> at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareRes
ource.java:433)
> at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:
191)
> 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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$
201(ScheduledThreadPoolExecutor.java:178)
> at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Sch
eduledThreadPoolExecutor.java:292)
> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:11
10)
> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6
03)
> at java.lang.Thread.run(Thread.java:722)
> 2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-108:null) Seq
> 2-2082210641: Cancelling because one of the answers is false and it is
stop on error.
> 2013-01-23 01:06:45,143 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-108:null) Seq
> 2-2082210641: Response Received:
> 2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (DirectAgent-
108:null) Seq 2-2082210641:
> Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110,
> [{"StartAnswer":{"vm":{"id":5,"name":"r-5-
VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"speed":500,"minRam":1
34217728,"maxRam":134217728,"arch":"i686","os":"Debian
> GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-5-VM
eth0ip=10.0.100.182
> eth0mask=255.255.255.0 gateway=10.0.100.1 domain=cs1cloud.internal
dhcprange=10.0.100.1
> eth1ip=0.0.0.0 eth1mask=0.0.0.0 sshonguest=true type=dhcpsrvr
disable_rp_filter=true
> extra_pubnics=2 dns1=10.0.100.5
>
nic_macs=06:12:00:00:00:08|02:00:4f:6b:00:08","rebootOnCrash":false,"enableH
A":true,"limitCpuUse":false,"vncPassword":"b8fdaa863d476636","params":
{"nicAdapter":"E1000"},"uuid":"04ee40b9-bd06-4814-b01e-
aa4928da5d96","disks":[{"id":6,"name":"ROOT-
5","mountPoint":"/CloudStack/tormsa02-raid0-4","path":"ROOT-
5","size":2097152000,"type":"ROOT","storagePoolType":"VMFS","storagePoolUuid
":"3546bfef-40ed-3f8f-9484-b5cd712235f8","deviceId":0}],"nics":
[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"e04d295a-
e633-407d-96e0-
aef8550df2d4","ip":"10.0.100.182","netmask":"255.255.255.0","gateway":"10.0.
100.1","mac":"06:12:00:00:00:08","dns1":"10.0.100.5","broadcastType":"Vlan",
"type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagg
ed","isSecurityGroupEnabled":false},
{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"31e1d523-79da-
40f7-b909-
47a0cce3e8cb","ip":"0.0.0.0","netmask":"0.0.0.0","gateway":"0.0.0.0","mac":"
02:00:4f:6b:00:08","broadcastType":"LinkLocal","type":"Control","isSecurityG
roupEnabled":false}]},"result":true,"wait":0}},{"check.CheckSshAnswer":
{"result":true,"wait":0}},{"GetDomRVersionAnswer":
{"result":false,"details":"GetDomRVersionCmd
> failed due to Exception: java.lang.Exception\nMessage: Failed to
authentication SSH user root on host
> 10.0.100.182\n","wait":0}}] }
> 2013-01-23 01:06:45,144 DEBUG [agent.manager.AgentAttache] (DirectAgent-
108:null) Seq
> 2-2082210641: No more commands found
> 2013-01-23 01:06:45,144 DEBUG [agent.transport.Request] (Job-Executor-
7:job-13) Seq
> 2-2082210641: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1,
Flags: 110, { StartAnswer,
> CheckSshAnswer, GetDomRVersionAnswer } }
> 2013-01-23 01:06:45,282 WARN
[network.router.VirtualNetworkApplianceManagerImpl]
> (Job-Executor-7:job-13) Unable to get the template/scripts version of
router r-5-VM due to:
> GetDomRVersionCmd failed due to Exception: java.lang.Exception
> Message: Failed to authentication SSH user root on host 10.0.100.182
>
> 2013-01-23 01:06:45,283 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-
Executor-7:job-13) The
> guru did not like the answers so stopping VM[DomainRouter|r-5-VM]
> 2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-
7:job-13) Seq
> 2-2082210644: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1,
Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
> 2013-01-23 01:06:45,287 DEBUG [agent.transport.Request] (Job-Executor-
7:job-13) Seq
> 2-2082210644: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1,
Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
> 2013-01-23 01:06:45,287 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-182:null) Seq
> 2-2082210644: Executing request
> 2013-01-23 01:06:45,288 INFO [vmware.resource.VmwareResource]
> (DirectAgent-182:torvms03lx.sigmasys.net) Executing resource StopCommand:
{"isProxy":false,"vmName":"r-5-VM","wait":0}
> 2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-
182:torvms03lx.sigmasys.net) find
> VM r-5-VM on host
> 2013-01-23 01:06:45,288 DEBUG [vmware.mo.HostMO] (DirectAgent-
182:torvms03lx.sigmasys.net) load
> VM cache on host
> 2013-01-23 01:06:46,211 INFO [vmware.resource.VmwareResource]
> (DirectAgent-182:torvms03lx.sigmasys.net) Remove all snapshot before
stopping VM r-5-VM
> 2013-01-23 01:06:46,595 DEBUG [cloud.server.StatsCollector]
(StatsCollector-2:null)
> VmStatsCollector is running...
> 2013-01-23 01:06:49,438 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers.
> 2013-01-23 01:06:53,877 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-8:null)
> Ping from 6
> 2013-01-23 01:06:54,281 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-182:null) Seq
> 2-2082210644: Response Received:
> 2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (DirectAgent-
182:null) Seq 2-2082210644:
> Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110,
> [{"StopAnswer":{"vncPort":0,"result":true,"details":"Stop VM r-5-VM
Succeed","wait":0}}] }
> 2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentAttache] (DirectAgent-
182:null) Seq
> 2-2082210644: No more commands found
> 2013-01-23 01:06:54,282 DEBUG [agent.transport.Request] (Job-Executor-
7:job-13) Seq
> 2-2082210644: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1,
Flags: 110, { StopAnswer } }
> 2013-01-23 01:06:54,282 DEBUG [agent.manager.AgentManagerImpl] (Job-
Executor-7:job-13) Details
> from executing class com.cloud.agent.api.StopCommand: Stop VM r-5-VM
Succeed
> 2013-01-23 01:06:54,282 ERROR [cloud.vm.VirtualMachineManagerImpl] (Job-
Executor-7:job-13)
> Failed to start instance VM[DomainRouter|r-5-VM]
> com.cloud.utils.exception.ExecutionException: Unable to start
VM[DomainRouter|r-5-VM] due to
> error in finalizeStart, not retrying
> at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImp
l.java:814)
> at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:
472)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNet
workApplianceManagerImpl.java:2352)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRout
er(VirtualNetworkApplianceManagerImpl.java:1597)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(Vir
tualNetworkApplianceManagerImpl.java:1697)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRou
terInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
> at
com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.
java:205)
> at
com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:
2056)
> at
com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172
)
> at
com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
> at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImp
l.java:752)
> at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:
472)
> at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:29
29)
> at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:26
01)
> at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:25
89)
> at
com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
> at
com.cloud.api.commands.DeployVMCmd.execute(DeployVMCmd.java:330)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
> at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
> 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:11
10)
> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6
03)
> at java.lang.Thread.run(Thread.java:722)
> 2013-01-23 01:06:54,797 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-
Executor-7:job-13)
> Cleaning up resources for the vm VM[DomainRouter|r-5-VM] in Starting state
> 2013-01-23 01:06:54,798 DEBUG [agent.transport.Request] (Job-Executor-
7:job-13) Seq
> 2-2082210645: Sending { Cmd , MgmtId: 345051758635, via: 2, Ver: v1,
Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
> 2013-01-23 01:06:54,969 DEBUG [agent.transport.Request] (Job-Executor-
7:job-13) Seq
> 2-2082210645: Executing: { Cmd , MgmtId: 345051758635, via: 2, Ver: v1,
Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
> 2013-01-23 01:06:54,969 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-173:null) Seq
> 2-2082210645: Executing request
> 2013-01-23 01:06:54,969 INFO [vmware.resource.VmwareResource]
> (DirectAgent-173:torvms03lx.sigmasys.net) Executing resource StopCommand:
{"isProxy":false,"vmName":"r-5-VM","wait":0}
> 2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-
173:torvms03lx.sigmasys.net) find
> VM r-5-VM on host
> 2013-01-23 01:06:54,969 DEBUG [vmware.mo.HostMO] (DirectAgent-
173:torvms03lx.sigmasys.net) load
> VM cache on host
> 2013-01-23 01:06:55,878 INFO [vmware.resource.VmwareResource]
> (DirectAgent-173:torvms03lx.sigmasys.net) VM r-5-VM is already in stopped
state
> 2013-01-23 01:06:55,879 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-173:null) Seq
> 2-2082210645: Response Received:
> 2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (DirectAgent-
173:null) Seq 2-2082210645:
> Processing: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1, Flags: 110,
> [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM r-5-VM is already
in stopped
> state","wait":0}}] }
> 2013-01-23 01:06:55,879 DEBUG [agent.manager.AgentAttache] (DirectAgent-
173:null) Seq
> 2-2082210645: No more commands found
> 2013-01-23 01:06:55,879 DEBUG [agent.transport.Request] (Job-Executor-
7:job-13) Seq
> 2-2082210645: Received: { Ans: , MgmtId: 345051758635, via: 2, Ver: v1,
Flags: 110, { StopAnswer } }
>
> 2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-
Executor-7:job-13)
> release cpu from host: 2, old used: 1500,reserved: 0, actual total: 48000,
total with overprovisioning:
> 48000; new used: 1000,reserved:0; movedfromreserved:
false,moveToReserveredfalse
> 2013-01-23 01:06:56,964 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-
Executor-7:job-13)
> release mem from host: 2, old used: 1476395008,reserved: 0, total:
34357202944; new used:
> 1342177280,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-01-23 01:06:56,986 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-
Executor-7:job-13)
> Unable to contact resource.
> com.cloud.exception.AgentUnavailableException: Resource [Host:2] is
unreachable: Host 2: Unable to
> start instance due to Unable to start VM[DomainRouter|r-5-VM] due to error
in finalizeStart, not retrying
> at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImp
l.java:847)
> at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:
472)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNet
workApplianceManagerImpl.java:2352)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRout
er(VirtualNetworkApplianceManagerImpl.java:1597)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(Vir
tualNetworkApplianceManagerImpl.java:1697)
> at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRou
terInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1675)
> at
com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.
java:205)
> at
com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:
2056)
> at
com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2172
)
> at
com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2113)
> at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImp
l.java:752)
> at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:
472)
> at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:29
29)
> at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:26
01)
> at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:25
89)
> at
com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
>
> Thanks and Regards.
>
> Asmita Patil Vagyani.
>
>