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

Reply via email to