cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dustin J. Mitchell" <dus...@mozilla.com>
Subject Can't start SSVMs
Date Tue, 04 Feb 2014 21:30:18 GMT
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?

Mime
View raw message