You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users-cn@cloudstack.apache.org by 许叁征 <xu...@chinanetcenter.com> on 2014/03/04 10:18:51 UTC
答复: Re: 在windows下编译cloudstack4.1.1
HI ALL
碰到一个问题，SSVM和CVM不能启动， 以下是日志，请教 大家这是问题出在哪，应如何解决，谢谢了。
014-03-04 17:16:08,012 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-22:job-344) Cleaning up resources for the vm VM[ConsoleProxy|v-62160-VM] in Starting state
2014-03-04 17:16:08,014 DEBUG [agent.transport.Request] (Job-Executor-22:job-344) Seq 56-1158480075: Sending { Cmd , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-62160-VM","wait":0}}] }
2014-03-04 17:16:08,014 DEBUG [agent.transport.Request] (Job-Executor-22:job-344) Seq 56-1158480075: Executing: { Cmd , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-62160-VM","wait":0}}] }
2014-03-04 17:16:08,014 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-250:null) Seq 56-1158480075: Executing request
2014-03-04 17:16:08,174 INFO [xen.resource.CitrixResourceBase] (DirectAgent-250:null) VM does not exist on XenServerf2f076b1-1405-451c-b37e-caf3605b6656
2014-03-04 17:16:08,174 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-250:null) Seq 56-1158480075: Response Received:
2014-03-04 17:16:08,174 DEBUG [agent.transport.Request] (DirectAgent-250:null) Seq 56-1158480075: Processing: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
2014-03-04 17:16:08,174 DEBUG [agent.manager.AgentAttache] (DirectAgent-250:null) Seq 56-1158480075: No more commands found
2014-03-04 17:16:08,174 DEBUG [agent.transport.Request] (Job-Executor-22:job-344) Seq 56-1158480075: Received: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 110, { StopAnswer } }
2014-03-04 17:16:08,243 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-22:job-344) Provider SecurityGroupProvider is not enabled in physical network id=200
2014-03-04 17:16:08,447 DEBUG [network.guru.ControlNetworkGuru] (Job-Executor-22:job-344) Released nic: NicProfile[248067-62160-null-null-null
2014-03-04 17:16:08,583 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] (Job-Executor-22:job-344) Releasing ip address for reservationId=3ebb6122-552e-49ef-aa7c-60e6db77163d, instance=248068
2014-03-04 17:16:08,647 DEBUG [network.guru.PodBasedNetworkGuru] (Job-Executor-22:job-344) Released nic: NicProfile[248068-62160-null-null-null
2014-03-04 17:16:08,714 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-22:job-344) Successfully released network resources for the vm VM[ConsoleProxy|v-62160-VM]
2014-03-04 17:16:08,714 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-22:job-344) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-62160-VM] in Starting state
2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) DeploymentPlanner allocation algorithm: random
2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Is ROOT volume READY (pool already allocated)?: No
2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Searching resources only under specified Pod: 1
2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Searching resources only under specified Pod: 1
2014-03-04 17:16:08,718 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2014-03-04 17:16:08,719 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) CPUOverprovisioningFactor considered: 6.0
2014-03-04 17:16:08,726 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Checking resources in Cluster: 1 under Pod: 1
2014-03-04 17:16:08,726 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Calling HostAllocators to find suitable hosts
2014-03-04 17:16:08,726 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2014-03-04 17:16:08,728 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check for allocation: [Host[-55-Routing], Host[-56-Routing]]
2014-03-04 17:16:08,731 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Found 2 hosts for allocation after prioritization: [Host[-55-Routing], Host[-56-Routing]]
2014-03-04 17:16:08,731 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2014-03-04 17:16:08,732 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Checking if host: 55 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 6.0
2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Hosts's actual total CPU: 34128 and CPU after applying overprovisioning: 204768
2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Free CPU: 172768 , Requested CPU: 500
2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Free RAM: 850673984 , Requested RAM: 1073741824
2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) STATS: Failed to alloc resource from host: 55 reservedCpu: 0, used cpu: 32000, requested cpu: 500, actual total cpu: 34128, total cpu with overprovisioning: 204768, reservedMem: 0, used Mem: 23622320128, requested mem: 1073741824, total Mem:24472994112 ,considerReservedCapacity?: true
2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) STATS: Failed to alloc resource from host: 55 reservedCpu: 0, used cpu: 32000, requested cpu: 500, actual total cpu: 34128, total cpu with overprovisioning: 204768, reservedMem: 0, used Mem: 23622320128, requested mem: 1073741824, total Mem:24472994112 ,considerReservedCapacity?: true
2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Host does not have enough RAM available, cannot allocate to this host.
2014-03-04 17:16:08,734 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Not using host 55; numCpusGood: true; cpuFreqGood: true, host has capacity?false
2014-03-04 17:16:08,734 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Host name: xenserver, hostId: 56 is in avoid set, skipping this and trying other available hosts
2014-03-04 17:16:08,734 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) No suitable hosts found
2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) No suitable hosts found under this Cluster: 1
2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) No suitable hosts found under this Cluster: 1
2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2014-03-04 17:16:08,872 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 56
2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) Hosts's actual total CPU: 36256 and CPU after applying overprovisioning: 217536
2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) release cpu from host: 56, old used: 4500,reserved: 0, actual total: 36256, total with overprovisioning: 217536; new used: 4000,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) release mem from host: 56, old used: 3221225472,reserved: 0, total: 24473070720; new used: 2147483648,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) release mem from host: 56, old used: 3221225472,reserved: 0, total: 24473070720; new used: 2147483648,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-04 17:16:08,938 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) StorageCollector is running...
2014-03-04 17:16:08,940 WARN [cloud.consoleproxy.ConsoleProxyManagerImpl] (Job-Executor-22:job-344) Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-62160-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:734)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
at com.cloud.server.ManagementServerImpl.startConsoleProxy(ManagementServerImpl.java:1911)
at com.cloud.server.ManagementServerImpl.startSystemVM(ManagementServerImpl.java:2728)
at com.cloud.api.commands.StartSystemVMCmd.execute(StartSystemVMCmd.java:107)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
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-03-04 17:16:08,942 WARN [cloud.api.ApiDispatcher] (Job-Executor-22:job-344) class com.cloud.api.ServerApiException : Fail to start system vm
2014-03-04 17:16:08,942 WARN [cloud.api.ApiDispatcher] (Job-Executor-22:job-344) class com.cloud.api.ServerApiException : Fail to start system vm
2014-03-04 17:16:08,942 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-22:job-344) Complete async job-344, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Fail to start system vm
2014-03-04 17:16:08,944 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) There is no secondary storage VM for secondary storage host nfs://172.16.0.130/home/share/secondary
2014-03-04 17:16:08,946 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) There is no secondary storage VM for secondary storage host nfs://172.16.0.130/home/secondary
2014-03-04 17:16:08,951 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-292:null) Seq 56-1158480076: Executing request
2014-03-04 17:16:09,944 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-292:null) Seq 56-1158480076: Response Received:
2014-03-04 17:16:09,944 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 56-1158480076: Received: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2014-03-04 17:16:11,633 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-18:null) Async job-344 completed
2014-03-04 17:16:15,025 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) HostStatsCollector is running...
2014-03-04 17:16:15,035 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-283:null) Seq 55-1849426050: Executing request
2014-03-04 17:16:15,439 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-283:null) Seq 55-1849426050: Response Received:
2014-03-04 17:16:15,439 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 55-1849426050: Received: { Ans: , MgmtId: 690716573693, via: 55, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2014-03-04 17:16:15,446 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-254:null) Seq 56-1158480077: Executing request
2014-03-04 17:16:15,795 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-254:null) Seq 56-1158480077: Response Received:
2014-03-04 17:16:15,795 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 56-1158480077: Received: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2014-03-04 17:16:16,461 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) VmStatsCollector is running...
2014-03-04 17:16:16,498 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-246:null) Seq 55-1849426051: Executing request
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 0.0
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 0.02
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.19
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.25
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.029999999999999
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 6.61
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 3.16
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.84
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.390000000000001
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.57
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.93
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.63
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.590000000000001
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 1.3299999999999998
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 0.19
2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 91.79
2014-03-04 17:16:17,069 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-246:null) Seq 55-1849426051: Response Received:
2014-03-04 17:16:17,069 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 55-1849426051: Received: { Ans: , MgmtId: 690716573693, via: 55, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
2014-03-04 17:16:17,078 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-262:null) Seq 56-1158480078: Executing request
2014-03-04 17:16:17,444 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-262:null) Vm cpu utilization 4.95
^C
Re: 答复: Re: 在windows下编译cloudstack4.1.1
Posted by "linuxbqj@gmail.com" <li...@gmail.com>.
许兄，能否把你的问题新开一个话题
2014-03-04 17:18 GMT+08:00 许叁征 <xu...@chinanetcenter.com>:
> HI ALL
>
> 碰到一个问题，SSVM和CVM不能启动， 以下是日志，请教 大家这是问题出在哪，应如何解决，谢谢了。
>
>
>
>
> 014-03-04 17:16:08,012 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-22:job-344) Cleaning up resources for the vm VM[ConsoleProxy|v-62160-VM] in Starting state
> 2014-03-04 17:16:08,014 DEBUG [agent.transport.Request] (Job-Executor-22:job-344) Seq 56-1158480075: Sending { Cmd , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-62160-VM","wait":0}}] }
> 2014-03-04 17:16:08,014 DEBUG [agent.transport.Request] (Job-Executor-22:job-344) Seq 56-1158480075: Executing: { Cmd , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-62160-VM","wait":0}}] }
> 2014-03-04 17:16:08,014 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-250:null) Seq 56-1158480075: Executing request
> 2014-03-04 17:16:08,174 INFO [xen.resource.CitrixResourceBase] (DirectAgent-250:null) VM does not exist on XenServerf2f076b1-1405-451c-b37e-caf3605b6656
> 2014-03-04 17:16:08,174 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-250:null) Seq 56-1158480075: Response Received:
> 2014-03-04 17:16:08,174 DEBUG [agent.transport.Request] (DirectAgent-250:null) Seq 56-1158480075: Processing: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
> 2014-03-04 17:16:08,174 DEBUG [agent.manager.AgentAttache] (DirectAgent-250:null) Seq 56-1158480075: No more commands found
> 2014-03-04 17:16:08,174 DEBUG [agent.transport.Request] (Job-Executor-22:job-344) Seq 56-1158480075: Received: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 110, { StopAnswer } }
> 2014-03-04 17:16:08,243 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-22:job-344) Provider SecurityGroupProvider is not enabled in physical network id=200
> 2014-03-04 17:16:08,447 DEBUG [network.guru.ControlNetworkGuru] (Job-Executor-22:job-344) Released nic: NicProfile[248067-62160-null-null-null
> 2014-03-04 17:16:08,583 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] (Job-Executor-22:job-344) Releasing ip address for reservationId=3ebb6122-552e-49ef-aa7c-60e6db77163d, instance=248068
> 2014-03-04 17:16:08,647 DEBUG [network.guru.PodBasedNetworkGuru] (Job-Executor-22:job-344) Released nic: NicProfile[248068-62160-null-null-null
> 2014-03-04 17:16:08,714 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-22:job-344) Successfully released network resources for the vm VM[ConsoleProxy|v-62160-VM]
> 2014-03-04 17:16:08,714 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-22:job-344) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-62160-VM] in Starting state
> 2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) DeploymentPlanner allocation algorithm: random
> 2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
> 2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Is ROOT volume READY (pool already allocated)?: No
> 2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Searching resources only under specified Pod: 1
> 2014-03-04 17:16:08,716 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Searching resources only under specified Pod: 1
> 2014-03-04 17:16:08,718 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
> 2014-03-04 17:16:08,719 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) CPUOverprovisioningFactor considered: 6.0
> 2014-03-04 17:16:08,726 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Checking resources in Cluster: 1 under Pod: 1
> 2014-03-04 17:16:08,726 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Calling HostAllocators to find suitable hosts
> 2014-03-04 17:16:08,726 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
> 2014-03-04 17:16:08,728 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check for allocation: [Host[-55-Routing], Host[-56-Routing]]
> 2014-03-04 17:16:08,731 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Found 2 hosts for allocation after prioritization: [Host[-55-Routing], Host[-56-Routing]]
> 2014-03-04 17:16:08,731 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
> 2014-03-04 17:16:08,732 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Checking if host: 55 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 6.0
> 2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Hosts's actual total CPU: 34128 and CPU after applying overprovisioning: 204768
> 2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Free CPU: 172768 , Requested CPU: 500
> 2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Free RAM: 850673984 , Requested RAM: 1073741824
> 2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) STATS: Failed to alloc resource from host: 55 reservedCpu: 0, used cpu: 32000, requested cpu: 500, actual total cpu: 34128, total cpu with overprovisioning: 204768, reservedMem: 0, used Mem: 23622320128, requested mem: 1073741824, total Mem:24472994112 ,considerReservedCapacity?: true
> 2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) STATS: Failed to alloc resource from host: 55 reservedCpu: 0, used cpu: 32000, requested cpu: 500, actual total cpu: 34128, total cpu with overprovisioning: 204768, reservedMem: 0, used Mem: 23622320128, requested mem: 1073741824, total Mem:24472994112 ,considerReservedCapacity?: true
> 2014-03-04 17:16:08,734 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Host does not have enough RAM available, cannot allocate to this host.
> 2014-03-04 17:16:08,734 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Not using host 55; numCpusGood: true; cpuFreqGood: true, host has capacity?false
> 2014-03-04 17:16:08,734 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Host name: xenserver, hostId: 56 is in avoid set, skipping this and trying other available hosts
> 2014-03-04 17:16:08,734 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-22:job-344 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
> 2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) No suitable hosts found
> 2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) No suitable hosts found under this Cluster: 1
> 2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) No suitable hosts found under this Cluster: 1
> 2014-03-04 17:16:08,734 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-22:job-344) Could not find suitable Deployment Destination for this VM under any clusters, returning.
> 2014-03-04 17:16:08,872 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 56
> 2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) Hosts's actual total CPU: 36256 and CPU after applying overprovisioning: 217536
> 2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) release cpu from host: 56, old used: 4500,reserved: 0, actual total: 36256, total with overprovisioning: 217536; new used: 4000,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) release mem from host: 56, old used: 3221225472,reserved: 0, total: 24473070720; new used: 2147483648,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2014-03-04 17:16:08,876 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-22:job-344) release mem from host: 56, old used: 3221225472,reserved: 0, total: 24473070720; new used: 2147483648,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2014-03-04 17:16:08,938 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) StorageCollector is running...
> 2014-03-04 17:16:08,940 WARN [cloud.consoleproxy.ConsoleProxyManagerImpl] (Job-Executor-22:job-344) Exception while trying to start console proxy
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-62160-VM]Scope=interface com.cloud.dc.DataCenter; id=1
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:734)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
> at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
> at com.cloud.server.ManagementServerImpl.startConsoleProxy(ManagementServerImpl.java:1911)
> at com.cloud.server.ManagementServerImpl.startSystemVM(ManagementServerImpl.java:2728)
> at com.cloud.api.commands.StartSystemVMCmd.execute(StartSystemVMCmd.java:107)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> 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-03-04 17:16:08,942 WARN [cloud.api.ApiDispatcher] (Job-Executor-22:job-344) class com.cloud.api.ServerApiException : Fail to start system vm
> 2014-03-04 17:16:08,942 WARN [cloud.api.ApiDispatcher] (Job-Executor-22:job-344) class com.cloud.api.ServerApiException : Fail to start system vm
> 2014-03-04 17:16:08,942 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-22:job-344) Complete async job-344, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Fail to start system vm
> 2014-03-04 17:16:08,944 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) There is no secondary storage VM for secondary storage host nfs://172.16.0.130/home/share/secondary
> 2014-03-04 17:16:08,946 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) There is no secondary storage VM for secondary storage host nfs://172.16.0.130/home/secondary
> 2014-03-04 17:16:08,951 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-292:null) Seq 56-1158480076: Executing request
> 2014-03-04 17:16:09,944 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-292:null) Seq 56-1158480076: Response Received:
> 2014-03-04 17:16:09,944 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 56-1158480076: Received: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-03-04 17:16:11,633 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-18:null) Async job-344 completed
> 2014-03-04 17:16:15,025 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) HostStatsCollector is running...
> 2014-03-04 17:16:15,035 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-283:null) Seq 55-1849426050: Executing request
> 2014-03-04 17:16:15,439 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-283:null) Seq 55-1849426050: Response Received:
> 2014-03-04 17:16:15,439 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 55-1849426050: Received: { Ans: , MgmtId: 690716573693, via: 55, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-03-04 17:16:15,446 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-254:null) Seq 56-1158480077: Executing request
> 2014-03-04 17:16:15,795 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-254:null) Seq 56-1158480077: Response Received:
> 2014-03-04 17:16:15,795 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 56-1158480077: Received: { Ans: , MgmtId: 690716573693, via: 56, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-03-04 17:16:16,461 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) VmStatsCollector is running...
> 2014-03-04 17:16:16,498 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-246:null) Seq 55-1849426051: Executing request
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 0.0
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 0.02
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.19
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.25
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.029999999999999
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 6.61
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 3.16
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.84
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.390000000000001
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.57
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 5.93
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.63
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 4.590000000000001
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 1.3299999999999998
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 0.19
> 2014-03-04 17:16:17,069 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-246:null) Vm cpu utilization 91.79
> 2014-03-04 17:16:17,069 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-246:null) Seq 55-1849426051: Response Received:
> 2014-03-04 17:16:17,069 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 55-1849426051: Received: { Ans: , MgmtId: 690716573693, via: 55, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
> 2014-03-04 17:16:17,078 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-262:null) Seq 56-1158480078: Executing request
> 2014-03-04 17:16:17,444 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-262:null) Vm cpu utilization 4.95
> ^C
>
>
--
白清杰 (Born Bai)
北京开源愿景信息技术有限公司
Mail: linuxbqj@gmail.com