Yes. vhd-util needs to be copied in the hypervisor host under /opt/xensource/bin
-Koushik On 18-Sep-2013, at 8:55 PM, Vadim Kimlaychuk <[email protected]> wrote: > Do you mean I have to copy vhd-util to the server where XCP is installed? > What should be the right path there? > > Vadim > ________________________________________ > From: Carlos Reátegui [[email protected]] > Sent: Wednesday, September 18, 2013 18:15 > To: [email protected] > Cc: [email protected] > Subject: Re: Cloudstack 4.1.1 + XCP 1.6 fresh install > > On a recent install of CS4.1.1 + XS6.1 I thought I had vhd-util in the right > place but it did not get copied to the hosts. It maybe a similar issue here. > > Try to copy the vhd-util to the hosts and see if things start working. They > did for me. > > On Sep 18, 2013, at 7:28 AM, Vadim Kimlaychuk <[email protected]> > wrote: > >> 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:[email protected]] >> Sent: Wednesday, September 18, 2013 5:26 PM >> To: [email protected] >> 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" <[email protected]> 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 >>>
