I'm setting up a Cloudstack instance for evaluation. It's built on CentOS 6.5,
and I'm using libvirt + Qemu/KVM. I've followed the installation guide
closely, except that I don't have access to VLAN tagging, so I'm using a single
flat network.
The management host fails to start the SSVM. Initially, I was seeing
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:3] is
unreachable: Unable to create
Vol[44|vm=44|ROOT]:com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: internal error Child process (/bin/mount
cloudstack1.relabs.releng.scl3.mozilla.com:/export/secondary/template/tmpl/1/3
/mnt/daac6db4-0322-3624-b82f-a08a3f23ae3e) unexpected exit status 32:
mount.nfs: mounting
cloudstack1.relabs.releng.scl3.mozilla.com:/export/secondary/template/tmpl/1/3
failed, reason given by server: No such file or directory
yet the system VM was in template/tmpl/1/8. So I rsync'd 8/ to 3/ and that
error went away, but the SSVM still fails to start.
2014-02-04 13:25:03,169 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
(secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-02-04 13:25:03,172 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) No
running secondary storage vms found in datacenter id=1, starting one
2014-02-04 13:25:03,174 INFO [storage.secondary.SecondaryStorageManagerImpl]
(secstorage-1:null) No stopped secondary storage vm is available, need to
allocate a new secondary storage vm
2014-02-04 13:25:03,175 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
(secstorage-1:null) Assign secondary storage vm from a newly started instance
for request from data center : 1
2014-02-04 13:25:03,184 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Found existing network configuration for offering [Network
Offering [6-Guest-DefaultSharedNetworkOfferingWithSGService]: Ntwk[204|Guest|6]
2014-02-04 13:25:03,184 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Releasing lock for
Acct[b6f22644-89b9-11e3-8660-005056bb5624-system]
2014-02-04 13:25:03,186 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Found existing network configuration for offering [Network
Offering [3-Control-System-Control-Network]: Ntwk[202|Control|3]
2014-02-04 13:25:03,186 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Releasing lock for
Acct[b6f22644-89b9-11e3-8660-005056bb5624-system]
2014-02-04 13:25:03,188 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Found existing network configuration for offering [Network
Offering [2-Management-System-Management-Network]: Ntwk[201|Management|2]
2014-02-04 13:25:03,188 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Releasing lock for
Acct[b6f22644-89b9-11e3-8660-005056bb5624-system]
2014-02-04 13:25:03,199 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Found existing network configuration for offering [Network
Offering [4-Storage-System-Storage-Network]: Ntwk[203|Storage|4]
2014-02-04 13:25:03,199 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Releasing lock for
Acct[b6f22644-89b9-11e3-8660-005056bb5624-system]
2014-02-04 13:25:03,208 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Allocating entries for VM: VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:03,211 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Allocating nics for VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:03,212 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Allocating nic for vm VM[SecondaryStorageVm|s-114-VM] in
network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2014-02-04 13:25:03,228 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Allocating nic for vm VM[SecondaryStorageVm|s-114-VM] in
network Ntwk[202|Control|3] with requested profile null
2014-02-04 13:25:03,239 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Allocating nic for vm VM[SecondaryStorageVm|s-114-VM] in
network Ntwk[201|Management|2] with requested profile null
2014-02-04 13:25:03,251 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Allocating nic for vm VM[SecondaryStorageVm|s-114-VM] in
network Ntwk[203|Storage|4] with requested profile null
2014-02-04 13:25:03,263 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Allocating disks for VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:03,274 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Allocation completed for VM: VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:03,276 DEBUG [cloud.alert.SecondaryStorageVmAlertAdapter]
(secstorage-1:null) received secondary storage vm alert
2014-02-04 13:25:03,276 DEBUG [cloud.alert.SecondaryStorageVmAlertAdapter]
(secstorage-1:null) New secondary storage vm created, zone: releng.scl3,
secStorageVm: s-114-VM, public IP: null, private IP: null
2014-02-04 13:25:03,285 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
2014-02-04 13:25:03,285 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully transitioned to start state for
VM[SecondaryStorageVm|s-114-VM] reservation id =
b8691416-dd1a-45fc-a02d-62677b87e6f6
2014-02-04 13:25:03,292 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Trying to deploy VM, vm has dcId: 1 and podId: null
2014-02-04 13:25:03,292 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-02-04 13:25:03,294 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-02-04 13:25:03,294 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_66429f12@275d0105
2014-02-04 13:25:03,294 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
pod:null,cluster:null, requested cpu: 500, requested ram: 268435456
2014-02-04 13:25:03,294 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2014-02-04 13:25:03,294 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Searching all possible resources under this Zone: 1
2014-02-04 13:25:03,295 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
2014-02-04 13:25:03,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2014-02-04 13:25:03,305 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2014-02-04 13:25:03,309 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check
for allocation: [Host[-1-Routing]]
2014-02-04 13:25:03,312 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
prioritization: [Host[-1-Routing]]
2014-02-04 13:25:03,312 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
2014-02-04 13:25:03,320 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Checking if host: 1 has enough capacity
for requested CPU: 500 and requested RAM: 268435456 ,
cpuOverprovisioningFactor: 1.0
2014-02-04 13:25:03,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 12368 and CPU
after applying overprovisioning: 12368
2014-02-04 13:25:03,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Free CPU: 12368 , Requested CPU: 500
2014-02-04 13:25:03,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Free RAM: 3971416064 , Requested RAM:
268435456
2014-02-04 13:25:03,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-02-04 13:25:03,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1,
used: 0, reserved: 0, actual total: 12368, total with overprovisioning: 12368;
requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-02-04 13:25:03,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1,
used: 0, reserved: 0, total: 3971416064; requested mem:
268435456,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-02-04 13:25:03,325 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-02-04 13:25:03,325 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 1 suitable
hosts
2014-02-04 13:25:03,326 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Checking suitable pools for volume (Id, Type): (113,ROOT)
2014-02-04 13:25:03,326 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) We need to allocate new storagepool for this volume
2014-02-04 13:25:03,326 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Calling StoragePoolAllocators to find suitable pools
2014-02-04 13:25:03,328 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(secstorage-1:null) LocalStoragePoolAllocator trying to find storage pool to
fit the vm
2014-02-04 13:25:03,328 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (secstorage-1:null)
ClusterScopeStoragePoolAllocator looking for storage pool
2014-02-04 13:25:03,328 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (secstorage-1:null)
Looking for pools in dc: 1 pod:1 cluster:1
2014-02-04 13:25:03,333 DEBUG [storage.allocator.AbstractStoragePoolAllocator]
(secstorage-1:null) Checking if storage pool is suitable, name: null ,poolId: 3
2014-02-04 13:25:03,336 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Checking pool 3 for storage, totalSize: 37943771136,
usedBytes: 3970433024, usedPct: 0.10463991598960924, disable threshold: 0.85
2014-02-04 13:25:03,353 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Checking pool: 3 for volume allocation
[Vol[113|vm=114|ROOT]], maxSize : 75887542272, totalAllocatedSize : 0,
askingSize : 0, allocated disable threshold: 0.85
2014-02-04 13:25:03,353 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (secstorage-1:null)
ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2014-02-04 13:25:03,353 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Trying to find a potenial host and associated storage pools
from the suitable host/pool lists for this VM
2014-02-04 13:25:03,353 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Checking if host: 1 can access any suitable storage pool
for volume: ROOT
2014-02-04 13:25:03,353 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Host: 1 can access pool: 3
2014-02-04 13:25:03,357 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Found a potential host id: 1 name:
hp1.relabs.releng.scl3.mozilla.com and associated storage pools for this VM
2014-02-04 13:25:03,357 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) 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(1)-Storage(Volume(113|ROOT-->Pool(3))]
2014-02-04 13:25:03,358 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Deployment found - P0=VM[SecondaryStorageVm|s-114-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(1)-Storage(Volume(113|ROOT-->Pool(3))]
2014-02-04 13:25:03,375 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Starting to Starting with event:
OperationRetryvm's original host id: null new host id: 1 host id before state
transition: null
2014-02-04 13:25:03,386 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total CPU: 12368 and CPU after applying
overprovisioning: 12368
2014-02-04 13:25:03,386 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) We are allocating VM, increasing the used capacity of this
host:1
2014-02-04 13:25:03,386 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Current Used CPU: 0 , Free CPU:12368 ,Requested CPU: 500
2014-02-04 13:25:03,386 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Current Used RAM: 0 , Free RAM:3971416064 ,Requested RAM:
268435456
2014-02-04 13:25:03,386 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) CPU STATS after allocation: for host: 1, old used: 0, old
reserved: 0, actual total: 12368, total with overprovisioning: 12368; new
used:500, reserved:0; requested cpu:500,alloc_from_last:false
2014-02-04 13:25:03,386 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) RAM STATS after allocation: for host: 1, old used: 0, old
reserved: 0, total: 3971416064; new used: 268435456, reserved: 0; requested
mem: 268435456,alloc_from_last:false
2014-02-04 13:25:03,394 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) VM is being created in podId: 1
2014-02-04 13:25:03,404 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=204 is already implemented
2014-02-04 13:25:03,442 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to prepare for
Nic[448-114-b8691416-dd1a-45fc-a02d-62677b87e6f6-10.26.78.136]
2014-02-04 13:25:03,443 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to prepare for
Nic[448-114-b8691416-dd1a-45fc-a02d-62677b87e6f6-10.26.78.136]
2014-02-04 13:25:03,456 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=202 is already implemented
2014-02-04 13:25:03,467 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is ready to launch console proxy
2014-02-04 13:25:03,467 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Expand console proxy standby capacity for zone releng.scl3
2014-02-04 13:25:03,470 INFO [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Found a stopped console proxy, bring it up to running
pool. proxy vm id : 2
2014-02-04 13:25:03,483 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
2014-02-04 13:25:03,483 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully transitioned to start state for
VM[ConsoleProxy|v-2-VM] reservation id = 058947c3-30f2-453d-b53d-ad9710668213
2014-02-04 13:25:03,493 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=201 is already implemented
2014-02-04 13:25:03,507 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
2014-02-04 13:25:03,507 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-02-04 13:25:03,508 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-02-04 13:25:03,509 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_66429f12@275d0105
2014-02-04 13:25:03,509 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Trying to allocate a host and storage pools from dc:1,
pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2014-02-04 13:25:03,509 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No
2014-02-04 13:25:03,509 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Searching resources only under specified Pod: 1
2014-02-04 13:25:03,509 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Listing clusters in order of aggregate capacity, that
have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2014-02-04 13:25:03,517 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
2014-02-04 13:25:03,517 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2014-02-04 13:25:03,523 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
check for allocation: [Host[-1-Routing]]
2014-02-04 13:25:03,525 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Allocated a nic
NicProfile[450-114-b8691416-dd1a-45fc-a02d-62677b87e6f6-10.26.78.128-null for
VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:03,527 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
prioritization: [Host[-1-Routing]]
2014-02-04 13:25:03,528 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2014-02-04 13:25:03,533 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=203 is already implemented
2014-02-04 13:25:03,541 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has enough
capacity for requested CPU: 500 and requested RAM: 1073741824 ,
cpuOverprovisioningFactor: 1.0
2014-02-04 13:25:03,544 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 12368 and
CPU after applying overprovisioning: 12368
2014-02-04 13:25:03,544 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 11868 , Requested CPU: 500
2014-02-04 13:25:03,544 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 3702980608 , Requested RAM:
1073741824
2014-02-04 13:25:03,544 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-02-04 13:25:03,544 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1,
used: 500, reserved: 0, actual total: 12368, total with overprovisioning:
12368; requested cpu:500,alloc_from_last_host?:false
,considerReservedCapacity?: true
2014-02-04 13:25:03,544 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1,
used: 268435456, reserved: 0, total: 3971416064; requested mem:
1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-02-04 13:25:03,544 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to
list: 1
2014-02-04 13:25:03,544 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 1 suitable
hosts
2014-02-04 13:25:03,545 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Checking suitable pools for volume (Id, Type): (2,ROOT)
2014-02-04 13:25:03,545 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) We need to allocate new storagepool for this volume
2014-02-04 13:25:03,545 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Calling StoragePoolAllocators to find suitable pools
2014-02-04 13:25:03,547 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(consoleproxy-1:null) LocalStoragePoolAllocator trying to find storage pool to
fit the vm
2014-02-04 13:25:03,547 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null)
ClusterScopeStoragePoolAllocator looking for storage pool
2014-02-04 13:25:03,547 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null)
Looking for pools in dc: 1 pod:1 cluster:1
2014-02-04 13:25:03,554 DEBUG [storage.allocator.AbstractStoragePoolAllocator]
(consoleproxy-1:null) Checking if storage pool is suitable, name: null ,poolId:
3
2014-02-04 13:25:03,559 DEBUG [cloud.storage.StorageManagerImpl]
(consoleproxy-1:null) Checking pool 3 for storage, totalSize: 37943771136,
usedBytes: 3970433024, usedPct: 0.10463991598960924, disable threshold: 0.85
2014-02-04 13:25:03,559 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Allocated a nic
NicProfile[451-114-b8691416-dd1a-45fc-a02d-62677b87e6f6-10.26.78.134-null for
VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:03,567 DEBUG [cloud.storage.VolumeManagerImpl]
(secstorage-1:null) Checking if we need to prepare 1 volumes for
VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:03,575 DEBUG [storage.image.TemplateDataFactoryImpl]
(secstorage-1:null) template 3 is already in store:1, type:Image
2014-02-04 13:25:03,576 DEBUG [cloud.storage.StorageManagerImpl]
(consoleproxy-1:null) Checking pool: 3 for volume allocation
[Vol[2|vm=2|ROOT]], maxSize : 75887542272, totalAllocatedSize : 0, askingSize :
0, allocated disable threshold: 0.85
2014-02-04 13:25:03,576 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null)
ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2014-02-04 13:25:03,576 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Trying to find a potenial host and associated storage
pools from the suitable host/pool lists for this VM
2014-02-04 13:25:03,576 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Checking if host: 1 can access any suitable storage pool
for volume: ROOT
2014-02-04 13:25:03,580 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Host: 1 can access pool: 3
2014-02-04 13:25:03,583 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) Found a potential host id: 1 name:
hp1.relabs.releng.scl3.mozilla.com and associated storage pools for this VM
2014-02-04 13:25:03,584 DEBUG [storage.datastore.PrimaryDataStoreImpl]
(secstorage-1:null) Not found (templateId:3poolId:3) in template_spool_ref,
persisting it
2014-02-04 13:25:03,585 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(consoleproxy-1:null) 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(1)-Storage(Volume(2|ROOT-->Pool(3))]
2014-02-04 13:25:03,585 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Deployment found - P0=VM[ConsoleProxy|v-2-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(1)-Storage(Volume(2|ROOT-->Pool(3))]
2014-02-04 13:25:03,593 DEBUG [storage.image.TemplateDataFactoryImpl]
(secstorage-1:null) template 3 is already in store:3, type:Primary
2014-02-04 13:25:03,595 DEBUG [storage.volume.VolumeServiceImpl]
(secstorage-1:null) Found template routing-3 in storage pool 3 with
VMTemplateStoragePool id: 301
2014-02-04 13:25:03,600 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Starting to Starting with
event: OperationRetryvm's original host id: null new host id: 1 host id before
state transition: null
2014-02-04 13:25:03,609 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total CPU: 12368 and CPU after applying
overprovisioning: 12368
2014-02-04 13:25:03,610 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) We are allocating VM, increasing the used capacity of
this host:1
2014-02-04 13:25:03,610 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Current Used CPU: 500 , Free CPU:11868 ,Requested CPU: 500
2014-02-04 13:25:03,610 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Current Used RAM: 268435456 , Free RAM:3702980608
,Requested RAM: 1073741824
2014-02-04 13:25:03,610 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) CPU STATS after allocation: for host: 1, old used: 500,
old reserved: 0, actual total: 12368, total with overprovisioning: 12368; new
used:1000, reserved:0; requested cpu:500,alloc_from_last:false
2014-02-04 13:25:03,610 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) RAM STATS after allocation: for host: 1, old used:
268435456, old reserved: 0, total: 3971416064; new used: 1342177280, reserved:
0; requested mem: 1
073741824,alloc_from_last:false
2014-02-04 13:25:03,610 DEBUG [storage.volume.VolumeServiceImpl]
(secstorage-1:null) Acquire lock on VMTemplateStoragePool 301 with timeout 3600
seconds
2014-02-04 13:25:03,612 INFO [storage.volume.VolumeServiceImpl]
(secstorage-1:null) lock is acquired for VMTemplateStoragePool 301
2014-02-04 13:25:03,617 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) VM is being created in podId: 1
2014-02-04 13:25:03,622 DEBUG [storage.motion.AncientDataMotionStrategy]
(secstorage-1:null) copyAsync inspecting src type TEMPLATE copyAsync inspecting
dest type TEMPLATE
2014-02-04 13:25:03,631 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Network id=204 is already implemented
2014-02-04 13:25:03,641 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-2118320200: Sending { Cmd , MgmtId: 345052501540, via: 1, Ver: v1, Flags:
100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/3/","origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-06-12-master-kvm.qcow2.bz2","uuid":"74849bde-89b9-11e3-8660-005056bb5624","id":3,"format":"QCOW2","accountId":1,"checksum":"6cea42b2633841648040becb588bd8f0","hvm":false,"displayText":"SystemVM
Template
(KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://cloudstack1.relabs.releng.scl3.mozilla.com/export/secondary","_role":"Image"}},"name":"routing-3","hypervisorType":"KVM"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-06-12-master-kvm.qcow2.bz2","uuid":"74849bde-89b9-11e3-8660-005056bb5624","id":3,"format":"QCOW2","accountId":1,"checksum":"6cea42b2633841648040becb588bd8f0","hvm":false,"displayText":"SystemVM
Template
(KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1efb0737-b839-35ba-9f41-f54a57f5bd66","id":3,"poolType":"NetworkFilesystem","host":"cloudstack1.relabs.releng.scl3.mozilla.com","path":"/export/primary","port":2049}},"name":"routing-3","hypervisorType":"KVM"}},"executeInSequence":true,"wait":10800}}]
}
2014-02-04 13:25:03,668 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to prepare for
Nic[5-2-058947c3-30f2-453d-b53d-ad9710668213-10.26.78.137]
2014-02-04 13:25:03,669 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
Nic[5-2-058947c3-30f2-453d-b53d-ad9710668213-10.26.78.137]
2014-02-04 13:25:03,675 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Network id=202 is already implemented
2014-02-04 13:25:03,705 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Network id=201 is already implemented
2014-02-04 13:25:03,728 DEBUG [network.guru.PodBasedNetworkGuru]
(consoleproxy-1:null) Allocated a nic
NicProfile[7-2-058947c3-30f2-453d-b53d-ad9710668213-10.26.78.132-null for
VM[ConsoleProxy|v-2-VM]
2014-02-04 13:25:03,735 DEBUG [cloud.storage.VolumeManagerImpl]
(consoleproxy-1:null) Checking if we need to prepare 1 volumes for
VM[ConsoleProxy|v-2-VM]
2014-02-04 13:25:03,743 DEBUG [storage.image.TemplateDataFactoryImpl]
(consoleproxy-1:null) template 3 is already in store:1, type:Image
2014-02-04 13:25:03,749 DEBUG [storage.image.TemplateDataFactoryImpl]
(consoleproxy-1:null) template 3 is already in store:3, type:Primary
2014-02-04 13:25:03,751 DEBUG [storage.volume.VolumeServiceImpl]
(consoleproxy-1:null) Found template routing-3 in storage pool 3 with
VMTemplateStoragePool id: 301
2014-02-04 13:25:03,761 DEBUG [storage.volume.VolumeServiceImpl]
(consoleproxy-1:null) Acquire lock on VMTemplateStoragePool 301 with timeout
3600 seconds
2014-02-04 13:25:03,809 DEBUG [agent.transport.Request]
(AgentManager-Handler-8:null) Seq 1-2118320200: Processing: { Ans: , MgmtId:
345052501540, via: 1, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Failed
to get template from pool: daac6db4-0322-3624-b82f-a08a3f23ae3e","wait":0}}] }
2014-02-04 13:25:03,809 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-8:null) Seq 1-2118320200: No more commands found
2014-02-04 13:25:03,811 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-2118320200: Received: { Ans: , MgmtId: 345052501540, via: 1, Ver: v1, Flags:
110, { PrimaryStorageDownloadAnswer } }
2014-02-04 13:25:03,827 INFO [storage.volume.VolumeServiceImpl]
(secstorage-1:null) releasing lock for VMTemplateStoragePool 301
2014-02-04 13:25:03,827 WARN [utils.db.Merovingian2] (secstorage-1:null) Was
unable to find lock for the key template_spool_ref301 and thread id 1941598313
2014-02-04 13:25:03,827 DEBUG [cloud.storage.VolumeManagerImpl]
(secstorage-1:null) Unable to create Vol[113|vm=114|ROOT]:Failed to get
template from pool: daac6db4-0322-3624-b82f-a08a3f23ae3e
2014-02-04 13:25:03,827 INFO [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:3] is
unreachable: Unable to create Vol[113|vm=114|ROOT]:Failed to get template from
pool: daac6db4-0322-3624-b82f-a08a3f23ae3e
at
com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2590)
at
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2641)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:570)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:267)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
at
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2014-02-04 13:25:03,833 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Cleaning up resources for the vm
VM[SecondaryStorageVm|s-114-VM] in Starting state
2014-02-04 13:25:03,835 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-2118320201: Sending { Cmd , MgmtId: 345052501540, via: 1, Ver: v1, Flags:
100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"s-114-VM","wait":0}}]
}
2014-02-04 13:25:03,951 DEBUG [agent.transport.Request]
(AgentManager-Handler-9:null) Seq 1-2118320201: Processing: { Ans: , MgmtId:
345052501540, via: 1, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-02-04 13:25:03,952 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-9:null) Seq 1-2118320201: No more commands found
2014-02-04 13:25:03,952 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-2118320201: Received: { Ans: , MgmtId: 345052501540, via: 1, Ver: v1, Flags:
110, { StopAnswer } }
2014-02-04 13:25:03,969 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[448-114-b8691416-dd1a-45fc-a02d-62677b87e6f6-10.26.78.136]
2014-02-04 13:25:03,970 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[448-114-b8691416-dd1a-45fc-a02d-62677b87e6f6-10.26.78.136]
2014-02-04 13:25:03,975 DEBUG [network.guru.ControlNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[449-114-null-null-null
2014-02-04 13:25:03,984 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for
reservationId=b8691416-dd1a-45fc-a02d-62677b87e6f6, instance=450
2014-02-04 13:25:03,984 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[450-114-null-null-null
2014-02-04 13:25:03,994 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for
reservationId=b8691416-dd1a-45fc-a02d-62677b87e6f6, instance=451
2014-02-04 13:25:03,994 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[451-114-null-null-null
2014-02-04 13:25:04,004 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully released network resources for the vm
VM[SecondaryStorageVm|s-114-VM]
2014-02-04 13:25:04,004 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully cleanued up resources for the vm
VM[SecondaryStorageVm|s-114-VM] in Starting state
2014-02-04 13:25:04,005 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: [1]
2014-02-04 13:25:04,006 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_66429f12@275d0105
2014-02-04 13:25:04,006 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
pod:null,cluster:null, requested cpu: 500, requested ram: 268435456
2014-02-04 13:25:04,006 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2014-02-04 13:25:04,006 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Searching all possible resources under this Zone: 1
2014-02-04 13:25:04,006 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
2014-02-04 13:25:04,014 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2014-02-04 13:25:04,014 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2014-02-04 13:25:04,016 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check
for allocation: [Host[-1-Routing]]
2014-02-04 13:25:04,019 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
prioritization: [Host[-1-Routing]]
2014-02-04 13:25:04,019 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
2014-02-04 13:25:04,019 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host name:
hp1.relabs.releng.scl3.mozilla.com, hostId: 1 is in avoid set, skipping this
and trying other available hosts
2014-02-04 13:25:04,019 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0 suitable
hosts
2014-02-04 13:25:04,019 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) No suitable hosts found
2014-02-04 13:25:04,019 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) No suitable hosts found under this Cluster: 1
2014-02-04 13:25:04,020 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(secstorage-1:null) Could not find suitable Deployment Destination for this VM
under any clusters, returning.
2014-02-04 13:25:04,020 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Searching all possible resources under this Zone: 1
2014-02-04 13:25:04,021 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
2014-02-04 13:25:04,026 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Removing from the clusterId list these clusters from avoid
set: [1]
2014-02-04 13:25:04,026 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) No clusters found after removing disabled clusters and
clusters in avoid list, returning.
2014-02-04 13:25:04,041 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Starting to Stopped with event:
OperationFailedvm's original host id: null new host id: null host id before
state transition: 1
2014-02-04 13:25:04,052 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total CPU: 12368 and CPU after applying
overprovisioning: 12368
2014-02-04 13:25:04,052 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total RAM: 3971416064 and RAM after applying
overprovisioning: 3971416064
2014-02-04 13:25:04,052 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release cpu from host: 1, old used: 1000,reserved: 0,
actual total: 12368, total with overprovisioning: 12368; new used:
500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-02-04 13:25:04,052 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release mem from host: 1, old used: 1342177280,reserved: 0,
total: 3971416064; new used: 1073741824,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2014-02-04 13:25:04,059 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-114-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:841)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:570)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:267)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
at
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2014-02-04 13:25:04,060 INFO [storage.secondary.SecondaryStorageManagerImpl]
(secstorage-1:null) Unable to start secondary storage vm for standby capacity,
secStorageVm vm Id : 114, will recycle it and start a new one
2014-02-04 13:25:04,060 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
Primary secondary storage is not even started, wait until next turn
Any suggestions?
