Skip to content

Instantly share code, notes, and snippets.

@thesurlydev

thesurlydev/gist:5058738

Created February 28, 2013 17:59
Show Gist options
  • Save thesurlydev/5058738 to your computer and use it in GitHub Desktop.
Save thesurlydev/5058738 to your computer and use it in GitHub Desktop.
Download ZIP
cloudstack 4.1, xenserver 6.1, ubuntu 12.04.1. below occurs when zone is enabled. seems pool.getPoolType().isShared() is evaluating to false at line ~127 in com.cloud.storage.allocator.AbstractStoragePoolAllocator
Raw
gistfile1.txt
2013-02-28 12:36:05,208 DEBUG [cloud.api.ApiServlet] (1273455260@qtp-2143632343-8:null) ===START=== 208.96.179.187 -- GET command=listZones&response=json&sessionkey=p%2BTXa9uiKk23EJHJtcsb4AHCuOk%3D&id=5ffb2e9d-e059-45a5-86a8-d25488851f3d&_=1362072964150
2013-02-28 12:36:05,214 DEBUG [cloud.api.ApiServlet] (1273455260@qtp-2143632343-8:null) ===END=== 208.96.179.187 -- GET command=listZones&response=json&sessionkey=p%2BTXa9uiKk23EJHJtcsb4AHCuOk%3D&id=5ffb2e9d-e059-45a5-86a8-d25488851f3d&_=1362072964150
2013-02-28 12:36:05,453 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2013-02-28 12:36:05,454 INFO [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) No running secondary storage vms found in datacenter id=1, starting one
2013-02-28 12:36:05,456 INFO [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Found a stopped secondary storage vm, bring it up to running pool. secStorageVm vm id : 11
2013-02-28 12:36:05,459 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null
2013-02-28 12:36:05,459 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Successfully transitioned to start state for VM[SecondaryStorageVm|s-11-VM] reservation id = c68f4087-5780-4808-b05c-7b6e7f86a68c
2013-02-28 12:36:05,464 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Trying to deploy VM, vm has dcId: 1 and podId: null
2013-02-28 12:36:05,464 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2013-02-28 12:36:05,465 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) DeploymentPlanner allocation algorithm: random
2013-02-28 12:36:05,465 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 100, requested ram: 104857600
2013-02-28 12:36:05,465 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2013-02-28 12:36:05,465 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Searching all possible resources under this Zone: 1
2013-02-28 12:36:05,466 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2013-02-28 12:36:05,467 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
2013-02-28 12:36:05,471 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2013-02-28 12:36:05,471 DEBUG [allocator.impl.FirstFitAllocator] (secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,473 DEBUG [allocator.impl.FirstFitAllocator] (secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
2013-02-28 12:36:05,474 DEBUG [allocator.impl.FirstFitAllocator] (secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
2013-02-28 12:36:05,475 DEBUG [allocator.impl.FirstFitAllocator] (secstorage-1:FirstFitRoutingAllocator) Looking for speed=100Mhz, Ram=100
2013-02-28 12:36:05,476 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 100 and requested RAM: 104857600 , cpuOverprovisioningFactor: 1.0
2013-02-28 12:36:05,478 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 46928 and CPU after applying overprovisioning: 46928
2013-02-28 12:36:05,478 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:FirstFitRoutingAllocator) Free CPU: 46928 , Requested CPU: 100
2013-02-28 12:36:05,478 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:FirstFitRoutingAllocator) Free RAM: 12049918272 , Requested RAM: 104857600
2013-02-28 12:36:05,478 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2013-02-28 12:36:05,478 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 0, reserved: 0, actual total: 46928, total with overprovisioning: 46928; requested cpu:100,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-02-28 12:36:05,478 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 0, reserved: 0, total: 12049918272; requested mem: 104857600,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-02-28 12:36:05,478 DEBUG [allocator.impl.FirstFitAllocator] (secstorage-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2013-02-28 12:36:05,478 DEBUG [allocator.impl.FirstFitAllocator] (secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2013-02-28 12:36:05,479 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Checking suitable pools for volume (Id, Type): (11,ROOT)
2013-02-28 12:36:05,479 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) We need to allocate new storagepool for this volume
2013-02-28 12:36:05,479 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Calling StoragePoolAllocators to find suitable pools
2013-02-28 12:36:05,480 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-02-28 12:36:05,480 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,481 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) FirstFitStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,481 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,481 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,481 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is storage pool shared? true
2013-02-28 12:36:05,481 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,481 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,481 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,481 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) Unable to find storage pool to fit the vm
2013-02-28 12:36:05,483 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Storage pool garbage collector found 0 templates to clean up in storage pool: primary1-nfs-local
2013-02-28 12:36:05,485 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Secondary storage garbage collector found 0 templates to cleanup on secondary storage host: nfs://172.16.8.23/export/secondary
2013-02-28 12:36:05,486 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Secondary storage garbage collector found 0 templates to cleanup on secondary storage host: nfs://172.16.8.23/export/secondary
2013-02-28 12:36:05,486 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-02-28 12:36:05,486 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,487 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) FirstFitStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,487 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,487 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,487 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is storage pool shared? true
2013-02-28 12:36:05,487 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,487 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,487 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,487 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) Unable to find storage pool to fit the vm
2013-02-28 12:36:05,487 DEBUG [storage.allocator.RandomStoragePoolAllocator] (secstorage-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,488 DEBUG [storage.allocator.RandomStoragePoolAllocator] (secstorage-1:null) RandomStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,488 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,488 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,488 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is storage pool shared? true
2013-02-28 12:36:05,488 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,488 DEBUG [storage.allocator.RandomStoragePoolAllocator] (secstorage-1:null) RandomStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,489 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-02-28 12:36:05,489 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,489 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) FirstFitStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,489 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,489 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,489 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is storage pool shared? true
2013-02-28 12:36:05,489 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,489 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,489 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,490 DEBUG [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) Unable to find storage pool to fit the vm
2013-02-28 12:36:05,490 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) No suitable pools found for volume: Vol[11|vm=11|ROOT] under cluster: 1
2013-02-28 12:36:05,490 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) No suitable pools found
2013-02-28 12:36:05,490 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) No suitable storagePools found under this Cluster: 1
2013-02-28 12:36:05,490 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2013-02-28 12:36:05,493 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: null
2013-02-28 12:36:05,495 WARN [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Exception while trying to start secondary storage vm
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-11-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:718)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:461)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:454)
at sun.reflect.GeneratedMethodAccessor181.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:37)
at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at sun.proxy.$Proxy236.start(Unknown Source)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:264)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:689)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-02-28 12:36:05,496 INFO [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 11, will recycle it and start a new one
2013-02-28 12:36:05,497 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) VM is already stopped: VM[SecondaryStorageVm|s-11-VM]
2013-02-28 12:36:05,499 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) 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
2013-02-28 12:36:05,501 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Destroying vm VM[SecondaryStorageVm|s-11-VM]
2013-02-28 12:36:05,501 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning up NICS
2013-02-28 12:36:05,501 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Cleaning network for vm: 11
2013-02-28 12:36:05,509 DEBUG [network.guru.DirectNetworkGuru] (secstorage-1:null) Deallocate network: networkId: 204, ip: null
2013-02-28 12:36:05,511 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed nic id=40
2013-02-28 12:36:05,515 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed nic id=41
2013-02-28 12:36:05,515 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
2013-02-28 12:36:05,515 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Expand console proxy standby capacity for zone zone1
2013-02-28 12:36:05,517 INFO [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Found a stopped console proxy, bring it up to running pool. proxy vm id : 2
2013-02-28 12:36:05,521 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed nic id=42
2013-02-28 12:36:05,522 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null
2013-02-28 12:36:05,522 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully transitioned to start state for VM[ConsoleProxy|v-2-VM] reservation id = 8728b09e-2d0f-46e0-9e1a-ce1f6f8ff117
2013-02-28 12:36:05,523 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and podId: null
2013-02-28 12:36:05,523 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2013-02-28 12:36:05,525 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) DeploymentPlanner allocation algorithm: random
2013-02-28 12:36:05,525 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 100, requested ram: 104857600
2013-02-28 12:36:05,525 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No
2013-02-28 12:36:05,525 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching all possible resources under this Zone: 1
2013-02-28 12:36:05,526 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed nic id=43
2013-02-28 12:36:05,527 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Cleaning storage for vm: 11
2013-02-28 12:36:05,527 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2013-02-28 12:36:05,527 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) CPUOverprovisioningFactor considered: 1.0
2013-02-28 12:36:05,531 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Expunging Vol[11|vm=11|ROOT]
2013-02-28 12:36:05,533 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Marking volume that was never created as destroyed: Vol[11|vm=11|ROOT]
2013-02-28 12:36:05,533 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
2013-02-28 12:36:05,533 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,534 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
2013-02-28 12:36:05,536 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
2013-02-28 12:36:05,537 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=100Mhz, Ram=100
2013-02-28 12:36:05,537 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Expunged VM[SecondaryStorageVm|s-11-VM]
2013-02-28 12:36:05,538 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 100 and requested RAM: 104857600 , cpuOverprovisioningFactor: 1.0
2013-02-28 12:36:05,540 INFO [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) Primary secondary storage is not even started, wait until next turn
2013-02-28 12:36:05,540 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 46928 and CPU after applying overprovisioning: 46928
2013-02-28 12:36:05,540 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 46928 , Requested CPU: 100
2013-02-28 12:36:05,540 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 12049918272 , Requested RAM: 104857600
2013-02-28 12:36:05,540 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2013-02-28 12:36:05,540 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 0, reserved: 0, actual total: 46928, total with overprovisioning: 46928; requested cpu:100,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-02-28 12:36:05,540 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 0, reserved: 0, total: 12049918272; requested mem: 104857600,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-02-28 12:36:05,540 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2013-02-28 12:36:05,540 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2013-02-28 12:36:05,541 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Checking suitable pools for volume (Id, Type): (2,ROOT)
2013-02-28 12:36:05,541 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) We need to allocate new storagepool for this volume
2013-02-28 12:36:05,542 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Calling StoragePoolAllocators to find suitable pools
2013-02-28 12:36:05,542 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-02-28 12:36:05,542 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,543 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,543 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,543 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,543 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is storage pool shared? true
2013-02-28 12:36:05,543 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,543 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,543 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,543 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) Unable to find storage pool to fit the vm
2013-02-28 12:36:05,545 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Storage pool garbage collector found 0 templates to clean up in storage pool: primary1-nfs-local
2013-02-28 12:36:05,547 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Secondary storage garbage collector found 0 templates to cleanup on secondary storage host: nfs://172.16.8.23/export/secondary
2013-02-28 12:36:05,547 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Secondary storage garbage collector found 0 templates to cleanup on secondary storage host: nfs://172.16.8.23/export/secondary
2013-02-28 12:36:05,548 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-02-28 12:36:05,548 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,549 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,549 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,549 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,549 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is storage pool shared? true
2013-02-28 12:36:05,549 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,549 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,549 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,550 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) Unable to find storage pool to fit the vm
2013-02-28 12:36:05,550 DEBUG [storage.allocator.RandomStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,550 DEBUG [storage.allocator.RandomStoragePoolAllocator] (consoleproxy-1:null) RandomStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,550 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,551 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,551 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is storage pool shared? true
2013-02-28 12:36:05,551 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,551 DEBUG [storage.allocator.RandomStoragePoolAllocator] (consoleproxy-1:null) RandomStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,551 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-02-28 12:36:05,551 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2013-02-28 12:36:05,551 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator has 1 pools to check for allocation
2013-02-28 12:36:05,552 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Checking if storage pool is suitable, name: primary1-nfs-local ,poolId: 200
2013-02-28 12:36:05,552 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is localStorageAllocationNeeded? true
2013-02-28 12:36:05,552 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Is storage pool shared? true
2013-02-28 12:36:05,552 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) StoragePool is not of correct type, skipping this pool
2013-02-28 12:36:05,552 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,552 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-02-28 12:36:05,552 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) Unable to find storage pool to fit the vm
2013-02-28 12:36:05,552 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) No suitable pools found for volume: Vol[2|vm=2|ROOT] under cluster: 1
2013-02-28 12:36:05,552 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) No suitable pools found
2013-02-28 12:36:05,552 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) No suitable storagePools found under this Cluster: 1
2013-02-28 12:36:05,552 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2013-02-28 12:36:05,555 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: null
2013-02-28 12:36:05,556 WARN [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-2-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:718)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:461)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:454)
at sun.reflect.GeneratedMethodAccessor181.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:37)
at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at sun.proxy.$Proxy236.start(Unknown Source)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:630)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1960)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:174)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-02-28 12:36:05,750 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
2013-02-28 12:36:05,751 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-02-28 12:36:05,798 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
2013-02-28 12:36:05,798 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment