Hi Sebastian, It sounds like you forgot to download the vhd-util. Either that, or you have not placed it at the right location. It's also possible that you must set it to executable (chmod +x vhd-util).
http://cloudstack.apache.org/docs/en-US/Apache_CloudStack/4.2.0/html/Installation_Guide/management-server-install-flow.html /Magnus 2013/11/29 Sebastian Trampler <sebastian.tramp...@iisys.de> > Hello, > > we have problems starting the ssvm. > > First of all some facts about our actual test system. > Cloudstack is installed on Ubuntu 12.04. Primary and secondary storage are > nfs shares hosted on Cloudstack server. > Host is a XenServer 6.2. > > While starting the ssvm we get the following error messages: > > 2013-11-29 08:38:10,103 DEBUG [storage.volume.VolumeServiceImpl] > (consoleproxy-1:null) Acquire lock on VMTemplateStoragePool 2280 with > timeout 3600 seconds > 2013-11-29 08:38:10,107 INFO [storage.volume.VolumeServiceImpl] > (consoleproxy-1:null) lock is acquired for VMTemplateStoragePool 2280 > 2013-11-29 08:38:10,109 DEBUG [cloud.storage.VolumeManagerImpl] > (secstorage-1:null) Checking if we need to prepare 1 volumes for > VM[SecondaryStorageVm|s-1159-VM] > 2013-11-29 08:38:10,135 DEBUG [storage.motion.AncientDataMotionStrategy] > (consoleproxy-1:null) copyAsync inspecting src type TEMPLATE copyAsync > inspecting dest type TEMPLATE > 2013-11-29 08:38:10,137 DEBUG [storage.image.TemplateDataFactoryImpl] > (secstorage-1:null) template 1 is already in store:2, type:Image > 2013-11-29 08:38:10,171 DEBUG [storage.image.TemplateDataFactoryImpl] > (secstorage-1:null) template 1 is already in store:2, type:Primary > 2013-11-29 08:38:10,174 DEBUG [storage.volume.VolumeServiceImpl] > (secstorage-1:null) Found template routing-1 in storage pool 2 with > VMTemplateStoragePool id: 2280 > 2013-11-29 08:38:10,185 DEBUG [agent.transport.Request] > (consoleproxy-1:null) Seq 1-1431371787: Sending { Cmd , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack. > storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to. > TemplateObjectTO":{"path":"template/tmpl/1/1/","origUrl":" > http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12- > master-xen.vhd.bz2","uuid":"82cd934b-4d43-11e3-8eab- > c63e476a579a","id":1,"format":"VHD","accountId":1,"checksum":" > fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM > Template (XenServer)","imageDataStore":{"com.cloud.agent.api.to. > NfsTO":{"_url":"nfs://172.16.51.47:/export/secondary2","_ > role":"Image"}},"name":"routing-1","hypervisorType":" > XenServer"}},"destTO":{"org.apache.cloudstack.storage.to. > TemplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.2/ > systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":" > 82cd934b-4d43-11e3-8eab-c63e476a579a","id":1,"format": > "VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d > 83","hvm":false,"displayText":"SystemVM Template > (XenServer)","imageDataStore":{"org.apache.cloudstack. > storage.to.PrimaryDataStoreTO":{"uuid":"fefdf148-d326-3fa0- > 9aca-3f8956fbd8f7","id":2,"poolType":"NetworkFilesystem", > "host":"172.16.51.47","path":"/export/primary2","port":2049} > },"name":"routing-1","hypervisorType":"XenServer"}}, > "executeInSequence":true,"wait":10800}}] } > 2013-11-29 08:38:10,187 DEBUG [agent.transport.Request] > (consoleproxy-1:null) Seq 1-1431371787: Executing: { Cmd , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack. > storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to. > TemplateObjectTO":{"path":"template/tmpl/1/1/","origUrl":" > http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12- > master-xen.vhd.bz2","uuid":"82cd934b-4d43-11e3-8eab- > c63e476a579a","id":1,"format":"VHD","accountId":1,"checksum":" > fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM > Template (XenServer)","imageDataStore":{"com.cloud.agent.api.to. > NfsTO":{"_url":"nfs://172.16.51.47:/export/secondary2","_ > role":"Image"}},"name":"routing-1","hypervisorType":" > XenServer"}},"destTO":{"org.apache.cloudstack.storage.to. > TemplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.2/ > systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":" > 82cd934b-4d43-11e3-8eab-c63e476a579a","id":1,"format": > "VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d > 83","hvm":false,"displayText":"SystemVM Template > (XenServer)","imageDataStore":{"org.apache.cloudstack. > storage.to.PrimaryDataStoreTO":{"uuid":"fefdf148-d326-3fa0- > 9aca-3f8956fbd8f7","id":2,"poolType":"NetworkFilesystem", > "host":"172.16.51.47","path":"/export/primary2","port":2049} > },"name":"routing-1","hypervisorType":"XenServer"}}, > "executeInSequence":true,"wait":10800}}] } > 2013-11-29 08:38:10,188 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-1:null) Seq 1-1431371787: Executing request > 2013-11-29 08:38:10,190 DEBUG [storage.volume.VolumeServiceImpl] > (secstorage-1:null) Acquire lock on VMTemplateStoragePool 2280 with timeout > 3600 seconds > 2013-11-29 08:38:12,360 WARN [xen.resource.XenServerStorageProcessor] > (DirectAgent-1:null) destoryVDIbyNameLabel failed due to there are 0 VDIs > with name cloud-0212d4f0-d5ca-4dc5-9071-25179ec8f8f8 > 2013-11-29 08:38:12,362 WARN [xen.resource.XenServerStorageProcessor] > (DirectAgent-1:null) can not create vdi in sr bd7cb192-5956-307f-c993- > f4ce268c39da > 2013-11-29 08:38:12,365 WARN [xen.resource.XenServerStorageProcessor] > (DirectAgent-1:null) Catch Exception > com.cloud.utils.exception.CloudRuntimeException > for template + due to com.cloud.utils.exception.CloudRuntimeException: > can not create vdi in sr bd7cb192-5956-307f-c993-f4ce268c39da > com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr > bd7cb192-5956-307f-c993-f4ce268c39da > at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor. > copy_vhd_from_secondarystorage(XenServerStorageProcessor.java:792) > at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor. > copyTemplateToPrimaryStorage(XenServerStorageProcessor.java:863) > at com.cloud.storage.resource.StorageSubsystemCommandHandler > Base.execute(StorageSubsystemCommandHandlerBase.java:70) > at com.cloud.storage.resource.StorageSubsystemCommandHandler > Base.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49) > at com.cloud.hypervisor.xen.resource.CitrixResourceBase. > executeRequest(CitrixResourceBase.java:621) > at com.cloud.hypervisor.xen.resource.XenServer56Resource. > executeRequest(XenServer56Resource.java:73) > at com.cloud.hypervisor.xen.resource.XenServer610Resource. > executeRequest(XenServer610Resource.java:104) > 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:701) > 2013-11-29 08:38:12,367 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-1:null) Seq 1-1431371787: Response Received: > 2013-11-29 08:38:12,368 DEBUG [agent.transport.Request] > (DirectAgent-1:null) Seq 1-1431371787: Processing: { Ans: , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack. > storage.command.CopyCmdAnswer":{"result":false,"details":"Catch Exception > com.cloud.utils.exception.CloudRuntimeException for template + due to > com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr > bd7cb192-5956-307f-c993-f4ce268c39da","wait":0}}] } > 2013-11-29 08:38:12,369 DEBUG [agent.transport.Request] > (consoleproxy-1:null) Seq 1-1431371787: Received: { Ans: , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } } > 2013-11-29 08:38:12,370 DEBUG [agent.manager.AgentAttache] > (DirectAgent-1:null) Seq 1-1431371787: No more commands found > 2013-11-29 08:38:12,404 INFO [storage.volume.VolumeServiceImpl] > (consoleproxy-1:null) releasing lock for VMTemplateStoragePool 2280 > 2013-11-29 08:38:12,405 WARN [utils.db.Merovingian2] > (consoleproxy-1:null) Was unable to find lock for the key > template_spool_ref2280 and thread id 1998200215 > 2013-11-29 08:38:12,406 DEBUG [cloud.storage.VolumeManagerImpl] > (consoleproxy-1:null) Unable to create Vol[2|vm=2|ROOT]:Catch Exception > com.cloud.utils.exception.CloudRuntimeException for template + due to > com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr > bd7cb192-5956-307f-c993-f4ce268c39da > 2013-11-29 08:38:12,406 INFO [cloud.vm.VirtualMachineManagerImpl] > (consoleproxy-1:null) Unable to contact resource. > com.cloud.exception.StorageUnavailableException: Resource [StoragePool:2] > is unreachable: Unable to create Vol[2|vm=2|ROOT]:Catch Exception > com.cloud.utils.exception.CloudRuntimeException for template + due to > com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr > bd7cb192-5956-307f-c993-f4ce268c39da > at com.cloud.storage.VolumeManagerImpl.recreateVolume( > VolumeManagerImpl.java:2544) > at com.cloud.storage.VolumeManagerImpl.prepare( > VolumeManagerImpl.java:2592) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart( > VirtualMachineManagerImpl.java:889) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:578) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:571) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy( > ConsoleProxyManagerImpl.java:556) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity( > ConsoleProxyManagerImpl.java:928) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool( > ConsoleProxyManagerImpl.java:1672) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool( > ConsoleProxyManagerImpl.java:157) > at com.cloud.vm.SystemVmLoadScanner.loadScan( > SystemVmLoadScanner.java:111) > 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:701) > 2013-11-29 08:38:12,420 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (consoleproxy-1:null) Cleaning up resources for the vm > VM[ConsoleProxy|v-2-VM] in Starting state > 2013-11-29 08:38:12,426 DEBUG [agent.transport.Request] > (consoleproxy-1:null) Seq 1-1431371788: Sending { Cmd , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api. > StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"v-2-VM","wait":0}}] > } > 2013-11-29 08:38:12,426 DEBUG [agent.transport.Request] > (consoleproxy-1:null) Seq 1-1431371788: Executing: { Cmd , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api. > StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"v-2-VM","wait":0}}] > } > 2013-11-29 08:38:12,427 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-6:null) Seq 1-1431371788: Executing request > 2013-11-29 08:38:12,523 INFO [xen.resource.CitrixResourceBase] > (DirectAgent-6:null) VM does not exist on XenServer8f6e5992-458e-4fe6- > 9559-439b81ca65b9 > 2013-11-29 08:38:12,524 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-6:null) Seq 1-1431371788: Response Received: > 2013-11-29 08:38:12,525 DEBUG [agent.transport.Request] > (DirectAgent-6:null) Seq 1-1431371788: Processing: { Ans: , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api. > StopAnswer":{"vncPort":0,"result":true,"details":"VM does not > exist","wait":0}}] } > 2013-11-29 08:38:12,525 DEBUG [agent.manager.AgentAttache] > (DirectAgent-6:null) Seq 1-1431371788: No more commands found > 2013-11-29 08:38:12,526 DEBUG [agent.transport.Request] > (consoleproxy-1:null) Seq 1-1431371788: Received: { Ans: , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 110, { StopAnswer } } > 2013-11-29 08:38:12,546 DEBUG [cloud.network.NetworkModelImpl] > (consoleproxy-1:null) Service SecurityGroup is not supported in the network > id=204 > 2013-11-29 08:38:12,567 DEBUG [cloud.network.NetworkManagerImpl] > (consoleproxy-1:null) Asking VirtualRouter to release > Nic[5-2-9cd70f9a-9622-49be-94c2-051974dd5b48-172.16.51.221] > 2013-11-29 08:38:12,576 DEBUG [network.guru.ControlNetworkGuru] > (consoleproxy-1:null) Released nic: NicProfile[6-2-null-null-null > 2013-11-29 08:38:12,603 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] > (consoleproxy-1:null) Releasing ip address for > reservationId=9cd70f9a-9622-49be-94c2-051974dd5b48, > instance=7 > 2013-11-29 08:38:12,605 DEBUG [network.guru.PodBasedNetworkGuru] > (consoleproxy-1:null) Released nic: NicProfile[7-2-null-null-null > 2013-11-29 08:38:12,618 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (consoleproxy-1:null) Successfully released network resources for the vm > VM[ConsoleProxy|v-2-VM] > 2013-11-29 08:38:12,619 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (consoleproxy-1:null) Successfully cleanued up resources for the vm > VM[ConsoleProxy|v-2-VM] in Starting state > 2013-11-29 08:38:12,625 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: [1] > 2013-11-29 08:38:12,628 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) DeploymentPlanner allocation algorithm: > com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_9e815cea@58b37561 > 2013-11-29 08:38:12,628 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) Trying to allocate a host and storage pools from > dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824 > 2013-11-29 08:38:12,628 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No > 2013-11-29 08:38:12,628 DEBUG [cloud.deploy.FirstFitPlanner] > (consoleproxy-1:null) Searching resources only under specified Pod: 1 > 2013-11-29 08:38:12,629 DEBUG [cloud.deploy.FirstFitPlanner] > (consoleproxy-1:null) Listing clusters in order of aggregate capacity, that > have (atleast one host with) enough CPU and RAM capacity under this Pod: 1 > 2013-11-29 08:38:12,652 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1 > 2013-11-29 08:38:12,652 DEBUG [allocator.impl.FirstFitAllocator] > (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 > pod:1 cluster:1 > 2013-11-29 08:38:12,662 DEBUG [allocator.impl.FirstFitAllocator] > (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts > to check for allocation: [Host[-1-Routing]] > 2013-11-29 08:38:12,668 DEBUG [allocator.impl.FirstFitAllocator] > (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation > after prioritization: [Host[-1-Routing]] > 2013-11-29 08:38:12,668 DEBUG [allocator.impl.FirstFitAllocator] > (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, > Ram=1024 > 2013-11-29 08:38:12,668 DEBUG [allocator.impl.FirstFitAllocator] > (consoleproxy-1:FirstFitRoutingAllocator) Host name: iisys-xen-02, > hostId: 1 is in avoid set, skipping this and trying other available hosts > 2013-11-29 08:38:12,668 DEBUG [allocator.impl.FirstFitAllocator] > (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 0 > suitable hosts > 2013-11-29 08:38:12,669 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) No suitable hosts found > 2013-11-29 08:38:12,669 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) No suitable hosts found under this Cluster: 1 > 2013-11-29 08:38:12,674 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] > (consoleproxy-1:null) Could not find suitable Deployment Destination for > this VM under any clusters, returning. > 2013-11-29 08:38:12,674 DEBUG [cloud.deploy.FirstFitPlanner] > (consoleproxy-1:null) Searching resources only under specified Pod: 1 > 2013-11-29 08:38:12,674 DEBUG [cloud.deploy.FirstFitPlanner] > (consoleproxy-1:null) Listing clusters in order of aggregate capacity, that > have (atleast one host with) enough CPU and RAM capacity under this Pod: 1 > 2013-11-29 08:38:12,678 DEBUG [cloud.deploy.FirstFitPlanner] > (consoleproxy-1:null) Removing from the clusterId list these clusters from > avoid set: [1] > 2013-11-29 08:38:12,678 DEBUG [cloud.deploy.FirstFitPlanner] > (consoleproxy-1:null) No clusters found after removing disabled clusters > and clusters in avoid list, returning. > 2013-11-29 08:38:12,702 DEBUG [cloud.capacity.CapacityManagerImpl] > (consoleproxy-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-11-29 08:38:12,723 DEBUG [cloud.capacity.CapacityManagerImpl] > (consoleproxy-1:null) Hosts's actual total CPU: 48000 and CPU after > applying overprovisioning: 48000 > 2013-11-29 08:38:12,723 DEBUG [cloud.capacity.CapacityManagerImpl] > (consoleproxy-1:null) Hosts's actual total RAM: 198565129728 and RAM after > applying overprovisioning: 198565134336 > 2013-11-29 08:38:12,724 DEBUG [cloud.capacity.CapacityManagerImpl] > (consoleproxy-1:null) release cpu from host: 1, old used: 1000,reserved: 0, > actual total: 48000, total with overprovisioning: 48000; new used: > 500,reserved:0; movedfromreserved: false,moveToReserveredfalse > 2013-11-29 08:38:12,724 DEBUG [cloud.capacity.CapacityManagerImpl] > (consoleproxy-1:null) release mem from host: 1, old used: > 1342177280,reserved: 0, total: 198565134336; new used: > 268435456,reserved:0; movedfromreserved: false,moveToReserveredfalse > 2013-11-29 08:38:12,739 WARN [cloud.consoleproxy.ConsoleProxyManagerImpl] > (consoleproxy-1:null) Exception while trying to start console proxy > com.cloud.exception.InsufficientServerCapacityException: Unable to create > a deployment for VM[ConsoleProxy|v-2-VM]Scope=interface > com.cloud.dc.DataCenter; id=1 > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart( > VirtualMachineManagerImpl.java:842) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:578) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:571) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy( > ConsoleProxyManagerImpl.java:556) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity( > ConsoleProxyManagerImpl.java:928) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool( > ConsoleProxyManagerImpl.java:1672) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool( > ConsoleProxyManagerImpl.java:157) > at com.cloud.vm.SystemVmLoadScanner.loadScan( > SystemVmLoadScanner.java:111) > 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:701) > 2013-11-29 08:38:15,198 INFO [storage.volume.VolumeServiceImpl] > (secstorage-1:null) Unable to acquire lock on VMTemplateStoragePool 2280 > 2013-11-29 08:38:15,202 ERROR [cloud.vm.VirtualMachineManagerImpl] > (secstorage-1:null) Failed to start instance VM[SecondaryStorageVm|s-1159- > VM] > java.lang.NullPointerException > at org.apache.cloudstack.storage.volume.VolumeServiceImpl. > createBaseImageAsync(VolumeServiceImpl.java:422) > at org.apache.cloudstack.storage.volume.VolumeServiceImpl. > createVolumeFromTemplateAsync(VolumeServiceImpl.java:569) > at com.cloud.storage.VolumeManagerImpl.recreateVolume( > VolumeManagerImpl.java:2536) > at com.cloud.storage.VolumeManagerImpl.prepare( > VolumeManagerImpl.java:2592) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart( > VirtualMachineManagerImpl.java:889) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:578) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:571) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl. > startSecStorageVm(SecondaryStorageManagerImpl.java:267) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl. > allocCapacity(SecondaryStorageManagerImpl.java:696) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool( > SecondaryStorageManagerImpl.java:1300) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool( > PremiumSecondaryStorageManagerImpl.java:123) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool( > PremiumSecondaryStorageManagerImpl.java:50) > 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:701) > 2013-11-29 08:38:15,217 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (secstorage-1:null) Cleaning up resources for the vm > VM[SecondaryStorageVm|s-1159-VM] in Starting state > 2013-11-29 08:38:15,223 DEBUG [agent.transport.Request] > (secstorage-1:null) Seq 1-1431371789: Sending { Cmd , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api. > StopCommand":{"isProxy":false,"executeInSequence":true," > vmName":"s-1159-VM","wait":0}}] } > 2013-11-29 08:38:15,223 DEBUG [agent.transport.Request] > (secstorage-1:null) Seq 1-1431371789: Executing: { Cmd , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api. > StopCommand":{"isProxy":false,"executeInSequence":true," > vmName":"s-1159-VM","wait":0}}] } > 2013-11-29 08:38:15,224 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-7:null) Seq 1-1431371789: Executing request > 2013-11-29 08:38:15,306 INFO [xen.resource.CitrixResourceBase] > (DirectAgent-7:null) VM does not exist on XenServer8f6e5992-458e-4fe6- > 9559-439b81ca65b9 > 2013-11-29 08:38:15,307 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-7:null) Seq 1-1431371789: Response Received: > 2013-11-29 08:38:15,308 DEBUG [agent.transport.Request] > (DirectAgent-7:null) Seq 1-1431371789: Processing: { Ans: , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api. > StopAnswer":{"vncPort":0,"result":true,"details":"VM does not > exist","wait":0}}] } > 2013-11-29 08:38:15,308 DEBUG [agent.manager.AgentAttache] > (DirectAgent-7:null) Seq 1-1431371789: No more commands found > 2013-11-29 08:38:15,308 DEBUG [agent.transport.Request] > (secstorage-1:null) Seq 1-1431371789: Received: { Ans: , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 110, { StopAnswer } } > 2013-11-29 08:38:15,329 DEBUG [cloud.network.NetworkModelImpl] > (secstorage-1:null) Service SecurityGroup is not supported in the network > id=204 > 2013-11-29 08:38:15,352 DEBUG [cloud.network.NetworkManagerImpl] > (secstorage-1:null) Asking VirtualRouter to release > Nic[4632-1159-00610b50-8d60-47fa-a951-a5f94ab71d1d-172.16.51.220] > 2013-11-29 08:38:15,360 DEBUG [network.guru.ControlNetworkGuru] > (secstorage-1:null) Released nic: NicProfile[4633-1159-null-null-null > 2013-11-29 08:38:15,388 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] > (secstorage-1:null) Releasing ip address for > reservationId=00610b50-8d60-47fa-a951-a5f94ab71d1d, > instance=4634 > 2013-11-29 08:38:15,390 DEBUG [network.guru.PodBasedNetworkGuru] > (secstorage-1:null) Released nic: NicProfile[4634-1159-null-null-null > 2013-11-29 08:38:15,419 DEBUG [network.guru.StorageNetworkGuru] > (secstorage-1:null) Release an storage ip 172.16.51.243 > 2013-11-29 08:38:15,432 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (secstorage-1:null) Successfully released network resources for the vm > VM[SecondaryStorageVm|s-1159-VM] > 2013-11-29 08:38:15,432 DEBUG [cloud.vm.VirtualMachineManagerImpl] > (secstorage-1:null) Successfully cleanued up resources for the vm > VM[SecondaryStorageVm|s-1159-VM] in Starting state > 2013-11-29 08:38:15,461 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-11-29 08:38:15,483 DEBUG [cloud.capacity.CapacityManagerImpl] > (secstorage-1:null) Hosts's actual total CPU: 48000 and CPU after applying > overprovisioning: 48000 > 2013-11-29 08:38:15,484 DEBUG [cloud.capacity.CapacityManagerImpl] > (secstorage-1:null) Hosts's actual total RAM: 198565129728 and RAM after > applying overprovisioning: 198565134336 > 2013-11-29 08:38:15,484 DEBUG [cloud.capacity.CapacityManagerImpl] > (secstorage-1:null) release cpu from host: 1, old used: 500,reserved: 0, > actual total: 48000, total with overprovisioning: 48000; new used: > 0,reserved:0; movedfromreserved: false,moveToReserveredfalse > 2013-11-29 08:38:15,484 DEBUG [cloud.capacity.CapacityManagerImpl] > (secstorage-1:null) release mem from host: 1, old used: 268435456,reserved: > 0, total: 198565134336; new used: 0,reserved:0; movedfromreserved: > false,moveToReserveredfalse > 2013-11-29 08:38:15,500 WARN [storage.secondary.SecondaryStorageManagerImpl] > (secstorage-1:null) Exception while trying to start secondary storage vm > com.cloud.exception.AgentUnavailableException: Resource [Host:1] is > unreachable: Host 1: Unable to start instance due to null > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart( > VirtualMachineManagerImpl.java:988) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:578) > at com.cloud.vm.VirtualMachineManagerImpl.start( > VirtualMachineManagerImpl.java:571) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl. > startSecStorageVm(SecondaryStorageManagerImpl.java:267) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl. > allocCapacity(SecondaryStorageManagerImpl.java:696) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool( > SecondaryStorageManagerImpl.java:1300) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool( > PremiumSecondaryStorageManagerImpl.java:123) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool( > PremiumSecondaryStorageManagerImpl.java:50) > 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:701) > Caused by: java.lang.NullPointerException > at org.apache.cloudstack.storage.volume.VolumeServiceImpl. > createBaseImageAsync(VolumeServiceImpl.java:422) > at org.apache.cloudstack.storage.volume.VolumeServiceImpl. > createVolumeFromTemplateAsync(VolumeServiceImpl.java:569) > at com.cloud.storage.VolumeManagerImpl.recreateVolume( > VolumeManagerImpl.java:2536) > at com.cloud.storage.VolumeManagerImpl.prepare( > VolumeManagerImpl.java:2592) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart( > VirtualMachineManagerImpl.java:889) > ... 20 more > 2013-11-29 08:38:15,504 INFO [storage.secondary.SecondaryStorageManagerImpl] > (secstorage-1:null) Unable to start secondary storage vm for standby > capacity, secStorageVm vm Id : 1159, will recycle it and start a new one > 2013-11-29 08:38:15,504 INFO [cloud.secstorage. > PremiumSecondaryStorageManagerImpl] (secstorage-1:null) Primary secondary > storage is not even started, wait until next turn > 2013-11-29 08:38:17,380 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-14:null) Ping from 1 > 2013-11-29 08:38:18,451 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-15:null) Seq 1-1431371781: Executing request > 2013-11-29 08:38:18,701 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-15:null) Seq 1-1431371781: Response Received: > 2013-11-29 08:38:18,703 DEBUG [agent.transport.Request] > (DirectAgent-15:null) Seq 1-1431371781: Processing: { Ans: , MgmtId: > 217970788423578, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api. > ClusterSyncAnswer":{"_clusterId":1,"_newStates":{}," > _isExecuted":false,"result":true,"wait":0}}] } > > > Many thanks in advance for your help! > > Best regards > > >
