cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From jason pavao <jason.pa...@oracle.com>
Subject CS 4.2.1 install can't get system vms to start
Date Thu, 05 Dec 2013 06:41:28 GMT
Folks,
I am working on installing a new 4.2.1 CS installation and I believe 
I've taken care of all the prerequisites, however I am unable to start 
my system vms and proceed with bringing up my cloud.

Below is output from my management-server.log

Can anyone lend a hand and let me know what i've done wrong/whats not 
working?

Many thanks in advance!
-jason

2013-12-04 23:36:07,268 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Cleaning up resources for the vm 
VM[SecondaryStorageVm|s-7-VM] in Starting state
2013-12-04 23:36:07,269 DEBUG [agent.transport.Request] 
(secstorage-1:null) Seq 1-1792016451: Sending  { Cmd , MgmtId: 
345049479113, via: 1, Ver: v1, Flags: 100111, 
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"s-7-VM","wait":0}}]

}
2013-12-04 23:36:07,275 DEBUG [cloud.network.NetworkManagerImpl] 
(consoleproxy-1:null) Asking VirtualRouter to prepare for 
Nic[15-5-3824b517-c0cb-4032-930e-ffa838c1a875-10.240.186.240]
2013-12-04 23:36:07,276 DEBUG [cloud.network.NetworkManagerImpl] 
(consoleproxy-1:null) Asking SecurityGroupProvider to prepare for 
Nic[15-5-3824b517-c0cb-4032-930e-ffa838c1a875-10.240.186.240]
2013-12-04 23:36:07,279 DEBUG [cloud.network.NetworkManagerImpl] 
(consoleproxy-1:null) Network id=202 is already implemented
2013-12-04 23:36:07,291 DEBUG [cloud.network.NetworkManagerImpl] 
(consoleproxy-1:null) Network id=201 is already implemented
2013-12-04 23:36:07,300 DEBUG [network.guru.PodBasedNetworkGuru] 
(consoleproxy-1:null) Allocated a nic 
NicProfile[17-5-3824b517-c0cb-4032-930e-ffa838c1a875-10.240.186.238-null 
for VM[ConsoleProxy|v-5-VM]
2013-12-04 23:36:07,303 DEBUG [cloud.storage.VolumeManagerImpl] 
(consoleproxy-1:null) Checking if we need to prepare 1 volumes for 
VM[ConsoleProxy|v-5-VM]
2013-12-04 23:36:07,307 DEBUG [storage.image.TemplateDataFactoryImpl] 
(consoleproxy-1:null) template 3 is already in store:1, type:Image
2013-12-04 23:36:07,309 DEBUG [storage.datastore.PrimaryDataStoreImpl] 
(consoleproxy-1:null) Not found (templateId:3poolId:2) in 
template_spool_ref, persisting it
2013-12-04 23:36:07,312 DEBUG [storage.image.TemplateDataFactoryImpl] 
(consoleproxy-1:null) template 3 is already in store:2, type:Primary
2013-12-04 23:36:07,313 DEBUG [storage.volume.VolumeServiceImpl] 
(consoleproxy-1:null) Found template routing-3 in storage pool 2 with 
VMTemplateStoragePool id: 12
2013-12-04 23:36:07,317 DEBUG [storage.volume.VolumeServiceImpl] 
(consoleproxy-1:null) Acquire lock on VMTemplateStoragePool 12 with 
timeout 3600 seconds
2013-12-04 23:36:07,318 INFO  [storage.volume.VolumeServiceImpl] 
(consoleproxy-1:null) lock is acquired for VMTemplateStoragePool 12
2013-12-04 23:36:07,321 DEBUG [storage.motion.AncientDataMotionStrategy] 
(consoleproxy-1:null) copyAsync inspecting src type TEMPLATE copyAsync 
inspecting dest type TEMPLATE
2013-12-04 23:36:07,326 DEBUG [agent.transport.Request] 
(consoleproxy-1:null) Seq 1-1792016452: Waiting for Seq 1792016451 
Scheduling:  { Cmd , MgmtId: 345049479113, 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":"77aa140e-5ca7-11e3-a598-0050568d37c9","id":3,"format":"QCOW2","accountId":1,"checksum":"6cea42b2633841648040becb588bd8f0","hvm":false,"displayText":"SystemVM

Template 
(KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://slcnas5043.us.oracle.com/export/osn_images/cloud/cloudstack/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":"77aa140e-5ca7-11e3-a598-0050568d37c9","id":3,"format":"QCOW2","accountId":1,"checksum":"6cea42b2633841648040becb588bd8f0","hvm":false,"displayText":"SystemVM

Template 
(KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"57f8e728-f0b8-324d-96cb-fdad763e14be","id":2,"poolType":"NetworkFilesystem","host":"slcnas504.us.oracle.com","path":"/export/osn_images/cloud/cloudstack/primary","port":2049}},"name":"routing-3","hypervisorType":"KVM"}},"executeInSequence":true,"wait":10800}}]

}
2013-12-04 23:36:07,486 DEBUG [agent.transport.Request] 
(AgentManager-Handler-12:null) Seq 1-1792016451: Processing:  { Ans: , 
MgmtId: 345049479113, via: 1, Ver: v1, Flags: 110, 
[{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2013-12-04 23:36:07,486 DEBUG [agent.manager.AgentAttache] 
(AgentManager-Handler-12:null) Seq 1-1792016452: Sending now.  is 
current sequence.
2013-12-04 23:36:07,487 DEBUG [agent.transport.Request] 
(secstorage-1:null) Seq 1-1792016451: Received:  { Ans: , MgmtId: 
345049479113, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2013-12-04 23:36:07,495 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VirtualRouter to release 
Nic[22-7-9f31089b-876b-48b3-8392-a540848cb21e-10.240.186.239]
2013-12-04 23:36:07,497 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to release 
Nic[22-7-9f31089b-876b-48b3-8392-a540848cb21e-10.240.186.239]
2013-12-04 23:36:07,498 DEBUG [network.guru.ControlNetworkGuru] 
(secstorage-1:null) Released nic: NicProfile[23-7-null-null-null
2013-12-04 23:36:07,502 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] 
(secstorage-1:null) Releasing ip address for 
reservationId=9f31089b-876b-48b3-8392-a540848cb21e, instance=24
2013-12-04 23:36:07,503 DEBUG [network.guru.PodBasedNetworkGuru] 
(secstorage-1:null) Released nic: NicProfile[24-7-null-null-null
2013-12-04 23:36:07,507 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] 
(secstorage-1:null) Releasing ip address for 
reservationId=9f31089b-876b-48b3-8392-a540848cb21e, instance=25
2013-12-04 23:36:07,507 DEBUG [network.guru.PodBasedNetworkGuru] 
(secstorage-1:null) Released nic: NicProfile[25-7-null-null-null
2013-12-04 23:36:07,509 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Successfully released network resources for the vm 
VM[SecondaryStorageVm|s-7-VM]
2013-12-04 23:36:07,509 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Successfully cleanued up resources for the vm 
VM[SecondaryStorageVm|s-7-VM] in Starting state
2013-12-04 23:36:07,510 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Deploy 
avoids pods: null, clusters: null, hosts: [1]
2013-12-04 23:36:07,511 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) 
DeploymentPlanner allocation algorithm: 
com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_4b954164@34a03ec8
2013-12-04 23:36:07,511 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
2013-12-04 23:36:07,511 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Is ROOT 
volume READY (pool already allocated)?: No
2013-12-04 23:36:07,511 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Searching all possible resources under this Zone: 1
2013-12-04 23:36:07,512 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-12-04 23:36:07,516 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) 
Checking resources in Cluster: 1 under Pod: 1
2013-12-04 23:36:07,516 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 
pod:1  cluster:1
2013-12-04 23:36:07,518 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to 
check for allocation: [Host[-1-Routing]]
2013-12-04 23:36:07,519 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation 
after prioritization: [Host[-1-Routing]]
2013-12-04 23:36:07,519 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
2013-12-04 23:36:07,519 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Host name: 
slcai547.us.oracle.com, hostId: 1 is in avoid set, skipping this and 
trying other available hosts
2013-12-04 23:36:07,520 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0 
suitable hosts
2013-12-04 23:36:07,520 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) No 
suitable hosts found
2013-12-04 23:36:07,520 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) No 
suitable hosts found under this Cluster: 1
2013-12-04 23:36:07,521 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Could 
not find suitable Deployment Destination for this VM under any clusters, 
returning.
2013-12-04 23:36:07,521 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Searching all possible resources under this Zone: 1
2013-12-04 23:36:07,522 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-12-04 23:36:07,523 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Removing from the clusterId list these clusters from 
avoid set: [1]
2013-12-04 23:36:07,524 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) No clusters found after removing disabled clusters 
and clusters in avoid list, returning.
2013-12-04 23:36:07,527 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) VM state transitted from :Starting to Stopped with 
event: OperationFailedvm's original host id: null new host id: null host 
id before state transition: 1
2013-12-04 23:36:07,531 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) Hosts's actual total CPU: 92832 and CPU after 
applying overprovisioning: 92832
2013-12-04 23:36:07,531 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) Hosts's actual total RAM: 271024279552 and RAM after 
applying overprovisioning: 271024275456
2013-12-04 23:36:07,531 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) release cpu from host: 1, old used: 1000,reserved: 
0, actual total: 92832, total with overprovisioning: 92832; new used: 
500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-04 23:36:07,531 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) release mem from host: 1, old used: 
1342177280,reserved: 0, total: 271024275456; new used: 
1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-04 23:36:07,533 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-7-VM]Scope=interface 
com.cloud.dc.DataCenter; id=1
         at 
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
         at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
         at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
         at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:267)
         at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
         at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
         at 
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
         at 
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
         at 
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
         at 
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
         at 
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
         at 
com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
         at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
         at 
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
         at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
         at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
         at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
         at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
         at java.lang.Thread.run(Thread.java:701)
2013-12-04 23:36:07,533 INFO 
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) 
Unable to start secondary storage vm for standby capacity, secStorageVm 
vm Id : 7, will recycle it and start a new one
2013-12-04 23:36:07,533 INFO 
[cloud.secstorage.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:null) Primary secondary storage is not even started, wait 
until next turn
2013-12-04 23:36:07,582 DEBUG [agent.transport.Request] 
(AgentManager-Handler-13:null) Seq 1-1792016452: Processing:  { Ans: , 
MgmtId: 345049479113, via: 1, Ver: v1, Flags: 110, 
[{"com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Failed

to get volumes from pool: 
a2711e07-f69b-3269-84a6-fccdda39a77e","wait":0}}] }
2013-12-04 23:36:07,582 DEBUG [agent.manager.AgentAttache] 
(AgentManager-Handler-13:null) Seq 1-1792016452: No more commands found
2013-12-04 23:36:07,582 DEBUG [agent.transport.Request] 
(consoleproxy-1:null) Seq 1-1792016452: Received:  { Ans: , MgmtId: 
345049479113, via: 1, Ver: v1, Flags: 110, { 
PrimaryStorageDownloadAnswer } }
2013-12-04 23:36:07,585 INFO  [storage.volume.VolumeServiceImpl] 
(consoleproxy-1:null) releasing lock for VMTemplateStoragePool 12
2013-12-04 23:36:07,586 WARN  [utils.db.Merovingian2] 
(consoleproxy-1:null) Was unable to find lock for the key 
template_spool_ref12 and thread id 320120691
2013-12-04 23:36:07,586 DEBUG [cloud.storage.VolumeManagerImpl] 
(consoleproxy-1:null) Unable to create Vol[5|vm=5|ROOT]:Failed to get 
volumes from pool: a2711e07-f69b-3269-84a6-fccdda39a77e
2013-12-04 23:36:07,586 INFO  [cloud.vm.VirtualMachineManagerImpl] 
(consoleproxy-1:null) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource 
[StoragePool:2] is unreachable: Unable to create Vol[5|vm=5|ROOT]:Failed 
to get volumes from pool: a2711e07-f69b-3269-84a6-fccdda39a77e
         at 
com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2544)
         at 
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2592)
         at 
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:889)
         at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
         at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
         at 
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
         at 
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
         at 
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
         at 
com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
         at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
         at 
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
         at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
         at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
         at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
         at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
         at java.lang.Thread.run(Thread.java:701)
2013-12-04 23:36:07,588 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(consoleproxy-1:null) Cleaning up resources for the vm 
VM[ConsoleProxy|v-5-VM] in Starting state
2013-12-04 23:36:07,588 DEBUG [agent.transport.Request] 
(consoleproxy-1:null) Seq 1-1792016453: Sending  { Cmd , MgmtId: 
345049479113, via: 1, Ver: v1, Flags: 100111, 
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"v-5-VM","wait":0}}]

}
2013-12-04 23:36:07,802 DEBUG [agent.transport.Request] 
(AgentManager-Handler-14:null) Seq 1-1792016453: Processing:  { Ans: , 
MgmtId: 345049479113, via: 1, Ver: v1, Flags: 110, 
[{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2013-12-04 23:36:07,802 DEBUG [agent.manager.AgentAttache] 
(AgentManager-Handler-14:null) Seq 1-1792016453: No more commands found
2013-12-04 23:36:07,802 DEBUG [agent.transport.Request] 
(consoleproxy-1:null) Seq 1-1792016453: Received:  { Ans: , MgmtId: 
345049479113, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2013-12-04 23:36:07,810 DEBUG [cloud.network.NetworkManagerImpl] 
(consoleproxy-1:null) Asking VirtualRouter to release 
Nic[15-5-3824b517-c0cb-4032-930e-ffa838c1a875-10.240.186.240]
2013-12-04 23:36:07,811 DEBUG [cloud.network.NetworkManagerImpl] 
(consoleproxy-1:null) Asking SecurityGroupProvider to release 
Nic[15-5-3824b517-c0cb-4032-930e-ffa838c1a875-10.240.186.240]
2013-12-04 23:36:07,813 DEBUG [network.guru.ControlNetworkGuru] 
(consoleproxy-1:null) Released nic: NicProfile[16-5-null-null-null
2013-12-04 23:36:07,817 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] 
(consoleproxy-1:null) Releasing ip address for 
reservationId=3824b517-c0cb-4032-930e-ffa838c1a875, instance=17
2013-12-04 23:36:07,817 DEBUG [network.guru.PodBasedNetworkGuru] 
(consoleproxy-1:null) Released nic: NicProfile[17-5-null-null-null
2013-12-04 23:36:07,818 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(consoleproxy-1:null) Successfully released network resources for the vm 
VM[ConsoleProxy|v-5-VM]
2013-12-04 23:36:07,818 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(consoleproxy-1:null) Successfully cleanued up resources for the vm 
VM[ConsoleProxy|v-5-VM] in Starting state
2013-12-04 23:36:07,819 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) 
Deploy avoids pods: null, clusters: null, hosts: [1]
2013-12-04 23:36:07,820 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) 
DeploymentPlanner allocation algorithm: 
com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_4b954164@34a03ec8
2013-12-04 23:36:07,820 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) 
Trying to allocate a host and storage pools from dc:1, 
pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2013-12-04 23:36:07,820 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is 
ROOT volume READY (pool already allocated)?: No
2013-12-04 23:36:07,820 DEBUG [cloud.deploy.FirstFitPlanner] 
(consoleproxy-1:null) Searching resources only under specified Pod: 1
2013-12-04 23:36:07,820 DEBUG [cloud.deploy.FirstFitPlanner] 
(consoleproxy-1:null) Listing clusters in order of aggregate capacity, 
that have (atleast one host with) enough CPU and RAM capacity under this 
Pod: 1
2013-12-04 23:36:07,825 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) 
Checking resources in Cluster: 1 under Pod: 1
2013-12-04 23:36:07,825 DEBUG [allocator.impl.FirstFitAllocator] 
(consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1  
pod:1  cluster:1
2013-12-04 23:36:07,826 DEBUG [allocator.impl.FirstFitAllocator] 
(consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts 
to check for allocation: [Host[-1-Routing]]
2013-12-04 23:36:07,828 DEBUG [allocator.impl.FirstFitAllocator] 
(consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation 
after prioritization: [Host[-1-Routing]]
2013-12-04 23:36:07,828 DEBUG [allocator.impl.FirstFitAllocator] 
(consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2013-12-04 23:36:07,828 DEBUG [allocator.impl.FirstFitAllocator] 
(consoleproxy-1:FirstFitRoutingAllocator) Host name: 
slcai547.us.oracle.com, hostId: 1 is in avoid set, skipping this and 
trying other available hosts
2013-12-04 23:36:07,828 DEBUG [allocator.impl.FirstFitAllocator] 
(consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 0 
suitable hosts
2013-12-04 23:36:07,828 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No 
suitable hosts found
2013-12-04 23:36:07,828 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No 
suitable hosts found under this Cluster: 1
2013-12-04 23:36:07,830 DEBUG 
[cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Could 
not find suitable Deployment Destination for this VM under any clusters, 
returning.
2013-12-04 23:36:07,830 DEBUG [cloud.deploy.FirstFitPlanner] 
(consoleproxy-1:null) Searching resources only under specified Pod: 1
2013-12-04 23:36:07,830 DEBUG [cloud.deploy.FirstFitPlanner] 
(consoleproxy-1:null) Listing clusters in order of aggregate capacity, 
that have (atleast one host with) enough CPU and RAM capacity under this 
Pod: 1
2013-12-04 23:36:07,831 DEBUG [cloud.deploy.FirstFitPlanner] 
(consoleproxy-1:null) Removing from the clusterId list these clusters 
from avoid set: [1]
2013-12-04 23:36:07,831 DEBUG [cloud.deploy.FirstFitPlanner] 
(consoleproxy-1:null) No clusters found after removing disabled clusters 
and clusters in avoid list, returning.
2013-12-04 23:36:07,835 DEBUG [cloud.capacity.CapacityManagerImpl] 
(consoleproxy-1:null) VM state transitted from :Starting to Stopped with 
event: OperationFailedvm's original host id: null new host id: null host 
id before state transition: 1
2013-12-04 23:36:07,839 DEBUG [cloud.capacity.CapacityManagerImpl] 
(consoleproxy-1:null) Hosts's actual total CPU: 92832 and CPU after 
applying overprovisioning: 92832
2013-12-04 23:36:07,839 DEBUG [cloud.capacity.CapacityManagerImpl] 
(consoleproxy-1:null) Hosts's actual total RAM: 271024279552 and RAM 
after applying overprovisioning: 271024275456
2013-12-04 23:36:07,839 DEBUG [cloud.capacity.CapacityManagerImpl] 
(consoleproxy-1:null) release cpu from host: 1, old used: 500,reserved: 
0, actual total: 92832, total with overprovisioning: 92832; new used: 
0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-04 23:36:07,839 DEBUG [cloud.capacity.CapacityManagerImpl] 
(consoleproxy-1:null) release mem from host: 1, old used: 
1073741824,reserved: 0, total: 271024275456; new used: 0,reserved:0; 
movedfromreserved: false,moveToReserveredfalse
2013-12-04 23:36:07,841 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-5-VM]Scope=interface 
com.cloud.dc.DataCenter; id=1
         at 
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
         at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
         at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
         at 
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
         at 
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
         at 
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
         at 
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
         at 
com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
         at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
         at 
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
         at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
         at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
         at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
         at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
         at java.lang.Thread.run(Thread.java:701)
2013-12-04 23:36:07,979 DEBUG 
[network.router.VirtualNetworkApplianceManagerImpl] 
(RouterStatusMonitor-1:null) Found 0 routers to update status.
2013-12-04 23:36:07,980 DEBUG 
[network.router.VirtualNetworkApplianceManagerImpl] 
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-12-04 23:36:08,011 DEBUG 
[network.router.VirtualNetworkApplianceManagerImpl] 
(RouterStatusMonitor-1:null) Found 0 routers to update status.
2013-12-04 23:36:08,011 DEBUG 
[network.router.VirtualNetworkApplianceManagerImpl] 
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.


Mime
View raw message