Hello,
We are currently working with Cloudstack 4.0.2 on a single zone/pod/cluster
setup with 4 hosts (CentOS 6, KVM)and one storage appliance (FreeNAS) serving
as primary storage and secondary storage. We recently experienced problems with
our system's primary storage's file system to the point that we needed to
rebuild it. We've also had to replace our secondary storage by creating a new
NFS share that we've re-imported all of our templates and ISOs to. With all of
these changes, we've recreated the SSVM multiple times to reflect the new
Secondary Storage settings.
The issue that we're currently experiencing is that data from Secondary Storage
doesn't seem to be able to transfer to Primary Storage. When we try to create a
VM from a template, the creation fails. The errors seen in management.log are
the first group of logs below.
With this failed attempt, the database table template_spool_ref adds a row with
the correct template_id, but with the download_pct=0 and state="NOT
DOWNLOADED". We encountered a similar issue even just getting the System VM
template onto Secondary Storage with the included script, where the template is
added to secondary storage, but the database and primary storage do not reflect
it being cached locally in /mnt/primary. We had to manually copy the System VM
Template to /mnt/primary and rename it to what the database expected to be in
/mnt/primary just to get our Secondary Storage VM to be created.
We are unable to create VMs from ISOs as well, reinforcing the notion that
there is an issue with accessing Secondary Storage. These errors are in the
second group of logs below. Attaching an ISO to a working VM also makes it
unable to start.
However, when accessing the SSVM, we can see that our single Secondary Storage
is successfully mounted and accessible at
/mnt/SecStorage/41a329bb-e5aa-3e98-892f-d5cfb582114c. ssvm-check.sh also
reveals no errors. The machine hosting Secondary storage is also able to
successfully ping the SSVM, and all files and directories have 777 permissions.
At this point, our suspicion is that there is an issue with bringing
templates/ISOs from Secondary Storage down to primary storage, but we have no
idea what could be causing it. Any and all help would be greatly appreciated.
Thanks in advance,
Alex Lee
Errors when creating VM from template:
2014-03-18 12:50:01,486 DEBUG [agent.manager.AgentManagerImpl]
(Job-Executor-116:job-554) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException:
Storage volume not found: no storage vol with matching name
'd8934d71-65b4-3a64-ad4d-f1c1605637d2.qcow2'
2014-03-18 12:50:01,486 DEBUG [cloud.template.TemplateManagerImpl]
(Job-Executor-116:job-554) Template 337 download to pool 206 failed due to
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException:
Storage volume not found: no storage vol with matching name
'd8934d71-65b4-3a64-ad4d-f1c1605637d2.qcow2'
2014-03-18 12:50:01,486 DEBUG [cloud.template.TemplateManagerImpl]
(Job-Executor-116:job-554) Downloading 337 via 1
2014-03-18 12:50:01,490 DEBUG [agent.transport.Request]
(Job-Executor-116:job-554) Seq 1-890971889: Sending { Cmd , MgmtId:
161331456390, via: 1, Ver: v1, Flags: 100111,
[{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/fd7aa037-9a5c-38fe-8e22-e454debe78f0","poolUuid":"53698317-909d-4caf-b383-0b1056a67152","poolId":206,"secondaryStorageUrl":"nfs://san01.aitecd.us.gov/mnt/U1Volume/secondaryStorage","primaryStorageUrl":"nfs://localhost/mnt/primary","url":"nfs://san01.aitecd.us.gov/mnt/U1Volume/secondaryStorage/template/tmpl//2/337//d8934d71-65b4-3a64-ad4d-f1c1605637d2.qcow2","format":"QCOW2","accountId":2,"name":"337-2-3904c94e-83a6-3f00-a2aa-e3f28168cab2","wait":10800}}]
}
2014-03-18 12:50:01,610 DEBUG [agent.transport.Request]
(AgentManager-Handler-7:null) Seq 1-890971889: Processing: { Ans: , MgmtId:
161331456390, via: 1, Ver: v1, Flags: 110,
[{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name 'd8934d71-65b4-3a64-ad4d-f1c1605637d2.qcow2'","wait":0}}] }
2014-03-18 12:50:01,610 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-7:null) Seq 1-890971889: No more commands found
2014-03-18 12:50:01,610 DEBUG [agent.transport.Request]
(Job-Executor-116:job-554) Seq 1-890971889: Received: { Ans: , MgmtId:
161331456390, via: 1, Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
2014-03-18 12:50:01,610 DEBUG [agent.manager.AgentManagerImpl]
(Job-Executor-116:job-554) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException:
Storage volume not found: no storage vol with matching name
'd8934d71-65b4-3a64-ad4d-f1c1605637d2.qcow2'
2014-03-18 12:50:01,610 DEBUG [cloud.template.TemplateManagerImpl]
(Job-Executor-116:job-554) Template 337 download to pool 206 failed due to
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException:
Storage volume not found: no storage vol with matching name
'd8934d71-65b4-3a64-ad4d-f1c1605637d2.qcow2'
2014-03-18 12:50:01,611 DEBUG [cloud.template.TemplateManagerImpl]
(Job-Executor-116:job-554) Template 337 is not found on and can not be
downloaded to pool 206
2014-03-18 12:50:01,611 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-116:job-554) Cannot use this pool Pool[206|SharedMountPoint]
because we can't propagate template
Tmpl[337-QCOW2-337-2-3904c94e-83a6-3f00-a2aa-e3f28168cab2
2014-03-18 12:50:01,617 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-116:job-554) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:206] is
unreachable: Unable to create Vol[1344|vm=1240|ROOT]
at
com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3361)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
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:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
Errors when creating VM with ISO:
2014-03-18 13:20:30,139 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking Ovs to prepare for
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,139 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking ExternalDhcpServer to prepare for
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,141 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking BareMetal to prepare for
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,141 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking SecurityGroupProvider to prepare for
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,144 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking CiscoNexus1000vVSM to prepare for
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,144 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking VpcVirtualRouter to prepare for
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,144 WARN [network.element.VpcVirtualRouterElement]
(Job-Executor-119:job-557) Network Ntwk[204|Guest|6] is not associated with any
VPC
2014-03-18 13:20:30,149 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking NiciraNvp to prepare for
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,155 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-119:job-557) Checking if we need to prepare 1 volumes for
VM[User|dc-new]
2014-03-18 13:20:30,160 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-119:job-557) Creating volume: Vol[1345|vm=1241|ROOT]
2014-03-18 13:20:30,160 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-119:job-557) Trying to create in Pool[206|SharedMountPoint]
2014-03-18 13:20:30,167 DEBUG [agent.transport.Request]
(Job-Executor-119:job-557) Seq 10-328016044: Sending { Cmd , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 100111,
[{"storage.CreateCommand":{"volId":1345,"pool":{"id":206,"uuid":"53698317-909d-4caf-b383-0b1056a67152","host":"localhost","path":"/mnt/primary","port":0,"type":"SharedMountPoint"},"diskCharacteristics":{"size":53687091200,"tags":[],"type":"ROOT","name":"ROOT-1241","useLocalStorage":false,"recreatable":false,"diskOfferingId":44,"volumeId":1345,"hyperType":"KVM"},"wait":0}}]
}
2014-03-18 13:20:30,469 DEBUG [agent.transport.Request]
(AgentManager-Handler-3:null) Seq 10-328016044: Processing: { Ans: , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 110,
[{"storage.CreateAnswer":{"volume":{"id":1345,"name":"/mnt/primary","mountPoint":"e2b921f9-801a-43ad-af3e-6ab1b9c042ea","path":"e2b921f9-801a-43ad-af3e-6ab1b9c042ea","size":53687091200,"type":"ROOT","storagePoolType":"SharedMountPoint","storagePoolUuid":"53698317-909d-4caf-b383-0b1056a67152","deviceId":0},"requestTemplateReload":false,"result":true,"wait":0}}]
}
2014-03-18 13:20:30,469 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-3:null) Seq 10-328016044: No more commands found
2014-03-18 13:20:30,470 DEBUG [agent.transport.Request]
(Job-Executor-119:job-557) Seq 10-328016044: Received: { Ans: , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 110, { CreateAnswer } }
2014-03-18 13:20:30,475 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-119:job-557) Volume Vol[1345|vm=1241|ROOT] is created on
Pool[206|SharedMountPoint]
2014-03-18 13:20:30,489 DEBUG [agent.transport.Request]
(Job-Executor-119:job-557) Seq 10-328016045: Sending { Cmd , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 100111,
[{"StartCommand":{"vm":{"id":1241,"name":"i-2-1241-VM","type":"User","cpus":1,"speed":2000,"minRam":2147483648,"maxRam":2147483648,"arch":"x86_64","os":"Windows
Server 2008 R2
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"a4b6257af0c390fe","params":{},"uuid":"c718d3fe-965e-4a7d-aad4-6409ccbb3f56","disks":[{"id":1345,"name":"/mnt/primary","mountPoint":"e2b921f9-801a-43ad-af3e-6ab1b9c042ea","path":"e2b921f9-801a-43ad-af3e-6ab1b9c042ea","size":53687091200,"type":"ROOT","storagePoolType":"SharedMountPoint","storagePoolUuid":"53698317-909d-4caf-b383-0b1056a67152","deviceId":0},{"id":1241,"name":"Windows
Server 2008
AGM","path":"nfs://san01.aitecd.us.gov/mnt/U1Volume/secondaryStorage/template/tmpl//2/331//331-2-b6d4b70d-fa70-3937-838b-f07e52da2283.iso","size":0,"type":"ISO","storagePoolType":"ISO","deviceId":3,"guestOsType":"Windows
Server 2008 R2
(64-bit)"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"d7d19741-47b5-4f89-b73f-fa42163e2d00","ip":"172.16.42.85","netmask":"255.255.0.0","gateway":"172.16.42.1","mac":"06:e8:ec:00:00:4a","dns1":"172.16.42.69","dns2":"172.16.42.70","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false}]},"wait":0}}]
}
2014-03-18 13:20:30,562 DEBUG [agent.transport.Request]
(AgentManager-Handler-11:null) Seq 10-328016045: Processing: { Ans: , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 110,
[{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:3943)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2730)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2855)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1061)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2014-03-18 13:20:30,562 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-11:null) Seq 10-328016045: No more commands found
2014-03-18 13:20:30,562 DEBUG [agent.transport.Request]
(Job-Executor-119:job-557) Seq 10-328016045: Received: { Ans: , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 110, { Answer } }
2014-03-18 13:20:30,567 ERROR [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-119:job-557) Failed to start instance VM[User|dc-new]
com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is
of class com.cloud.agent.api.StartAnswer
at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:783)
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:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2014-03-18 13:20:30,572 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-119:job-557) Cleaning up resources for the vm VM[User|dc-new] in
Starting state
2014-03-18 13:20:30,573 DEBUG [agent.transport.Request]
(Job-Executor-119:job-557) Seq 10-328016046: Sending { Cmd , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 100111,
[{"StopCommand":{"isProxy":false,"vmName":"i-2-1241-VM","wait":0}}] }
2014-03-18 13:20:30,783 DEBUG [agent.transport.Request]
(AgentManager-Handler-15:null) Seq 10-328016046: Processing: { Ans: , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2014-03-18 13:20:30,783 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-15:null) Seq 10-328016046: No more commands found
2014-03-18 13:20:30,783 DEBUG [agent.transport.Request]
(Job-Executor-119:job-557) Seq 10-328016046: Received: { Ans: , MgmtId:
161331456390, via: 10, Ver: v1, Flags: 110, { StopAnswer } }
2014-03-18 13:20:30,795 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Changing active number of nics for network id=204 on
-1
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking JuniperSRX to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking Netscaler to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking F5BigIP to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking VirtualRouter to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking Ovs to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking ExternalDhcpServer to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking BareMetal to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking SecurityGroupProvider to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking CiscoNexus1000vVSM to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking VpcVirtualRouter to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-119:job-557) Asking NiciraNvp to release
Nic[4007-1241-7fff009b-a5f8-48a4-8452-94d386853820-172.16.42.85]
2014-03-18 13:20:30,799 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-119:job-557) Successfully released network resources for the vm
VM[User|dc-new]
2014-03-18 13:20:30,799 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-119:job-557) Successfully cleanued up resources for the vm
VM[User|dc-new] in Starting state
2014-03-18 13:20:30,808 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-119:job-557) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original host id: null new host id: null host id
before state transition: 10
2014-03-18 13:20:30,811 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-119:job-557) Hosts's actual total CPU: 57600 and CPU after
applying overprovisioning: 57600
2014-03-18 13:20:30,811 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-119:job-557) release cpu from host: 10, old used: 6100,reserved:
0, actual total: 57600, total with overprovisioning: 57600; new used:
4100,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-18 13:20:30,811 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-119:job-557) release mem from host: 10, old used:
7516192768,reserved: 0, total: 203097681920; new used: 5368709120,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2014-03-18 13:20:30,816 DEBUG [cloud.vm.UserVmManagerImpl]
(Job-Executor-119:job-557) Destroying vm VM[User|dc-new] as it failed to create
2014-03-18 13:20:30,826 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-119:job-557) VM state transitted from :Stopped to Error with
event: OperationFailedToErrorvm's original host id: null new host id: null host
id before state transition: null
2014-03-18 13:20:30,865 WARN [api.commands.DeployVMCmd]
(Job-Executor-119:job-557) Exception:
com.cloud.exception.AgentUnavailableException: Resource [Host:10] is
unreachable: Host 10: Unable to start instance due to Unable to get answer that
is of class com.cloud.agent.api.StartAnswer
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
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:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Unable to get
answer that is of class com.cloud.agent.api.StartAnswer
at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:783)
... 18 more