You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users-cn@cloudstack.apache.org by "yingkailiu@163.com" <yi...@163.com> on 2015/02/04 04:44:56 UTC
删除所有host节点后，无法再添加节点重建环境。
部署模式：高级网络，NFS共享存储
机器情况：一个管理节点，两个计算节点
场景：删除了所有的host节点后，再添加host，ssvm 和cpvm 不能启动
详细错误日志是：
2015-02-04 11:25:42,357 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2015-02-04 11:25:42,357 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Checking if host: 7 can access any suitable storage pool for volume: ROOT
2015-02-04 11:25:42,358 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Host: 7 can access pool: 1
2015-02-04 11:25:42,358 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Found a potential host id: 7 name: kruihost-102 and associated storage pools for this VM
2015-02-04 11:25:42,359 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(76|ROOT-->Pool(1))]
2015-02-04 11:25:42,359 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Deployment found - P0=VM[ConsoleProxy|v-75-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(76|ROOT-->Pool(1))]
2015-02-04 11:25:42,359 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:42,359 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:42,361 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:42,362 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:42,362 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2015-02-04 11:25:42,365 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host: 7 has cpu capability (cpu:4, speed:3192) to support requested CPU: 1 and requested speed: 500
2015-02-04 11:25:42,365 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Checking if host: 7 has enough capacity for requested CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Free CPU: 12768 , Requested CPU: 500
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Free RAM: 7464352768 , Requested RAM: 536870912
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host has enough CPU and RAM available
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 7, used: 0, reserved: 0, actual total: 12768, total with overprovisioning: 12768; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 7, used: 0, reserved: 0, total: 7464352768; requested mem: 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-02-04 11:25:42,366 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found a suitable host, adding to list: 7
2015-02-04 11:25:42,366 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2015-02-04 11:25:42,366 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking suitable pools for volume (Id, Type): (79,ROOT)
2015-02-04 11:25:42,366 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) We need to allocate new storagepool for this volume
2015-02-04 11:25:42,367 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Calling StoragePoolAllocators to find suitable pools
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) ClusterScopeStoragePoolAllocator looking for storage pool
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Looking for pools in dc: 1 pod:1 cluster:1
2015-02-04 11:25:42,368 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Found pools matching tags: [Pool[1|NetworkFilesystem]]
2015-02-04 11:25:42,368 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Removing pool Pool[1|NetworkFilesystem] from avoid set, must have been inserted when searching for another disk's tag
2015-02-04 11:25:42,369 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Checking if storage pool is suitable, name: null ,poolId: 1
2015-02-04 11:25:42,373 DEBUG [c.c.s.StorageManagerImpl] (secstorage-1:ctx-c4d874ed) Checking pool: 1 for volume allocation [Vol[79|vm=78|ROOT]], maxSize : 1854509940736, totalAllocatedSize : 180052845568, askingSize : 2626564608, allocated disable threshold: 0.85
2015-02-04 11:25:42,374 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking if host: 7 can access any suitable storage pool for volume: ROOT
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Host: 7 can access pool: 1
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Found a potential host id: 7 name: kruihost-102 and associated storage pools for this VM
2015-02-04 11:25:42,375 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(79|ROOT-->Pool(1))]
2015-02-04 11:25:42,375 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Deployment found - P0=VM[SecondaryStorageVm|s-78-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(79|ROOT-->Pool(1))]
2015-02-04 11:25:42,419 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 7 host id before state transition: null
2015-02-04 11:25:42,424 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,424 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) We are allocating VM, increasing the used capacity of this host:7
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Current Used CPU: 0 , Free CPU:12768 ,Requested CPU: 500
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Current Used RAM: 0 , Free RAM:7464352768 ,Requested RAM: 1073741824
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) CPU STATS after allocation: for host: 7, old used: 0, old reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) RAM STATS after allocation: for host: 7, old used: 0, old reserved: 0, total: 7464352768; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2015-02-04 11:25:42,440 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 7 host id before state transition: null
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) We are allocating VM, increasing the used capacity of this host:7
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Current Used CPU: 500 , Free CPU:12268 ,Requested CPU: 500
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Current Used RAM: 1073741824 , Free RAM:6390610944 ,Requested RAM: 536870912
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) CPU STATS after allocation: for host: 7, old used: 500, old reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) RAM STATS after allocation: for host: 7, old used: 1073741824, old reserved: 0, total: 7464352768; new used: 1610612736, reserved: 0; requested mem: 536870912,alloc_from_last:false
2015-02-04 11:25:42,465 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM is being created in podId: 1
2015-02-04 11:25:42,470 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=200 is already implemented
2015-02-04 11:25:42,490 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) VM is being created in podId: 1
2015-02-04 11:25:42,495 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=200 is already implemented
2015-02-04 11:25:42,519 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=202 is already implemented
2015-02-04 11:25:42,543 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=202 is already implemented
2015-02-04 11:25:42,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=201 is already implemented
2015-02-04 11:25:42,677 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=201 is already implemented
2015-02-04 11:25:42,724 DEBUG [c.c.n.g.PodBasedNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Allocated a nic NicProfile[272-75-a0c0fadc-c528-410e-b52e-8fc63e996d7f-192.168.1.36-null for VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:42,740 DEBUG [c.c.n.g.PodBasedNetworkGuru] (secstorage-1:ctx-c4d874ed) Allocated a nic NicProfile[283-78-3a09b82f-53f1-4516-ab86-4408c3114336-192.168.1.40-null for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,760 DEBUG [o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Checking if we need to prepare 1 volumes for VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:42,768 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (consoleproxy-1:ctx-7fe8ff91) template 1 is already in store:1, type:Image
2015-02-04 11:25:42,770 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (consoleproxy-1:ctx-7fe8ff91) template 1 is already in store:1, type:Primary
2015-02-04 11:25:42,776 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=203 is already implemented
2015-02-04 11:25:42,850 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (consoleproxy-1:ctx-7fe8ff91) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
2015-02-04 11:25:42,857 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"41eb998b-ad48-48ce-ab02-b75284147577","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-75","size":2626564608,"volumeId":76,"vmName":"v-75-VM","accountId":1,"format":"VHD","id":76,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:42,858 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"41eb998b-ad48-48ce-ab02-b75284147577","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-75","size":2626564608,"volumeId":76,"vmName":"v-75-VM","accountId":1,"format":"VHD","id":76,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:42,858 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Executing request
2015-02-04 11:25:42,870 DEBUG [c.c.n.g.StorageNetworkGuru] (secstorage-1:ctx-c4d874ed) Allocated a storage nic NicProfile[284-78-3a09b82f-53f1-4516-ab86-4408c3114336-192.168.1.50-null for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,936 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-82:ctx-6287cd89) Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:42,936 WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-82:ctx-6287cd89) Unable to create volume; Pool=volumeTO[uuid=41eb998b-ad48-48ce-ab02-b75284147577|path=null|datastore=PrimaryDataStoreTO[uuid=302666f4-bbe7-334d-80da-35834c6e9662|name=null|id=1|pooltype=NetworkFilesystem]]; Disk:
com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:874)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.cloneVolumeFromBaseTemplate(XenServerStorageProcessor.java:987)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:78)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:609)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: The uuid you supplied was invalid.
at com.xensource.xenapi.Types.checkResponse(Types.java:927)
at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
at com.xensource.xenapi.VDI.getByUuid(VDI.java:326)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:870)
... 19 more
2015-02-04 11:25:42,937 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Response Received:
2015-02-04 11:25:42,938 DEBUG [c.c.a.t.Request] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.","wait":0}}] }
2015-02-04 11:25:42,938 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2015-02-04 11:25:42,978 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Checking if we need to prepare 1 volumes for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,986 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (secstorage-1:ctx-c4d874ed) template 1 is already in store:1, type:Image
2015-02-04 11:25:42,988 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (secstorage-1:ctx-c4d874ed) template 1 is already in store:1, type:Primary
2015-02-04 11:25:43,000 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@54854c57), no need to delete from object in store ref table
2015-02-04 11:25:43,001 DEBUG [o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Unable to create Vol[76|vm=75|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,001 INFO [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[76|vm=75|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1202)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1254)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:962)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:555)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:941)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1666)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:118)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,049 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Cleaning up resources for the vm VM[ConsoleProxy|v-75-VM] in Starting state
2015-02-04 11:25:43,052 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-75-VM","wait":0}}] }
2015-02-04 11:25:43,052 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-75-VM","wait":0}}] }
2015-02-04 11:25:43,052 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Executing request
2015-02-04 11:25:43,073 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (secstorage-1:ctx-c4d874ed) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
2015-02-04 11:25:43,081 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7ade6a71-72d5-4a7a-a211-c08841ebcda1","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-78","size":2626564608,"volumeId":79,"vmName":"s-78-VM","accountId":1,"format":"VHD","id":79,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:43,082 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7ade6a71-72d5-4a7a-a211-c08841ebcda1","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-78","size":2626564608,"volumeId":79,"vmName":"s-78-VM","accountId":1,"format":"VHD","id":79,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:43,082 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Executing request
2015-02-04 11:25:43,116 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-83:ctx-546652bc) VM does not exist on XenServera04fb561-b702-4722-85ea-be8af521dbc1
2015-02-04 11:25:43,116 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Response Received:
2015-02-04 11:25:43,116 DEBUG [c.c.a.t.Request] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2015-02-04 11:25:43,117 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { StopAnswer } }
2015-02-04 11:25:43,126 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-54:ctx-b52a84a1) Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,126 WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-54:ctx-b52a84a1) Unable to create volume; Pool=volumeTO[uuid=7ade6a71-72d5-4a7a-a211-c08841ebcda1|path=null|datastore=PrimaryDataStoreTO[uuid=302666f4-bbe7-334d-80da-35834c6e9662|name=null|id=1|pooltype=NetworkFilesystem]]; Disk:
com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:874)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.cloneVolumeFromBaseTemplate(XenServerStorageProcessor.java:987)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:78)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:609)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: The uuid you supplied was invalid.
at com.xensource.xenapi.Types.checkResponse(Types.java:927)
at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
at com.xensource.xenapi.VDI.getByUuid(VDI.java:326)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:870)
... 19 more
2015-02-04 11:25:43,127 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Response Received:
2015-02-04 11:25:43,127 DEBUG [c.c.a.t.Request] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.","wait":0}}] }
2015-02-04 11:25:43,127 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2015-02-04 11:25:43,153 DEBUG [c.c.n.g.ControlNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Released nic: NicProfile[271-75-null-null-null
2015-02-04 11:25:43,200 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (secstorage-1:ctx-c4d874ed) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@22cbf40e), no need to delete from object in store ref table
2015-02-04 11:25:43,200 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Unable to create Vol[79|vm=78|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,200 INFO [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[79|vm=78|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1202)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1254)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:962)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:694)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1278)
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:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,222 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (consoleproxy-1:ctx-7fe8ff91) Releasing ip address for reservationId=a0c0fadc-c528-410e-b52e-8fc63e996d7f, instance=272
2015-02-04 11:25:43,223 DEBUG [c.c.n.g.PodBasedNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Released nic: NicProfile[272-75-null-null-null
2015-02-04 11:25:43,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up resources for the vm VM[SecondaryStorageVm|s-78-VM] in Starting state
2015-02-04 11:25:43,237 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-78-VM","wait":0}}] }
2015-02-04 11:25:43,237 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-78-VM","wait":0}}] }
2015-02-04 11:25:43,237 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Executing request
2015-02-04 11:25:43,252 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Successfully released network resources for the vm VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:43,252 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-75-VM] in Starting state
2015-02-04 11:25:43,254 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Deploy avoids pods: null, clusters: null, hosts: [7]
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5b2f1ffc
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Is ROOT volume READY (pool already allocated)?: No
2015-02-04 11:25:43,255 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,255 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,259 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:43,259 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:43,261 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Host name: kruihost-102, hostId: 7 is in avoid set, skipping this and trying other available hosts
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2015-02-04 11:25:43,263 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) No suitable hosts found
2015-02-04 11:25:43,263 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) No suitable hosts found under this Cluster: 1
2015-02-04 11:25:43,264 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2015-02-04 11:25:43,264 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,264 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,266 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Removing from the clusterId list these clusters from avoid set: [1]
2015-02-04 11:25:43,266 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2015-02-04 11:25:43,297 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-39:ctx-312e1710) VM does not exist on XenServera04fb561-b702-4722-85ea-be8af521dbc1
2015-02-04 11:25:43,297 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Response Received:
2015-02-04 11:25:43,297 DEBUG [c.c.a.t.Request] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2015-02-04 11:25:43,298 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { StopAnswer } }
2015-02-04 11:25:43,342 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 7
2015-02-04 11:25:43,345 DEBUG [c.c.n.g.ControlNetworkGuru] (secstorage-1:ctx-c4d874ed) Released nic: NicProfile[282-78-null-null-null
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total RAM: 7464352896 and RAM after applying overprovisioning: 7464352768
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) release cpu from host: 7, old used: 1000,reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) release mem from host: 7, old used: 1610612736,reserved: 0, total: 7464352768; new used: 536870912,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,372 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (secstorage-1:ctx-c4d874ed) Releasing ip address for reservationId=3a09b82f-53f1-4516-ab86-4408c3114336, instance=283
2015-02-04 11:25:43,372 DEBUG [c.c.n.g.PodBasedNetworkGuru] (secstorage-1:ctx-c4d874ed) Released nic: NicProfile[283-78-null-null-null
2015-02-04 11:25:43,394 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-75-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:921)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:555)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:941)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1666)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:118)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,426 DEBUG [c.c.n.g.StorageNetworkGuru] (secstorage-1:ctx-c4d874ed) Release an storage ip 192.168.1.50
2015-02-04 11:25:43,443 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Successfully released network resources for the vm VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,443 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Successfully cleanued up resources for the vm VM[SecondaryStorageVm|s-78-VM] in Starting state
2015-02-04 11:25:43,447 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Deploy avoids pods: null, clusters: null, hosts: [7]
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5b2f1ffc
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Is ROOT volume READY (pool already allocated)?: No
2015-02-04 11:25:43,448 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,449 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,458 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:43,458 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:43,463 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host name: kruihost-102, hostId: 7 is in avoid set, skipping this and trying other available hosts
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2015-02-04 11:25:43,466 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) No suitable hosts found
2015-02-04 11:25:43,466 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) No suitable hosts found under this Cluster: 1
2015-02-04 11:25:43,468 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2015-02-04 11:25:43,469 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,469 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,471 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Removing from the clusterId list these clusters from avoid set: [1]
2015-02-04 11:25:43,471 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2015-02-04 11:25:43,508 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 7
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total RAM: 7464352896 and RAM after applying overprovisioning: 7464352768
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) release cpu from host: 7, old used: 500,reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) release mem from host: 7, old used: 536870912,reserved: 0, total: 7464352768; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,526 WARN [c.c.s.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Exception while trying to start secondary storage vm
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-78-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:921)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:694)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1278)
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:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,526 INFO [c.c.s.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 78, will recycle it and start a new one
2015-02-04 11:25:43,538 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) VM is already stopped: VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,559 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Stopped to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
2015-02-04 11:25:43,559 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Destroying vm VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,559 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up NICS
2015-02-04 11:25:43,559 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Cleaning network for vm: 78
2015-02-04 11:25:43,588 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-c4d874ed) public network deallocate network: networkId: 200, ip: 192.168.1.154
2015-02-04 11:25:43,609 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-c4d874ed) Deallocated nic: NicProfile[281-78-null-null-null
2015-02-04 11:25:43,626 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=281
2015-02-04 11:25:43,627 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=282
2015-02-04 11:25:43,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,693 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=283
2015-02-04 11:25:43,694 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,727 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=284
2015-02-04 11:25:43,727 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,728 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
2015-02-04 11:25:43,729 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Cleaning storage for vm: 78
2015-02-04 11:25:43,754 DEBUG [o.a.c.s.v.VolumeServiceImpl] (secstorage-1:ctx-c4d874ed) Marking volume that was never created as destroyed: Vol[79|vm=78|ROOT]
2015-02-04 11:25:43,818 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Expunged VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,844 INFO [c.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Primary secondary storage is not even started, wait until next turn
2015-02-04 11:25:50,841 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:ctx-d105ed3e) Found 0 running routers.
2015-02-04 11:25:50,854 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-c40b17d6) Snapshot scheduler.poll is being called at 2015-02-04 03:25:50 GMT
2015-02-04 11:25:50,857 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-c40b17d6) Got 0 snapshots to be executed at 2015-02-04 03:25:50 GMT
2015-02-04 11:25:50,861 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0879491e) Found 2 routers to update status.
2015-02-04 11:25:50,862 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0879491e) Found 0 networks to update RvR status.
2015-02-04 11:25:50,914 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) External devices stats collector is running...
2015-02-04 11:25:50,934 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) Network 204 is not configured for external networking, so skipping usage check.
2015-02-04 11:25:50,935 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) Network 206 is not configured for external networking, so skipping usage check.
2015-02-04 11:26:00,871 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-6657bcd7) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
2015-02-04 11:26:00,898 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-6657bcd7) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
yingkailiu@163.com
回复: 回复: 删除所有host节点后，无法再添加节点重建环境。
Posted by "yingkailiu@163.com" <yi...@163.com>.
谢谢，template_host_ref 这个表是空的。
yingkailiu@163.com
发件人： hongtu.zang@gmail.com
发送时间： 2015-02-04 12:14
收件人： users-cn
主题： 回复: 删除所有host节点后，无法再添加节点重建环境。
进db
把template_host_ref 里面跟系统虚拟机模板有关的项清掉试试看
hongtu.zang@gmail.com
发件人： yingkailiu@163.com
发送时间： 2015-02-04 11:44
收件人： users-cn
主题： 删除所有host节点后，无法再添加节点重建环境。
部署模式：高级网络，NFS共享存储
机器情况：一个管理节点，两个计算节点
场景：删除了所有的host节点后，再添加host，ssvm 和cpvm 不能启动
详细错误日志是：
2015-02-04 11:25:42,357 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2015-02-04 11:25:42,357 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Checking if host: 7 can access any suitable storage pool for volume: ROOT
2015-02-04 11:25:42,358 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Host: 7 can access pool: 1
2015-02-04 11:25:42,358 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Found a potential host id: 7 name: kruihost-102 and associated storage pools for this VM
2015-02-04 11:25:42,359 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(76|ROOT-->Pool(1))]
2015-02-04 11:25:42,359 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Deployment found - P0=VM[ConsoleProxy|v-75-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(76|ROOT-->Pool(1))]
2015-02-04 11:25:42,359 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:42,359 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:42,361 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:42,362 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:42,362 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2015-02-04 11:25:42,365 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host: 7 has cpu capability (cpu:4, speed:3192) to support requested CPU: 1 and requested speed: 500
2015-02-04 11:25:42,365 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Checking if host: 7 has enough capacity for requested CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Free CPU: 12768 , Requested CPU: 500
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Free RAM: 7464352768 , Requested RAM: 536870912
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host has enough CPU and RAM available
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 7, used: 0, reserved: 0, actual total: 12768, total with overprovisioning: 12768; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 7, used: 0, reserved: 0, total: 7464352768; requested mem: 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-02-04 11:25:42,366 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found a suitable host, adding to list: 7
2015-02-04 11:25:42,366 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2015-02-04 11:25:42,366 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking suitable pools for volume (Id, Type): (79,ROOT)
2015-02-04 11:25:42,366 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) We need to allocate new storagepool for this volume
2015-02-04 11:25:42,367 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Calling StoragePoolAllocators to find suitable pools
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) ClusterScopeStoragePoolAllocator looking for storage pool
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Looking for pools in dc: 1 pod:1 cluster:1
2015-02-04 11:25:42,368 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Found pools matching tags: [Pool[1|NetworkFilesystem]]
2015-02-04 11:25:42,368 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Removing pool Pool[1|NetworkFilesystem] from avoid set, must have been inserted when searching for another disk's tag
2015-02-04 11:25:42,369 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Checking if storage pool is suitable, name: null ,poolId: 1
2015-02-04 11:25:42,373 DEBUG [c.c.s.StorageManagerImpl] (secstorage-1:ctx-c4d874ed) Checking pool: 1 for volume allocation [Vol[79|vm=78|ROOT]], maxSize : 1854509940736, totalAllocatedSize : 180052845568, askingSize : 2626564608, allocated disable threshold: 0.85
2015-02-04 11:25:42,374 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking if host: 7 can access any suitable storage pool for volume: ROOT
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Host: 7 can access pool: 1
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Found a potential host id: 7 name: kruihost-102 and associated storage pools for this VM
2015-02-04 11:25:42,375 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(79|ROOT-->Pool(1))]
2015-02-04 11:25:42,375 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Deployment found - P0=VM[SecondaryStorageVm|s-78-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(79|ROOT-->Pool(1))]
2015-02-04 11:25:42,419 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 7 host id before state transition: null
2015-02-04 11:25:42,424 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,424 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) We are allocating VM, increasing the used capacity of this host:7
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Current Used CPU: 0 , Free CPU:12768 ,Requested CPU: 500
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Current Used RAM: 0 , Free RAM:7464352768 ,Requested RAM: 1073741824
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) CPU STATS after allocation: for host: 7, old used: 0, old reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) RAM STATS after allocation: for host: 7, old used: 0, old reserved: 0, total: 7464352768; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2015-02-04 11:25:42,440 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 7 host id before state transition: null
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) We are allocating VM, increasing the used capacity of this host:7
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Current Used CPU: 500 , Free CPU:12268 ,Requested CPU: 500
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Current Used RAM: 1073741824 , Free RAM:6390610944 ,Requested RAM: 536870912
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) CPU STATS after allocation: for host: 7, old used: 500, old reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) RAM STATS after allocation: for host: 7, old used: 1073741824, old reserved: 0, total: 7464352768; new used: 1610612736, reserved: 0; requested mem: 536870912,alloc_from_last:false
2015-02-04 11:25:42,465 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM is being created in podId: 1
2015-02-04 11:25:42,470 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=200 is already implemented
2015-02-04 11:25:42,490 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) VM is being created in podId: 1
2015-02-04 11:25:42,495 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=200 is already implemented
2015-02-04 11:25:42,519 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=202 is already implemented
2015-02-04 11:25:42,543 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=202 is already implemented
2015-02-04 11:25:42,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=201 is already implemented
2015-02-04 11:25:42,677 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=201 is already implemented
2015-02-04 11:25:42,724 DEBUG [c.c.n.g.PodBasedNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Allocated a nic NicProfile[272-75-a0c0fadc-c528-410e-b52e-8fc63e996d7f-192.168.1.36-null for VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:42,740 DEBUG [c.c.n.g.PodBasedNetworkGuru] (secstorage-1:ctx-c4d874ed) Allocated a nic NicProfile[283-78-3a09b82f-53f1-4516-ab86-4408c3114336-192.168.1.40-null for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,760 DEBUG [o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Checking if we need to prepare 1 volumes for VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:42,768 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (consoleproxy-1:ctx-7fe8ff91) template 1 is already in store:1, type:Image
2015-02-04 11:25:42,770 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (consoleproxy-1:ctx-7fe8ff91) template 1 is already in store:1, type:Primary
2015-02-04 11:25:42,776 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=203 is already implemented
2015-02-04 11:25:42,850 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (consoleproxy-1:ctx-7fe8ff91) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
2015-02-04 11:25:42,857 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"41eb998b-ad48-48ce-ab02-b75284147577","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-75","size":2626564608,"volumeId":76,"vmName":"v-75-VM","accountId":1,"format":"VHD","id":76,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:42,858 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"41eb998b-ad48-48ce-ab02-b75284147577","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-75","size":2626564608,"volumeId":76,"vmName":"v-75-VM","accountId":1,"format":"VHD","id":76,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:42,858 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Executing request
2015-02-04 11:25:42,870 DEBUG [c.c.n.g.StorageNetworkGuru] (secstorage-1:ctx-c4d874ed) Allocated a storage nic NicProfile[284-78-3a09b82f-53f1-4516-ab86-4408c3114336-192.168.1.50-null for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,936 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-82:ctx-6287cd89) Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:42,936 WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-82:ctx-6287cd89) Unable to create volume; Pool=volumeTO[uuid=41eb998b-ad48-48ce-ab02-b75284147577|path=null|datastore=PrimaryDataStoreTO[uuid=302666f4-bbe7-334d-80da-35834c6e9662|name=null|id=1|pooltype=NetworkFilesystem]]; Disk:
com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:874)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.cloneVolumeFromBaseTemplate(XenServerStorageProcessor.java:987)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:78)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:609)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: The uuid you supplied was invalid.
at com.xensource.xenapi.Types.checkResponse(Types.java:927)
at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
at com.xensource.xenapi.VDI.getByUuid(VDI.java:326)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:870)
... 19 more
2015-02-04 11:25:42,937 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Response Received:
2015-02-04 11:25:42,938 DEBUG [c.c.a.t.Request] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.","wait":0}}] }
2015-02-04 11:25:42,938 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2015-02-04 11:25:42,978 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Checking if we need to prepare 1 volumes for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,986 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (secstorage-1:ctx-c4d874ed) template 1 is already in store:1, type:Image
2015-02-04 11:25:42,988 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (secstorage-1:ctx-c4d874ed) template 1 is already in store:1, type:Primary
2015-02-04 11:25:43,000 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@54854c57), no need to delete from object in store ref table
2015-02-04 11:25:43,001 DEBUG [o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Unable to create Vol[76|vm=75|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,001 INFO [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[76|vm=75|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1202)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1254)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:962)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:555)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:941)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1666)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:118)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,049 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Cleaning up resources for the vm VM[ConsoleProxy|v-75-VM] in Starting state
2015-02-04 11:25:43,052 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-75-VM","wait":0}}] }
2015-02-04 11:25:43,052 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-75-VM","wait":0}}] }
2015-02-04 11:25:43,052 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Executing request
2015-02-04 11:25:43,073 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (secstorage-1:ctx-c4d874ed) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
2015-02-04 11:25:43,081 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7ade6a71-72d5-4a7a-a211-c08841ebcda1","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-78","size":2626564608,"volumeId":79,"vmName":"s-78-VM","accountId":1,"format":"VHD","id":79,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:43,082 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7ade6a71-72d5-4a7a-a211-c08841ebcda1","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-78","size":2626564608,"volumeId":79,"vmName":"s-78-VM","accountId":1,"format":"VHD","id":79,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:43,082 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Executing request
2015-02-04 11:25:43,116 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-83:ctx-546652bc) VM does not exist on XenServera04fb561-b702-4722-85ea-be8af521dbc1
2015-02-04 11:25:43,116 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Response Received:
2015-02-04 11:25:43,116 DEBUG [c.c.a.t.Request] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2015-02-04 11:25:43,117 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { StopAnswer } }
2015-02-04 11:25:43,126 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-54:ctx-b52a84a1) Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,126 WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-54:ctx-b52a84a1) Unable to create volume; Pool=volumeTO[uuid=7ade6a71-72d5-4a7a-a211-c08841ebcda1|path=null|datastore=PrimaryDataStoreTO[uuid=302666f4-bbe7-334d-80da-35834c6e9662|name=null|id=1|pooltype=NetworkFilesystem]]; Disk:
com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:874)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.cloneVolumeFromBaseTemplate(XenServerStorageProcessor.java:987)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:78)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:609)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: The uuid you supplied was invalid.
at com.xensource.xenapi.Types.checkResponse(Types.java:927)
at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
at com.xensource.xenapi.VDI.getByUuid(VDI.java:326)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:870)
... 19 more
2015-02-04 11:25:43,127 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Response Received:
2015-02-04 11:25:43,127 DEBUG [c.c.a.t.Request] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.","wait":0}}] }
2015-02-04 11:25:43,127 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2015-02-04 11:25:43,153 DEBUG [c.c.n.g.ControlNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Released nic: NicProfile[271-75-null-null-null
2015-02-04 11:25:43,200 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (secstorage-1:ctx-c4d874ed) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@22cbf40e), no need to delete from object in store ref table
2015-02-04 11:25:43,200 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Unable to create Vol[79|vm=78|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,200 INFO [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[79|vm=78|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1202)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1254)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:962)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:694)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1278)
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:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,222 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (consoleproxy-1:ctx-7fe8ff91) Releasing ip address for reservationId=a0c0fadc-c528-410e-b52e-8fc63e996d7f, instance=272
2015-02-04 11:25:43,223 DEBUG [c.c.n.g.PodBasedNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Released nic: NicProfile[272-75-null-null-null
2015-02-04 11:25:43,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up resources for the vm VM[SecondaryStorageVm|s-78-VM] in Starting state
2015-02-04 11:25:43,237 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-78-VM","wait":0}}] }
2015-02-04 11:25:43,237 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-78-VM","wait":0}}] }
2015-02-04 11:25:43,237 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Executing request
2015-02-04 11:25:43,252 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Successfully released network resources for the vm VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:43,252 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-75-VM] in Starting state
2015-02-04 11:25:43,254 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Deploy avoids pods: null, clusters: null, hosts: [7]
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5b2f1ffc
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Is ROOT volume READY (pool already allocated)?: No
2015-02-04 11:25:43,255 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,255 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,259 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:43,259 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:43,261 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Host name: kruihost-102, hostId: 7 is in avoid set, skipping this and trying other available hosts
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2015-02-04 11:25:43,263 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) No suitable hosts found
2015-02-04 11:25:43,263 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) No suitable hosts found under this Cluster: 1
2015-02-04 11:25:43,264 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2015-02-04 11:25:43,264 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,264 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,266 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Removing from the clusterId list these clusters from avoid set: [1]
2015-02-04 11:25:43,266 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2015-02-04 11:25:43,297 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-39:ctx-312e1710) VM does not exist on XenServera04fb561-b702-4722-85ea-be8af521dbc1
2015-02-04 11:25:43,297 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Response Received:
2015-02-04 11:25:43,297 DEBUG [c.c.a.t.Request] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2015-02-04 11:25:43,298 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { StopAnswer } }
2015-02-04 11:25:43,342 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 7
2015-02-04 11:25:43,345 DEBUG [c.c.n.g.ControlNetworkGuru] (secstorage-1:ctx-c4d874ed) Released nic: NicProfile[282-78-null-null-null
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total RAM: 7464352896 and RAM after applying overprovisioning: 7464352768
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) release cpu from host: 7, old used: 1000,reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) release mem from host: 7, old used: 1610612736,reserved: 0, total: 7464352768; new used: 536870912,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,372 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (secstorage-1:ctx-c4d874ed) Releasing ip address for reservationId=3a09b82f-53f1-4516-ab86-4408c3114336, instance=283
2015-02-04 11:25:43,372 DEBUG [c.c.n.g.PodBasedNetworkGuru] (secstorage-1:ctx-c4d874ed) Released nic: NicProfile[283-78-null-null-null
2015-02-04 11:25:43,394 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-75-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:921)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:555)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:941)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1666)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:118)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,426 DEBUG [c.c.n.g.StorageNetworkGuru] (secstorage-1:ctx-c4d874ed) Release an storage ip 192.168.1.50
2015-02-04 11:25:43,443 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Successfully released network resources for the vm VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,443 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Successfully cleanued up resources for the vm VM[SecondaryStorageVm|s-78-VM] in Starting state
2015-02-04 11:25:43,447 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Deploy avoids pods: null, clusters: null, hosts: [7]
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5b2f1ffc
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Is ROOT volume READY (pool already allocated)?: No
2015-02-04 11:25:43,448 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,449 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,458 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:43,458 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:43,463 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host name: kruihost-102, hostId: 7 is in avoid set, skipping this and trying other available hosts
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2015-02-04 11:25:43,466 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) No suitable hosts found
2015-02-04 11:25:43,466 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) No suitable hosts found under this Cluster: 1
2015-02-04 11:25:43,468 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2015-02-04 11:25:43,469 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,469 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,471 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Removing from the clusterId list these clusters from avoid set: [1]
2015-02-04 11:25:43,471 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2015-02-04 11:25:43,508 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 7
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total RAM: 7464352896 and RAM after applying overprovisioning: 7464352768
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) release cpu from host: 7, old used: 500,reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) release mem from host: 7, old used: 536870912,reserved: 0, total: 7464352768; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,526 WARN [c.c.s.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Exception while trying to start secondary storage vm
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-78-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:921)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:694)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1278)
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:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,526 INFO [c.c.s.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 78, will recycle it and start a new one
2015-02-04 11:25:43,538 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) VM is already stopped: VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,559 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Stopped to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
2015-02-04 11:25:43,559 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Destroying vm VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,559 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up NICS
2015-02-04 11:25:43,559 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Cleaning network for vm: 78
2015-02-04 11:25:43,588 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-c4d874ed) public network deallocate network: networkId: 200, ip: 192.168.1.154
2015-02-04 11:25:43,609 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-c4d874ed) Deallocated nic: NicProfile[281-78-null-null-null
2015-02-04 11:25:43,626 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=281
2015-02-04 11:25:43,627 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=282
2015-02-04 11:25:43,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,693 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=283
2015-02-04 11:25:43,694 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,727 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=284
2015-02-04 11:25:43,727 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,728 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
2015-02-04 11:25:43,729 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Cleaning storage for vm: 78
2015-02-04 11:25:43,754 DEBUG [o.a.c.s.v.VolumeServiceImpl] (secstorage-1:ctx-c4d874ed) Marking volume that was never created as destroyed: Vol[79|vm=78|ROOT]
2015-02-04 11:25:43,818 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Expunged VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,844 INFO [c.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Primary secondary storage is not even started, wait until next turn
2015-02-04 11:25:50,841 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:ctx-d105ed3e) Found 0 running routers.
2015-02-04 11:25:50,854 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-c40b17d6) Snapshot scheduler.poll is being called at 2015-02-04 03:25:50 GMT
2015-02-04 11:25:50,857 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-c40b17d6) Got 0 snapshots to be executed at 2015-02-04 03:25:50 GMT
2015-02-04 11:25:50,861 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0879491e) Found 2 routers to update status.
2015-02-04 11:25:50,862 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0879491e) Found 0 networks to update RvR status.
2015-02-04 11:25:50,914 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) External devices stats collector is running...
2015-02-04 11:25:50,934 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) Network 204 is not configured for external networking, so skipping usage check.
2015-02-04 11:25:50,935 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) Network 206 is not configured for external networking, so skipping usage check.
2015-02-04 11:26:00,871 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-6657bcd7) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
2015-02-04 11:26:00,898 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-6657bcd7) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
yingkailiu@163.com
回复: 删除所有host节点后，无法再添加节点重建环境。
Posted by "hongtu.zang@gmail.com" <ho...@gmail.com>.
进db
把template_host_ref 里面跟系统虚拟机模板有关的项清掉试试看
hongtu.zang@gmail.com
发件人： yingkailiu@163.com
发送时间： 2015-02-04 11:44
收件人： users-cn
主题： 删除所有host节点后，无法再添加节点重建环境。
部署模式：高级网络，NFS共享存储
机器情况：一个管理节点，两个计算节点
场景：删除了所有的host节点后，再添加host，ssvm 和cpvm 不能启动
详细错误日志是：
2015-02-04 11:25:42,357 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2015-02-04 11:25:42,357 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Checking if host: 7 can access any suitable storage pool for volume: ROOT
2015-02-04 11:25:42,358 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Host: 7 can access pool: 1
2015-02-04 11:25:42,358 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Found a potential host id: 7 name: kruihost-102 and associated storage pools for this VM
2015-02-04 11:25:42,359 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(76|ROOT-->Pool(1))]
2015-02-04 11:25:42,359 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Deployment found - P0=VM[ConsoleProxy|v-75-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(76|ROOT-->Pool(1))]
2015-02-04 11:25:42,359 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:42,359 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:42,361 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:42,362 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:42,362 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2015-02-04 11:25:42,365 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host: 7 has cpu capability (cpu:4, speed:3192) to support requested CPU: 1 and requested speed: 500
2015-02-04 11:25:42,365 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Checking if host: 7 has enough capacity for requested CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Free CPU: 12768 , Requested CPU: 500
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Free RAM: 7464352768 , Requested RAM: 536870912
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host has enough CPU and RAM available
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 7, used: 0, reserved: 0, actual total: 12768, total with overprovisioning: 12768; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-02-04 11:25:42,366 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 7, used: 0, reserved: 0, total: 7464352768; requested mem: 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-02-04 11:25:42,366 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found a suitable host, adding to list: 7
2015-02-04 11:25:42,366 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2015-02-04 11:25:42,366 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking suitable pools for volume (Id, Type): (79,ROOT)
2015-02-04 11:25:42,366 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) We need to allocate new storagepool for this volume
2015-02-04 11:25:42,367 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Calling StoragePoolAllocators to find suitable pools
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) ClusterScopeStoragePoolAllocator looking for storage pool
2015-02-04 11:25:42,367 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Looking for pools in dc: 1 pod:1 cluster:1
2015-02-04 11:25:42,368 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Found pools matching tags: [Pool[1|NetworkFilesystem]]
2015-02-04 11:25:42,368 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Removing pool Pool[1|NetworkFilesystem] from avoid set, must have been inserted when searching for another disk's tag
2015-02-04 11:25:42,369 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) Checking if storage pool is suitable, name: null ,poolId: 1
2015-02-04 11:25:42,373 DEBUG [c.c.s.StorageManagerImpl] (secstorage-1:ctx-c4d874ed) Checking pool: 1 for volume allocation [Vol[79|vm=78|ROOT]], maxSize : 1854509940736, totalAllocatedSize : 180052845568, askingSize : 2626564608, allocated disable threshold: 0.85
2015-02-04 11:25:42,374 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (secstorage-1:ctx-c4d874ed) ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking if host: 7 can access any suitable storage pool for volume: ROOT
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Host: 7 can access pool: 1
2015-02-04 11:25:42,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Found a potential host id: 7 name: kruihost-102 and associated storage pools for this VM
2015-02-04 11:25:42,375 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(79|ROOT-->Pool(1))]
2015-02-04 11:25:42,375 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Deployment found - P0=VM[SecondaryStorageVm|s-78-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(7)-Storage(Volume(79|ROOT-->Pool(1))]
2015-02-04 11:25:42,419 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 7 host id before state transition: null
2015-02-04 11:25:42,424 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,424 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) We are allocating VM, increasing the used capacity of this host:7
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Current Used CPU: 0 , Free CPU:12768 ,Requested CPU: 500
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Current Used RAM: 0 , Free RAM:7464352768 ,Requested RAM: 1073741824
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) CPU STATS after allocation: for host: 7, old used: 0, old reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2015-02-04 11:25:42,425 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) RAM STATS after allocation: for host: 7, old used: 0, old reserved: 0, total: 7464352768; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2015-02-04 11:25:42,440 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 7 host id before state transition: null
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) We are allocating VM, increasing the used capacity of this host:7
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Current Used CPU: 500 , Free CPU:12268 ,Requested CPU: 500
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Current Used RAM: 1073741824 , Free RAM:6390610944 ,Requested RAM: 536870912
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) CPU STATS after allocation: for host: 7, old used: 500, old reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false
2015-02-04 11:25:42,446 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) RAM STATS after allocation: for host: 7, old used: 1073741824, old reserved: 0, total: 7464352768; new used: 1610612736, reserved: 0; requested mem: 536870912,alloc_from_last:false
2015-02-04 11:25:42,465 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM is being created in podId: 1
2015-02-04 11:25:42,470 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=200 is already implemented
2015-02-04 11:25:42,490 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) VM is being created in podId: 1
2015-02-04 11:25:42,495 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=200 is already implemented
2015-02-04 11:25:42,519 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=202 is already implemented
2015-02-04 11:25:42,543 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=202 is already implemented
2015-02-04 11:25:42,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Network id=201 is already implemented
2015-02-04 11:25:42,677 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=201 is already implemented
2015-02-04 11:25:42,724 DEBUG [c.c.n.g.PodBasedNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Allocated a nic NicProfile[272-75-a0c0fadc-c528-410e-b52e-8fc63e996d7f-192.168.1.36-null for VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:42,740 DEBUG [c.c.n.g.PodBasedNetworkGuru] (secstorage-1:ctx-c4d874ed) Allocated a nic NicProfile[283-78-3a09b82f-53f1-4516-ab86-4408c3114336-192.168.1.40-null for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,760 DEBUG [o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Checking if we need to prepare 1 volumes for VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:42,768 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (consoleproxy-1:ctx-7fe8ff91) template 1 is already in store:1, type:Image
2015-02-04 11:25:42,770 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (consoleproxy-1:ctx-7fe8ff91) template 1 is already in store:1, type:Primary
2015-02-04 11:25:42,776 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Network id=203 is already implemented
2015-02-04 11:25:42,850 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (consoleproxy-1:ctx-7fe8ff91) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
2015-02-04 11:25:42,857 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"41eb998b-ad48-48ce-ab02-b75284147577","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-75","size":2626564608,"volumeId":76,"vmName":"v-75-VM","accountId":1,"format":"VHD","id":76,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:42,858 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"41eb998b-ad48-48ce-ab02-b75284147577","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-75","size":2626564608,"volumeId":76,"vmName":"v-75-VM","accountId":1,"format":"VHD","id":76,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:42,858 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Executing request
2015-02-04 11:25:42,870 DEBUG [c.c.n.g.StorageNetworkGuru] (secstorage-1:ctx-c4d874ed) Allocated a storage nic NicProfile[284-78-3a09b82f-53f1-4516-ab86-4408c3114336-192.168.1.50-null for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,936 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-82:ctx-6287cd89) Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:42,936 WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-82:ctx-6287cd89) Unable to create volume; Pool=volumeTO[uuid=41eb998b-ad48-48ce-ab02-b75284147577|path=null|datastore=PrimaryDataStoreTO[uuid=302666f4-bbe7-334d-80da-35834c6e9662|name=null|id=1|pooltype=NetworkFilesystem]]; Disk:
com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:874)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.cloneVolumeFromBaseTemplate(XenServerStorageProcessor.java:987)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:78)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:609)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: The uuid you supplied was invalid.
at com.xensource.xenapi.Types.checkResponse(Types.java:927)
at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
at com.xensource.xenapi.VDI.getByUuid(VDI.java:326)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:870)
... 19 more
2015-02-04 11:25:42,937 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Response Received:
2015-02-04 11:25:42,938 DEBUG [c.c.a.t.Request] (DirectAgent-82:ctx-6287cd89) Seq 7-445382685: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.","wait":0}}] }
2015-02-04 11:25:42,938 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382685: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2015-02-04 11:25:42,978 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Checking if we need to prepare 1 volumes for VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:42,986 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (secstorage-1:ctx-c4d874ed) template 1 is already in store:1, type:Image
2015-02-04 11:25:42,988 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (secstorage-1:ctx-c4d874ed) template 1 is already in store:1, type:Primary
2015-02-04 11:25:43,000 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@54854c57), no need to delete from object in store ref table
2015-02-04 11:25:43,001 DEBUG [o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:ctx-7fe8ff91) Unable to create Vol[76|vm=75|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,001 INFO [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[76|vm=75|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1202)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1254)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:962)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:555)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:941)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1666)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:118)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,049 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Cleaning up resources for the vm VM[ConsoleProxy|v-75-VM] in Starting state
2015-02-04 11:25:43,052 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-75-VM","wait":0}}] }
2015-02-04 11:25:43,052 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-75-VM","wait":0}}] }
2015-02-04 11:25:43,052 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Executing request
2015-02-04 11:25:43,073 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (secstorage-1:ctx-c4d874ed) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
2015-02-04 11:25:43,081 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7ade6a71-72d5-4a7a-a211-c08841ebcda1","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-78","size":2626564608,"volumeId":79,"vmName":"s-78-VM","accountId":1,"format":"VHD","id":79,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:43,082 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"db73a4b2-f476-464a-9495-1340275f5450","origUrl":"http://download.cloud.com/templates/4.3/systemvm64template-2014-01-14-master-xen.vhd.bz2","uuid":"fe5533f0-a56f-11e4-b3f1-643150474b29","id":1,"format":"VHD","accountId":1,"checksum":"74b92f031cc5c2089ee89efb81344dcf","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7ade6a71-72d5-4a7a-a211-c08841ebcda1","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"302666f4-bbe7-334d-80da-35834c6e9662","id":1,"poolType":"NetworkFilesystem","host":"192.168.1.2","path":"/home/primary","port":2049,"url":"NetworkFilesystem://192.168.1.2//home/primary/?ROLE=Primary&STOREUUID=302666f4-bbe7-334d-80da-35834c6e9662"}},"name":"ROOT-78","size":2626564608,"volumeId":79,"vmName":"s-78-VM","accountId":1,"format":"VHD","id":79,"deviceId":0,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":0}}] }
2015-02-04 11:25:43,082 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Executing request
2015-02-04 11:25:43,116 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-83:ctx-546652bc) VM does not exist on XenServera04fb561-b702-4722-85ea-be8af521dbc1
2015-02-04 11:25:43,116 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Response Received:
2015-02-04 11:25:43,116 DEBUG [c.c.a.t.Request] (DirectAgent-83:ctx-546652bc) Seq 7-445382686: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2015-02-04 11:25:43,117 DEBUG [c.c.a.t.Request] (consoleproxy-1:ctx-7fe8ff91) Seq 7-445382686: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { StopAnswer } }
2015-02-04 11:25:43,126 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-54:ctx-b52a84a1) Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,126 WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-54:ctx-b52a84a1) Unable to create volume; Pool=volumeTO[uuid=7ade6a71-72d5-4a7a-a211-c08841ebcda1|path=null|datastore=PrimaryDataStoreTO[uuid=302666f4-bbe7-334d-80da-35834c6e9662|name=null|id=1|pooltype=NetworkFilesystem]]; Disk:
com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:874)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.cloneVolumeFromBaseTemplate(XenServerStorageProcessor.java:987)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:78)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:609)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: The uuid you supplied was invalid.
at com.xensource.xenapi.Types.checkResponse(Types.java:927)
at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
at com.xensource.xenapi.VDI.getByUuid(VDI.java:326)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:870)
... 19 more
2015-02-04 11:25:43,127 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Response Received:
2015-02-04 11:25:43,127 DEBUG [c.c.a.t.Request] (DirectAgent-54:ctx-b52a84a1) Seq 7-445382687: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.","wait":0}}] }
2015-02-04 11:25:43,127 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382687: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2015-02-04 11:25:43,153 DEBUG [c.c.n.g.ControlNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Released nic: NicProfile[271-75-null-null-null
2015-02-04 11:25:43,200 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (secstorage-1:ctx-c4d874ed) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@22cbf40e), no need to delete from object in store ref table
2015-02-04 11:25:43,200 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Unable to create Vol[79|vm=78|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
2015-02-04 11:25:43,200 INFO [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[79|vm=78|ROOT]:com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: db73a4b2-f476-464a-9495-1340275f5450 failed due to The uuid you supplied was invalid.
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1202)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1254)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:962)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:694)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1278)
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:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,222 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (consoleproxy-1:ctx-7fe8ff91) Releasing ip address for reservationId=a0c0fadc-c528-410e-b52e-8fc63e996d7f, instance=272
2015-02-04 11:25:43,223 DEBUG [c.c.n.g.PodBasedNetworkGuru] (consoleproxy-1:ctx-7fe8ff91) Released nic: NicProfile[272-75-null-null-null
2015-02-04 11:25:43,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up resources for the vm VM[SecondaryStorageVm|s-78-VM] in Starting state
2015-02-04 11:25:43,237 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Sending { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-78-VM","wait":0}}] }
2015-02-04 11:25:43,237 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Executing: { Cmd , MgmtId: 110162963024681, via: 7(kruihost-102), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-78-VM","wait":0}}] }
2015-02-04 11:25:43,237 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Executing request
2015-02-04 11:25:43,252 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Successfully released network resources for the vm VM[ConsoleProxy|v-75-VM]
2015-02-04 11:25:43,252 DEBUG [c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-75-VM] in Starting state
2015-02-04 11:25:43,254 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Deploy avoids pods: null, clusters: null, hosts: [7]
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5b2f1ffc
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2015-02-04 11:25:43,255 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Is ROOT volume READY (pool already allocated)?: No
2015-02-04 11:25:43,255 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,255 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,259 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:43,259 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:43,261 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Host name: kruihost-102, hostId: 7 is in avoid set, skipping this and trying other available hosts
2015-02-04 11:25:43,263 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (consoleproxy-1:ctx-7fe8ff91 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2015-02-04 11:25:43,263 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) No suitable hosts found
2015-02-04 11:25:43,263 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) No suitable hosts found under this Cluster: 1
2015-02-04 11:25:43,264 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2015-02-04 11:25:43,264 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,264 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,266 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) Removing from the clusterId list these clusters from avoid set: [1]
2015-02-04 11:25:43,266 DEBUG [c.c.d.FirstFitPlanner] (consoleproxy-1:ctx-7fe8ff91) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2015-02-04 11:25:43,297 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-39:ctx-312e1710) VM does not exist on XenServera04fb561-b702-4722-85ea-be8af521dbc1
2015-02-04 11:25:43,297 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Response Received:
2015-02-04 11:25:43,297 DEBUG [c.c.a.t.Request] (DirectAgent-39:ctx-312e1710) Seq 7-445382688: Processing: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not exist","wait":0}}] }
2015-02-04 11:25:43,298 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-c4d874ed) Seq 7-445382688: Received: { Ans: , MgmtId: 110162963024681, via: 7, Ver: v1, Flags: 10, { StopAnswer } }
2015-02-04 11:25:43,342 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 7
2015-02-04 11:25:43,345 DEBUG [c.c.n.g.ControlNetworkGuru] (secstorage-1:ctx-c4d874ed) Released nic: NicProfile[282-78-null-null-null
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Hosts's actual total RAM: 7464352896 and RAM after applying overprovisioning: 7464352768
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) release cpu from host: 7, old used: 1000,reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,349 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:ctx-7fe8ff91) release mem from host: 7, old used: 1610612736,reserved: 0, total: 7464352768; new used: 536870912,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,372 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (secstorage-1:ctx-c4d874ed) Releasing ip address for reservationId=3a09b82f-53f1-4516-ab86-4408c3114336, instance=283
2015-02-04 11:25:43,372 DEBUG [c.c.n.g.PodBasedNetworkGuru] (secstorage-1:ctx-c4d874ed) Released nic: NicProfile[283-78-null-null-null
2015-02-04 11:25:43,394 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-7fe8ff91) Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-75-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:921)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:555)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:941)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1666)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:118)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,426 DEBUG [c.c.n.g.StorageNetworkGuru] (secstorage-1:ctx-c4d874ed) Release an storage ip 192.168.1.50
2015-02-04 11:25:43,443 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Successfully released network resources for the vm VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,443 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Successfully cleanued up resources for the vm VM[SecondaryStorageVm|s-78-VM] in Starting state
2015-02-04 11:25:43,447 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Deploy avoids pods: null, clusters: null, hosts: [7]
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5b2f1ffc
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912
2015-02-04 11:25:43,448 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Is ROOT volume READY (pool already allocated)?: No
2015-02-04 11:25:43,448 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,449 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,458 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Checking resources in Cluster: 1 under Pod: 1
2015-02-04 11:25:43,458 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2015-02-04 11:25:43,463 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-7-Routing]]
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-7-Routing]]
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host name: kruihost-102, hostId: 7 is in avoid set, skipping this and trying other available hosts
2015-02-04 11:25:43,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (secstorage-1:ctx-c4d874ed FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2015-02-04 11:25:43,466 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) No suitable hosts found
2015-02-04 11:25:43,466 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) No suitable hosts found under this Cluster: 1
2015-02-04 11:25:43,468 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (secstorage-1:ctx-c4d874ed) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2015-02-04 11:25:43,469 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Searching resources only under specified Pod: 1
2015-02-04 11:25:43,469 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-02-04 11:25:43,471 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) Removing from the clusterId list these clusters from avoid set: [1]
2015-02-04 11:25:43,471 DEBUG [c.c.d.FirstFitPlanner] (secstorage-1:ctx-c4d874ed) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2015-02-04 11:25:43,508 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 7
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total CPU: 12768 and CPU after applying overprovisioning: 12768
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) Hosts's actual total RAM: 7464352896 and RAM after applying overprovisioning: 7464352768
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) release cpu from host: 7, old used: 500,reserved: 0, actual total: 12768, total with overprovisioning: 12768; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,512 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) release mem from host: 7, old used: 536870912,reserved: 0, total: 7464352768; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-04 11:25:43,526 WARN [c.c.s.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Exception while trying to start secondary storage vm
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-78-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:921)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:745)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:694)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1278)
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:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-02-04 11:25:43,526 INFO [c.c.s.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 78, will recycle it and start a new one
2015-02-04 11:25:43,538 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) VM is already stopped: VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,559 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-c4d874ed) VM state transitted from :Stopped to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
2015-02-04 11:25:43,559 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Destroying vm VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,559 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up NICS
2015-02-04 11:25:43,559 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Cleaning network for vm: 78
2015-02-04 11:25:43,588 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-c4d874ed) public network deallocate network: networkId: 200, ip: 192.168.1.154
2015-02-04 11:25:43,609 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-c4d874ed) Deallocated nic: NicProfile[281-78-null-null-null
2015-02-04 11:25:43,626 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=281
2015-02-04 11:25:43,627 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=282
2015-02-04 11:25:43,660 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,693 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=283
2015-02-04 11:25:43,694 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,727 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Removed nic id=284
2015-02-04 11:25:43,727 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-c4d874ed) Revoving nic secondary ip entry ...
2015-02-04 11:25:43,728 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
2015-02-04 11:25:43,729 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-c4d874ed) Cleaning storage for vm: 78
2015-02-04 11:25:43,754 DEBUG [o.a.c.s.v.VolumeServiceImpl] (secstorage-1:ctx-c4d874ed) Marking volume that was never created as destroyed: Vol[79|vm=78|ROOT]
2015-02-04 11:25:43,818 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-c4d874ed) Expunged VM[SecondaryStorageVm|s-78-VM]
2015-02-04 11:25:43,844 INFO [c.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-c4d874ed) Primary secondary storage is not even started, wait until next turn
2015-02-04 11:25:50,841 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:ctx-d105ed3e) Found 0 running routers.
2015-02-04 11:25:50,854 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-c40b17d6) Snapshot scheduler.poll is being called at 2015-02-04 03:25:50 GMT
2015-02-04 11:25:50,857 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-c40b17d6) Got 0 snapshots to be executed at 2015-02-04 03:25:50 GMT
2015-02-04 11:25:50,861 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0879491e) Found 2 routers to update status.
2015-02-04 11:25:50,862 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0879491e) Found 0 networks to update RvR status.
2015-02-04 11:25:50,914 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) External devices stats collector is running...
2015-02-04 11:25:50,934 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) Network 204 is not configured for external networking, so skipping usage check.
2015-02-04 11:25:50,935 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-abb5843e) Network 206 is not configured for external networking, so skipping usage check.
2015-02-04 11:26:00,871 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-6657bcd7) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
2015-02-04 11:26:00,898 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-6657bcd7) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
yingkailiu@163.com