Yes, its over there (I have Ubuntu 12.04 LTS) : root@mgmt4xcp:/home/vadim# ls -al /usr/share/cloudstack-common/scripts/vm/hypervisor/xenserver/vh* -rwxr-xr-x 1 root root 318977 Sep 18 15:55 /usr/share/cloudstack-common/scripts/vm/hypervisor/xenserver/vhd-util
Vadim -----Original Message----- From: Ian Duffy [mailto:i...@ianduffy.ie] Sent: Wednesday, September 18, 2013 5:26 PM To: users@cloudstack.apache.org Subject: Re: Cloudstack 4.1.1 + XCP 1.6 fresh install 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":fa > lse,"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-c0137 > 77b0e36","poolId":200,"primaryPool":{"id":200,"uuid":"964f362d-c1cf-3e > 3b-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","a > ccountId":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-c0137 > 77b0e36","poolId":200,"primaryPool":{"id":200,"uuid":"964f362d-c1cf-3e > 3b-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","a > ccountId":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":fa > lse,"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%2FkCeNEEDUkDxJ > iXnhBc%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 >