Did you copy over vhd-util to the correct folder and chmod +x it?
On 18 Sep 2013 15:13, "Vadim Kimlaychuk" <vadim.kimlayc...@elion.ee> wrote:
> Hello all,
>
> Trying to install subj. several times I have decided to ask
> your help. May be someone already faced the same problem? I did the
> configuration according to “Installation guide” and always end up with the
> same problem: on system VM creation I got repeated errors like this:
>
> 2013-09-18 16:49:21,605 DEBUG [cloud.storage.StorageManagerImpl]
> (consoleproxy-1:null) Creating volume: Vol[2|vm=2|ROOT]
> 2013-09-18 16:49:21,605 DEBUG [cloud.storage.StorageManagerImpl]
> (consoleproxy-1:null) Trying to create in Pool[200|NetworkFilesystem]
> 2013-09-18 16:49:23,381 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-4:null) kill_copy_process failed
> 2013-09-18 16:49:23,381 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-4:null) can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> 2013-09-18 16:49:23,382 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-4:null) Catch Exception
> com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2707)
> at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2729)
> at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
> at
> com.cloud.hypervisor.xen.resource.XcpServerResource.executeRequest(XcpServerResource.java:51)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
> 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$101(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> 2013-09-18 16:49:23,384 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-4:null) Seq 1-1333067786: Response Received:
> 2013-09-18 16:49:23,385 DEBUG [agent.transport.Request]
> (DirectAgent-4:null) Seq 1-1333067786: Processing: { Ans: , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 110,
> [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch
> Exception com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6","wait":0}}] }
> 2013-09-18 16:49:23,385 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-1333067786: Received: { Ans: , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer
> } }
> 2013-09-18 16:49:23,385 DEBUG [agent.manager.AgentManagerImpl]
> (secstorage-1:null) Details from executing class
> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception
> com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> 2013-09-18 16:49:23,386 DEBUG [cloud.template.TemplateManagerImpl]
> (secstorage-1:null) Template 1 download to pool 200 failed due to Catch
> Exception com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> 2013-09-18 16:49:23,386 DEBUG [cloud.template.TemplateManagerImpl]
> (secstorage-1:null) Downloading 1 via 1
> 2013-09-18 16:49:23,394 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-4:null) Seq 1-1333067786: No more commands found
> 2013-09-18 16:49:23,411 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-1333067787: Sending { Cmd , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 100111,
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolUuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolId":200,"primaryPool":{"id":200,"uuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","host":"192.168.107.142","path":"/export/primary","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://
> 192.168.107.142/export/secondary","primaryStorageUrl":"nfs://
> 192.168.107.142/export/primary","url":"nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
> }
> 2013-09-18 16:49:23,412 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-1333067787: Executing: { Cmd , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 100111,
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolUuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolId":200,"primaryPool":{"id":200,"uuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","host":"192.168.107.142","path":"/export/primary","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://
> 192.168.107.142/export/secondary","primaryStorageUrl":"nfs://
> 192.168.107.142/export/primary","url":"nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
> }
> 2013-09-18 16:49:23,412 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-5:null) Seq 1-1333067787: Executing request
> 2013-09-18 16:49:25,604 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-5:null) kill_copy_process failed
> 2013-09-18 16:49:25,605 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-5:null) can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> 2013-09-18 16:49:25,605 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-5:null) Catch Exception
> com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2707)
> at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2729)
> at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
> at
> com.cloud.hypervisor.xen.resource.XcpServerResource.executeRequest(XcpServerResource.java:51)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
> 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$101(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> 2013-09-18 16:49:25,606 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-5:null) Seq 1-1333067787: Response Received:
> 2013-09-18 16:49:25,607 DEBUG [agent.transport.Request]
> (DirectAgent-5:null) Seq 1-1333067787: Processing: { Ans: , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 110,
> [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch
> Exception com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6","wait":0}}] }
> 2013-09-18 16:49:25,607 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-1333067787: Received: { Ans: , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer
> } }
> 2013-09-18 16:49:25,607 DEBUG [agent.manager.AgentManagerImpl]
> (secstorage-1:null) Details from executing class
> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception
> com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> 2013-09-18 16:49:25,607 DEBUG [cloud.template.TemplateManagerImpl]
> (secstorage-1:null) Template 1 download to pool 200 failed due to Catch
> Exception com.cloud.utils.exception.CloudRuntimeException on
> host:e6a339ee-521c-4c67-ac55-cbd256607150 for template: nfs://
> 192.168.107.142/export/secondary/template/tmpl/1/1/ due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
> 2013-09-18 16:49:25,608 DEBUG [cloud.template.TemplateManagerImpl]
> (secstorage-1:null) Template 1 is not found on and can not be downloaded to
> pool 200
> 2013-09-18 16:49:25,608 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Cannot use this pool Pool[200|NetworkFilesystem]
> because we can't propagate template Tmpl[1-VHD-routing-1
> 2013-09-18 16:49:25,612 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-5:null) Seq 1-1333067787: No more commands found
> 2013-09-18 16:49:25,618 INFO [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Unable to contact resource.
> com.cloud.exception.StorageUnavailableException: Resource
> [StoragePool:200] is unreachable: Unable to create Vol[1|vm=1|ROOT]
> at
> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3488)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:748)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
> at
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
> at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
> at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
> at
> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
> at
> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> 2013-09-18 16:49:25,625 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Cleaning up resources for the vm
> VM[SecondaryStorageVm|s-1-VM] in Starting state
> 2013-09-18 16:49:25,627 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-1333067788: Sending { Cmd , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"s-1-VM","wait":0}}] }
> 2013-09-18 16:49:25,628 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-1333067788: Executing: { Cmd , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"s-1-VM","wait":0}}] }
> 2013-09-18 16:49:25,628 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-6:null) Seq 1-1333067788: Executing request
> 2013-09-18 16:49:25,640 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-5:null) ===START=== 192.168.107.75 -- GET
>
> command=listSystemVms&response=json&sessionkey=zvxEneqJ%2FkCeNEEDUkDxJiXnhBc%3D&_=1379512165664
> 2013-09-18 16:49:25,689 INFO [xen.resource.CitrixResourceBase]
> (DirectAgent-6:null) VM does not exist on
> XenServere6a339ee-521c-4c67-ac55-cbd256607150
> 2013-09-18 16:49:25,690 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-6:null) Seq 1-1333067788: Response Received:
> 2013-09-18 16:49:25,690 DEBUG [agent.transport.Request]
> (DirectAgent-6:null) Seq 1-1333067788: Processing: { Ans: , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 110,
> [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does not
> exist","wait":0}}] }
> 2013-09-18 16:49:25,690 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-1333067788: Received: { Ans: , MgmtId:
> 8796752993784, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
> 2013-09-18 16:49:25,692 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-6:null) Seq 1-1333067788: No more commands found
> 2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
> 2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
> 2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
> 2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
> 2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
> 2013-09-18 16:49:25,716 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network defaultGuestNetwork
> 2013-09-18 16:49:25,721 DEBUG [network.guru.ControlNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[2-1-null-null-null
> 2013-09-18 16:49:25,724 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,725 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
> 2013-09-18 16:49:25,733 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> (secstorage-1:null) Releasing ip address for
> reservationId=7ab6fd6f-027f-4e3d-b70d-78474d479424, instance=3
> 2013-09-18 16:49:25,735 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[3-1-null-null-null
> 2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,740 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
> 2013-09-18 16:49:25,749 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> (secstorage-1:null) Releasing ip address for
> reservationId=7ab6fd6f-027f-4e3d-b70d-78474d479424, instance=4
> 2013-09-18 16:49:25,751 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[4-1-null-null-null
> 2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
> 2013-09-18 16:49:25,753 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
> 2013-09-18 16:49:25,753 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Successfully released network resources for the vm
> VM[SecondaryStorageVm|s-1-VM]
> 2013-09-18 16:49:25,754 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Successfully cleanued up resources for the vm
> VM[SecondaryStorageVm|s-1-VM] in Starting state
> 2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) DeploymentPlanner allocation algorithm: random
> 2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
> pod:null,cluster:null, requested cpu: 500, requested ram: 268435456
> 2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
> 2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Searching all possible resources under this Zone: 1
> 2013-09-18 16:49:25,759 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Listing clusters in order of aggregate capacity, that
> have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
> 2013-09-18 16:49:25,762 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
> 2013-09-18 16:49:25,776 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
> 2013-09-18 16:49:25,776 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
> cluster:1
> 2013-09-18 16:49:25,779 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
> check for allocation: [Host[-1-Routing]]
> 2013-09-18 16:49:25,788 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
> prioritization: [Host[-1-Routing]]
> 2013-09-18 16:49:25,789 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
> 2013-09-18 16:49:25,789 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Host name: xen4export, hostId: 1 is
> in avoid set, skipping this and trying other available hosts
> 2013-09-18 16:49:25,789 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0 suitable
> hosts
> 2013-09-18 16:49:25,789 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) No suitable hosts found
> 2013-09-18 16:49:25,789 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) No suitable hosts found under this Cluster: 1
> 2013-09-18 16:49:25,789 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Could not find suitable Deployment Destination for this
> VM under any clusters, returning.
> 2013-09-18 16:49:25,807 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) VM state transitted from :Starting to Stopped with
> event: OperationFailedvm's original host id: null new host id: null host id
> before state transition: 1
> 2013-09-18 16:49:25,820 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) Hosts's actual total CPU: 11732 and CPU after applying
> overprovisioning: 11732
> 2013-09-18 16:49:25,820 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) release cpu from host: 1, old used: 1000,reserved: 0,
> actual total: 11732, total with overprovisioning: 11732; new used:
> 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-09-18 16:49:25,820 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) release mem from host: 1, old used:
> 1342177280,reserved: 0, total: 12056611392; new used:
> 1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-09-18 16:49:25,825 WARN
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
> Exception while trying to start secondary storage vm
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM[SecondaryStorageVm|s-1-VM]Scope=interface
> com.cloud.dc.DataCenter; id=1
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:728)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
> at
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
> at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
> at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
> at
> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
> at
> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
> 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)
>
> Please, help to find the root of the problem
>
> Thank you,
>
> Vadim Kimlaychuk
>
