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 淡看浮华 <36...@qq.com> on 2014/03/10 04:32:43 UTC
通过ISO添加虚拟机实例失败
我是在一台机器上安装ubuntu12.0.4系统，然后部署cloudstack4.0.2，既做管理节点，又做计算节点。主存储和二级存储都是通过NFS方式提供。
通过上次ISO制作了模板，然后通过这个ISO模板创建虚拟机实例，我第一次创建的时候是成功了，可销毁实例之后，再创建，就弹出下面的错误提示：
Unable to create a deployment for VM[User|vm1]
虚拟机状态也显示error.
最近刚接触cloudstack，好多东西不懂，还望各位大牛前辈多多指点啊，谢谢。
日志如下（报找不到合适的部署位置）：
2014-03-10 11:09:24,075 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:25,560 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:25,560 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:25,561 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:26,995 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===START=== 192.168.0.50 -- GET command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
2014-03-10 11:09:27,029 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2014-03-10 11:09:27,029 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2014-03-10 11:09:27,085 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:27,201 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-8:null) Allocating in the DB for vm
2014-03-10 11:09:27,202 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocating entries for VM: VM[User|vm1]
2014-03-10 11:09:27,209 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocating nics for VM[User|vm1]
2014-03-10 11:09:27,209 DEBUG [cloud.network.NetworkManagerImpl] (catalina-exec-8:null) Allocating nic for vm VM[User|vm1] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2014-03-10 11:09:27,221 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocaing disks for VM[User|vm1]
2014-03-10 11:09:27,230 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocation completed for VM: VM[User|vm1]
2014-03-10 11:09:27,231 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-8:null) Successfully allocated DB entry for VM[User|vm1]
2014-03-10 11:09:27,658 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-8:null) submit async job-104, details: AsyncJobVO {id:104, userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 22, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"uazZwh3tFJL7FmrJVclZug8CMPo\u003d","ctxUserId":"2","serviceOfferingId":"25c6d5d2-1feb-49c7-930e-69f51c1ea527","zoneId":"c27c3b63-6136-45bd-a779-95aafd3c91b4","response":"json","templateId":"5d6b7d6a-48fe-4009-8b11-cbea7242f971","id":"22","hypervisor":"KVM,KVM","name":"vm1","diskOfferingId":"1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835","_":"1394420930591","ctxAccountId":"2","ctxStartEventId":"392","displayname":"vm1"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 279278805450863, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-03-10 11:09:27,660 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-104) Executing com.cloud.api.commands.DeployVMCmd for job-104
2014-03-10 11:09:27,665 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END=== 192.168.0.50 -- GET command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
2014-03-10 11:09:27,832 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) 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-03-10 11:09:27,832 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Successfully transitioned to start state for VM[User|vm1] reservation id = 26596ed8-6c57-451b-886a-63c31c9d3070
2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Trying to deploy VM, vm has dcId: 1 and podId: null
2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-10 11:09:27,920 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) DeploymentPlanner allocation algorithm: random
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Is ROOT volume READY (pool already allocated)?: No
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Searching all possible resources under this Zone: 1
2014-03-10 11:09:27,924 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-03-10 11:09:27,926 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) CPUOverprovisioningFactor considered: 2.0
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Cluster: 1 has HyperVisorType that does not match the VM, skipping this cluster
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2014-03-10 11:09:28,075 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: null
2014-03-10 11:09:28,081 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-39:job-104) Destroying vm VM[User|vm1] as it failed to create
2014-03-10 11:09:28,228 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original host id: null new host id: null host id before state transition: null
2014-03-10 11:09:28,580 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:28,788 INFO [api.commands.DeployVMCmd] (Job-Executor-39:job-104) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|vm1]Scope=interface com.cloud.dc.DataCenter; id=1
2014-03-10 11:09:28,788 WARN [cloud.api.ApiDispatcher] (Job-Executor-39:job-104) class com.cloud.api.ServerApiException : Unable to create a deployment for VM[User|vm1]
2014-03-10 11:09:28,788 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-104) Complete async job-104, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|vm1]
2014-03-10 11:09:30,057 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:31,582 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:32,779 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===START=== 192.168.0.50 -- GET command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
2014-03-10 11:09:32,795 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-9:null) Async job-104 completed
2014-03-10 11:09:32,806 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===END=== 192.168.0.50 -- GET command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
2014-03-10 11:09:32,819 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START=== 192.168.0.50 -- GET command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
2014-03-10 11:09:32,827 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-2:null) THE WHERE CLAUSE IS:user_vm.id = ?
2014-03-10 11:09:32,866 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END=== 192.168.0.50 -- GET command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
2014-03-10 11:09:33,083 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:34,567 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:34,768 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
2014-03-10 11:09:36,059 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:36,969 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-03-10 11:09:37,126 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
回复：通过ISO添加虚拟机实例失败
Posted by 淡看浮华 <36...@qq.com>.
我在全局设置里，配置了cpu和内存都是2分钟就回收，虚拟机实例销毁之后资源就回收了吧，这样还会导致资源不足吗？
而且在主页上显示的资源还是很多的
------------------ 原始邮件 ------------------
发件人: "Mr.博";<28...@qq.com>;
发送时间: 2014年3月10日(星期一) 中午11:36
收件人: "users-cn"<us...@cloudstack.apache.org>;
主题: 回复：通过ISO添加虚拟机实例失败
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|vm1]Scope=interface com.cloud.dc.DataCenter; id=1
这里是说资源不足了
------------------ 原始邮件 ------------------
发件人: "淡看浮华";<36...@qq.com>;
发送时间: 2014年3月10日(星期一) 中午11:32
收件人: "users-cn"<us...@cloudstack.apache.org>;
主题: 通过ISO添加虚拟机实例失败
我是在一台机器上安装ubuntu12.0.4系统，然后部署cloudstack4.0.2，既做管理节点，又做计算节点。主存储和二级存储都是通过NFS方式提供。
通过上次ISO制作了模板，然后通过这个ISO模板创建虚拟机实例，我第一次创建的时候是成功了，可销毁实例之后，再创建，就弹出下面的错误提示：
Unable to create a deployment for VM[User|vm1]
虚拟机状态也显示error.
最近刚接触cloudstack，好多东西不懂，还望各位大牛前辈多多指点啊，谢谢。
日志如下（报找不到合适的部署位置）：
2014-03-10 11:09:24,075 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:25,560 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:25,560 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:25,561 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:26,995 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===START=== 192.168.0.50 -- GET command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
2014-03-10 11:09:27,029 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2014-03-10 11:09:27,029 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2014-03-10 11:09:27,085 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:27,201 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-8:null) Allocating in the DB for vm
2014-03-10 11:09:27,202 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocating entries for VM: VM[User|vm1]
2014-03-10 11:09:27,209 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocating nics for VM[User|vm1]
2014-03-10 11:09:27,209 DEBUG [cloud.network.NetworkManagerImpl] (catalina-exec-8:null) Allocating nic for vm VM[User|vm1] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2014-03-10 11:09:27,221 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocaing disks for VM[User|vm1]
2014-03-10 11:09:27,230 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocation completed for VM: VM[User|vm1]
2014-03-10 11:09:27,231 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-8:null) Successfully allocated DB entry for VM[User|vm1]
2014-03-10 11:09:27,658 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-8:null) submit async job-104, details: AsyncJobVO {id:104, userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 22, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"uazZwh3tFJL7FmrJVclZug8CMPo\u003d","ctxUserId":"2","serviceOfferingId":"25c6d5d2-1feb-49c7-930e-69f51c1ea527","zoneId":"c27c3b63-6136-45bd-a779-95aafd3c91b4","response":"json","templateId":"5d6b7d6a-48fe-4009-8b11-cbea7242f971","id":"22","hypervisor":"KVM,KVM","name":"vm1","diskOfferingId":"1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835","_":"1394420930591","ctxAccountId":"2","ctxStartEventId":"392","displayname":"vm1"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 279278805450863, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-03-10 11:09:27,660 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-104) Executing com.cloud.api.commands.DeployVMCmd for job-104
2014-03-10 11:09:27,665 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END=== 192.168.0.50 -- GET command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
2014-03-10 11:09:27,832 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) 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-03-10 11:09:27,832 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Successfully transitioned to start state for VM[User|vm1] reservation id = 26596ed8-6c57-451b-886a-63c31c9d3070
2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Trying to deploy VM, vm has dcId: 1 and podId: null
2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-10 11:09:27,920 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) DeploymentPlanner allocation algorithm: random
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Is ROOT volume READY (pool already allocated)?: No
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Searching all possible resources under this Zone: 1
2014-03-10 11:09:27,924 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-03-10 11:09:27,926 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) CPUOverprovisioningFactor considered: 2.0
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Cluster: 1 has HyperVisorType that does not match the VM, skipping this cluster
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2014-03-10 11:09:28,075 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: null
2014-03-10 11:09:28,081 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-39:job-104) Destroying vm VM[User|vm1] as it failed to create
2014-03-10 11:09:28,228 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original host id: null new host id: null host id before state transition: null
2014-03-10 11:09:28,580 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:28,788 INFO [api.commands.DeployVMCmd] (Job-Executor-39:job-104) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|vm1]Scope=interface com.cloud.dc.DataCenter; id=1
2014-03-10 11:09:28,788 WARN [cloud.api.ApiDispatcher] (Job-Executor-39:job-104) class com.cloud.api.ServerApiException : Unable to create a deployment for VM[User|vm1]
2014-03-10 11:09:28,788 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-104) Complete async job-104, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|vm1]
2014-03-10 11:09:30,057 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:31,582 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:32,779 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===START=== 192.168.0.50 -- GET command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
2014-03-10 11:09:32,795 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-9:null) Async job-104 completed
2014-03-10 11:09:32,806 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===END=== 192.168.0.50 -- GET command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
2014-03-10 11:09:32,819 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START=== 192.168.0.50 -- GET command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
2014-03-10 11:09:32,827 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-2:null) THE WHERE CLAUSE IS:user_vm.id = ?
2014-03-10 11:09:32,866 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END=== 192.168.0.50 -- GET command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
2014-03-10 11:09:33,083 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:34,567 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:34,768 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
2014-03-10 11:09:36,059 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:36,969 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-03-10 11:09:37,126 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
回复：通过ISO添加虚拟机实例失败
Posted by "Mr.博" <28...@qq.com>.
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|vm1]Scope=interface com.cloud.dc.DataCenter; id=1
这里是说资源不足了
------------------ 原始邮件 ------------------
发件人: "淡看浮华";<36...@qq.com>;
发送时间: 2014年3月10日(星期一) 中午11:32
收件人: "users-cn"<us...@cloudstack.apache.org>;
主题: 通过ISO添加虚拟机实例失败
我是在一台机器上安装ubuntu12.0.4系统，然后部署cloudstack4.0.2，既做管理节点，又做计算节点。主存储和二级存储都是通过NFS方式提供。
通过上次ISO制作了模板，然后通过这个ISO模板创建虚拟机实例，我第一次创建的时候是成功了，可销毁实例之后，再创建，就弹出下面的错误提示：
Unable to create a deployment for VM[User|vm1]
虚拟机状态也显示error.
最近刚接触cloudstack，好多东西不懂，还望各位大牛前辈多多指点啊，谢谢。
日志如下（报找不到合适的部署位置）：
2014-03-10 11:09:24,075 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:25,560 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:25,560 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:25,561 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:26,995 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===START=== 192.168.0.50 -- GET command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
2014-03-10 11:09:27,029 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2014-03-10 11:09:27,029 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2014-03-10 11:09:27,085 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:27,201 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-8:null) Allocating in the DB for vm
2014-03-10 11:09:27,202 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocating entries for VM: VM[User|vm1]
2014-03-10 11:09:27,209 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocating nics for VM[User|vm1]
2014-03-10 11:09:27,209 DEBUG [cloud.network.NetworkManagerImpl] (catalina-exec-8:null) Allocating nic for vm VM[User|vm1] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2014-03-10 11:09:27,221 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocaing disks for VM[User|vm1]
2014-03-10 11:09:27,230 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-8:null) Allocation completed for VM: VM[User|vm1]
2014-03-10 11:09:27,231 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-8:null) Successfully allocated DB entry for VM[User|vm1]
2014-03-10 11:09:27,658 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-8:null) submit async job-104, details: AsyncJobVO {id:104, userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 22, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"uazZwh3tFJL7FmrJVclZug8CMPo\u003d","ctxUserId":"2","serviceOfferingId":"25c6d5d2-1feb-49c7-930e-69f51c1ea527","zoneId":"c27c3b63-6136-45bd-a779-95aafd3c91b4","response":"json","templateId":"5d6b7d6a-48fe-4009-8b11-cbea7242f971","id":"22","hypervisor":"KVM,KVM","name":"vm1","diskOfferingId":"1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835","_":"1394420930591","ctxAccountId":"2","ctxStartEventId":"392","displayname":"vm1"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 279278805450863, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-03-10 11:09:27,660 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-104) Executing com.cloud.api.commands.DeployVMCmd for job-104
2014-03-10 11:09:27,665 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END=== 192.168.0.50 -- GET command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
2014-03-10 11:09:27,832 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) 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-03-10 11:09:27,832 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Successfully transitioned to start state for VM[User|vm1] reservation id = 26596ed8-6c57-451b-886a-63c31c9d3070
2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Trying to deploy VM, vm has dcId: 1 and podId: null
2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-39:job-104) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-10 11:09:27,920 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) DeploymentPlanner allocation algorithm: random
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Is ROOT volume READY (pool already allocated)?: No
2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Searching all possible resources under this Zone: 1
2014-03-10 11:09:27,924 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-03-10 11:09:27,926 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) CPUOverprovisioningFactor considered: 2.0
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Cluster: 1 has HyperVisorType that does not match the VM, skipping this cluster
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-39:job-104) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2014-03-10 11:09:28,075 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: null
2014-03-10 11:09:28,081 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-39:job-104) Destroying vm VM[User|vm1] as it failed to create
2014-03-10 11:09:28,228 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-39:job-104) VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original host id: null new host id: null host id before state transition: null
2014-03-10 11:09:28,580 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:28,788 INFO [api.commands.DeployVMCmd] (Job-Executor-39:job-104) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|vm1]Scope=interface com.cloud.dc.DataCenter; id=1
2014-03-10 11:09:28,788 WARN [cloud.api.ApiDispatcher] (Job-Executor-39:job-104) class com.cloud.api.ServerApiException : Unable to create a deployment for VM[User|vm1]
2014-03-10 11:09:28,788 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-104) Complete async job-104, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|vm1]
2014-03-10 11:09:30,057 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:31,582 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:32,779 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===START=== 192.168.0.50 -- GET command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
2014-03-10 11:09:32,795 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-9:null) Async job-104 completed
2014-03-10 11:09:32,806 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===END=== 192.168.0.50 -- GET command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
2014-03-10 11:09:32,819 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START=== 192.168.0.50 -- GET command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
2014-03-10 11:09:32,827 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-2:null) THE WHERE CLAUSE IS:user_vm.id = ?
2014-03-10 11:09:32,866 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END=== 192.168.0.50 -- GET command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
2014-03-10 11:09:33,083 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:34,567 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:34,768 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
2014-03-10 11:09:36,059 DEBUG [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Detected management node left, id:4, nodeIP:169.254.0.1
2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl] (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by timestamp but is pingable
2014-03-10 11:09:36,969 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-03-10 11:09:37,126 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
回复： 通过ISO添加虚拟机实例失败
Posted by 淡看浮华 <36...@qq.com>.
是的，只有一个kvm主机。
不过这种类型不匹配的问题会概率性出现吗？
用同一个ISO模板，分配的资源也都一样，偶尔能创建成功，大部分时间都不成功
------------------ 原始邮件 ------------------
发件人: "曾冠华";<ah...@gmail.com>;
发送时间: 2014年3月10日(星期一) 中午11:49
收件人: "users-cn"<us...@cloudstack.apache.org>;
主题: Re: 通过ISO添加虚拟机实例失败
2014-03-10 11:09:27,924 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) Listing clusters in order of aggregate capacity,
that have (atleast one host with) enough CPU and RAM capacity under this
Zone: 1
2014-03-10 11:09:27,926 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) CPUOverprovisioningFactor considered: 2.0
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) Cluster: 1 has HyperVisorType that does not match
the VM, skipping this cluster
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) Could not find suitable Deployment Destination
for this VM under any clusters, returning.
你应该只有一个hypervisor，你的hypervisor类型和vm的类型对不上，没有合适的hypervisor，跳过去了， 自然会报资源不足
2014-03-10 11:32 GMT+08:00 淡看浮华 <36...@qq.com>:
>
> 我是在一台机器上安装ubuntu12.0.4系统，然后部署cloudstack4.0.2，既做管理节点，又做计算节点。主存储和二级存储都是通过NFS方式提供。
> 通过上次ISO制作了模板，然后通过这个ISO模板创建虚拟机实例，我第一次创建的时候是成功了，可销毁实例之后，再创建，就弹出下面的错误提示：
> Unable to create a deployment for VM[User|vm1]
> 虚拟机状态也显示error.
>
> 最近刚接触cloudstack，好多东西不懂，还望各位大牛前辈多多指点啊，谢谢。
>
> 日志如下（报找不到合适的部署位置）：
> 2014-03-10 11:09:24,075 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:25,560 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:25,560 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:25,561 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:26,995 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-8:null) ===START=== 192.168.0.50 -- GET
> command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
> 2014-03-10 11:09:27,029 DEBUG
> [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null)
> Access granted to Acct[2-admin] to zone:1 by DomainChecker
> 2014-03-10 11:09:27,029 DEBUG
> [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null)
> Access granted to Acct[2-admin] to zone:1 by DomainChecker
> 2014-03-10 11:09:27,085 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:27,201 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-8:null) Allocating in the DB for vm
> 2014-03-10 11:09:27,202 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocating entries for VM: VM[User|vm1]
> 2014-03-10 11:09:27,209 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocating nics for VM[User|vm1]
> 2014-03-10 11:09:27,209 DEBUG [cloud.network.NetworkManagerImpl]
> (catalina-exec-8:null) Allocating nic for vm VM[User|vm1] in network
> Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
> 2014-03-10 11:09:27,221 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocaing disks for VM[User|vm1]
> 2014-03-10 11:09:27,230 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocation completed for VM: VM[User|vm1]
> 2014-03-10 11:09:27,231 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-8:null) Successfully allocated DB entry for VM[User|vm1]
> 2014-03-10 11:09:27,658 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-8:null) submit async job-104, details: AsyncJobVO {id:104,
> userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine,
> instanceId: 22, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator:
> null, cmdInfo:
> {"sessionkey":"uazZwh3tFJL7FmrJVclZug8CMPo\u003d","ctxUserId":"2","serviceOfferingId":"25c6d5d2-1feb-49c7-930e-69f51c1ea527","zoneId":"c27c3b63-6136-45bd-a779-95aafd3c91b4","response":"json","templateId":"5d6b7d6a-48fe-4009-8b11-cbea7242f971","id":"22","hypervisor":"KVM,KVM","name":"vm1","diskOfferingId":"1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835","_":"1394420930591","ctxAccountId":"2","ctxStartEventId":"392","displayname":"vm1"},
> cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
> processStatus: 0, resultCode: 0, result: null, initMsid: 279278805450863,
> completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-03-10 11:09:27,660 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-39:job-104) Executing com.cloud.api.commands.DeployVMCmd for
> job-104
> 2014-03-10 11:09:27,665 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-8:null) ===END=== 192.168.0.50 -- GET
> command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
> 2014-03-10 11:09:27,832 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-39:job-104) 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-03-10 11:09:27,832 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-39:job-104) Successfully transitioned to start state for
> VM[User|vm1] reservation id = 26596ed8-6c57-451b-886a-63c31c9d3070
> 2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-39:job-104) Trying to deploy VM, vm has dcId: 1 and podId:
> null
> 2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-39:job-104) Deploy avoids pods: null, clusters: null, hosts:
> null
> 2014-03-10 11:09:27,920 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) DeploymentPlanner allocation algorithm: random
> 2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Trying to allocate a host and storage pools from
> dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
> 2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Is ROOT volume READY (pool already allocated)?: No
> 2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Searching all possible resources under this Zone:
> 1
> 2014-03-10 11:09:27,924 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Listing clusters in order of aggregate capacity,
> that have (atleast one host with) enough CPU and RAM capacity under this
> Zone: 1
> 2014-03-10 11:09:27,926 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) CPUOverprovisioningFactor considered: 2.0
> 2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Cluster: 1 has HyperVisorType that does not match
> the VM, skipping this cluster
> 2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Could not find suitable Deployment Destination
> for this VM under any clusters, returning.
> 2014-03-10 11:09:28,075 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-39:job-104) VM state transitted from :Starting to Stopped
> with event: OperationFailedvm's original host id: null new host id: null
> host id before state transition: null
> 2014-03-10 11:09:28,081 DEBUG [cloud.vm.UserVmManagerImpl]
> (Job-Executor-39:job-104) Destroying vm VM[User|vm1] as it failed to create
> 2014-03-10 11:09:28,228 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-39:job-104) VM state transitted from :Stopped to Error with
> event: OperationFailedToErrorvm's original host id: null new host id: null
> host id before state transition: null
> 2014-03-10 11:09:28,580 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:28,788 INFO [api.commands.DeployVMCmd]
> (Job-Executor-39:job-104)
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|vm1]Scope=interface com.cloud.dc.DataCenter; id=1
> 2014-03-10 11:09:28,788 WARN [cloud.api.ApiDispatcher]
> (Job-Executor-39:job-104) class com.cloud.api.ServerApiException : Unable
> to create a deployment for VM[User|vm1]
> 2014-03-10 11:09:28,788 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-39:job-104) Complete async job-104, jobStatus: 2, resultCode:
> 530, result: Error Code: 533 Error text: Unable to create a deployment for
> VM[User|vm1]
> 2014-03-10 11:09:30,057 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:31,582 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:32,779 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-9:null) ===START=== 192.168.0.50 -- GET
> command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
> 2014-03-10 11:09:32,795 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-9:null) Async job-104 completed
> 2014-03-10 11:09:32,806 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-9:null) ===END=== 192.168.0.50 -- GET
> command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
> 2014-03-10 11:09:32,819 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-2:null) ===START=== 192.168.0.50 -- GET
> command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
> 2014-03-10 11:09:32,827 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-2:null) THE WHERE CLAUSE IS:user_vm.id = ?
> 2014-03-10 11:09:32,866 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-2:null) ===END=== 192.168.0.50 -- GET
> command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
> 2014-03-10 11:09:33,083 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:34,567 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:34,768 DEBUG [cloud.server.StatsCollector]
> (StatsCollector-3:null) VmStatsCollector is running...
> 2014-03-10 11:09:36,059 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:36,969 DEBUG
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
> is ready to launch secondary storage VM
> 2014-03-10 11:09:37,126 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Zone 1 is ready to launch console proxy
Re: 通过ISO添加虚拟机实例失败
Posted by 曾冠华 <ah...@gmail.com>.
2014-03-10 11:09:27,924 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) Listing clusters in order of aggregate capacity,
that have (atleast one host with) enough CPU and RAM capacity under this
Zone: 1
2014-03-10 11:09:27,926 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) CPUOverprovisioningFactor considered: 2.0
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) Cluster: 1 has HyperVisorType that does not match
the VM, skipping this cluster
2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-39:job-104) Could not find suitable Deployment Destination
for this VM under any clusters, returning.
你应该只有一个hypervisor，你的hypervisor类型和vm的类型对不上，没有合适的hypervisor，跳过去了， 自然会报资源不足
2014-03-10 11:32 GMT+08:00 淡看浮华 <36...@qq.com>:
>
> 我是在一台机器上安装ubuntu12.0.4系统，然后部署cloudstack4.0.2，既做管理节点，又做计算节点。主存储和二级存储都是通过NFS方式提供。
> 通过上次ISO制作了模板，然后通过这个ISO模板创建虚拟机实例，我第一次创建的时候是成功了，可销毁实例之后，再创建，就弹出下面的错误提示：
> Unable to create a deployment for VM[User|vm1]
> 虚拟机状态也显示error.
>
> 最近刚接触cloudstack，好多东西不懂，还望各位大牛前辈多多指点啊，谢谢。
>
> 日志如下（报找不到合适的部署位置）：
> 2014-03-10 11:09:24,075 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:24,076 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:25,560 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:25,560 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:25,561 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:26,995 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-8:null) ===START=== 192.168.0.50 -- GET
> command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
> 2014-03-10 11:09:27,029 DEBUG
> [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null)
> Access granted to Acct[2-admin] to zone:1 by DomainChecker
> 2014-03-10 11:09:27,029 DEBUG
> [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-8:null)
> Access granted to Acct[2-admin] to zone:1 by DomainChecker
> 2014-03-10 11:09:27,085 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:27,085 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:27,201 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-8:null) Allocating in the DB for vm
> 2014-03-10 11:09:27,202 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocating entries for VM: VM[User|vm1]
> 2014-03-10 11:09:27,209 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocating nics for VM[User|vm1]
> 2014-03-10 11:09:27,209 DEBUG [cloud.network.NetworkManagerImpl]
> (catalina-exec-8:null) Allocating nic for vm VM[User|vm1] in network
> Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
> 2014-03-10 11:09:27,221 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocaing disks for VM[User|vm1]
> 2014-03-10 11:09:27,230 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-8:null) Allocation completed for VM: VM[User|vm1]
> 2014-03-10 11:09:27,231 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-8:null) Successfully allocated DB entry for VM[User|vm1]
> 2014-03-10 11:09:27,658 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-8:null) submit async job-104, details: AsyncJobVO {id:104,
> userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine,
> instanceId: 22, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator:
> null, cmdInfo:
> {"sessionkey":"uazZwh3tFJL7FmrJVclZug8CMPo\u003d","ctxUserId":"2","serviceOfferingId":"25c6d5d2-1feb-49c7-930e-69f51c1ea527","zoneId":"c27c3b63-6136-45bd-a779-95aafd3c91b4","response":"json","templateId":"5d6b7d6a-48fe-4009-8b11-cbea7242f971","id":"22","hypervisor":"KVM,KVM","name":"vm1","diskOfferingId":"1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835","_":"1394420930591","ctxAccountId":"2","ctxStartEventId":"392","displayname":"vm1"},
> cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
> processStatus: 0, resultCode: 0, result: null, initMsid: 279278805450863,
> completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-03-10 11:09:27,660 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-39:job-104) Executing com.cloud.api.commands.DeployVMCmd for
> job-104
> 2014-03-10 11:09:27,665 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-8:null) ===END=== 192.168.0.50 -- GET
> command=deployVirtualMachine&zoneId=c27c3b63-6136-45bd-a779-95aafd3c91b4&templateId=5d6b7d6a-48fe-4009-8b11-cbea7242f971&hypervisor=KVM,KVM&serviceOfferingId=25c6d5d2-1feb-49c7-930e-69f51c1ea527&diskOfferingId=1f32d1e8-abe0-4d8c-8601-8fe2cf6c3835&displayname=vm1&name=vm1&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420930591
> 2014-03-10 11:09:27,832 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-39:job-104) 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-03-10 11:09:27,832 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-39:job-104) Successfully transitioned to start state for
> VM[User|vm1] reservation id = 26596ed8-6c57-451b-886a-63c31c9d3070
> 2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-39:job-104) Trying to deploy VM, vm has dcId: 1 and podId:
> null
> 2014-03-10 11:09:27,917 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-39:job-104) Deploy avoids pods: null, clusters: null, hosts:
> null
> 2014-03-10 11:09:27,920 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) DeploymentPlanner allocation algorithm: random
> 2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Trying to allocate a host and storage pools from
> dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
> 2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Is ROOT volume READY (pool already allocated)?: No
> 2014-03-10 11:09:27,921 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Searching all possible resources under this Zone:
> 1
> 2014-03-10 11:09:27,924 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Listing clusters in order of aggregate capacity,
> that have (atleast one host with) enough CPU and RAM capacity under this
> Zone: 1
> 2014-03-10 11:09:27,926 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) CPUOverprovisioningFactor considered: 2.0
> 2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Cluster: 1 has HyperVisorType that does not match
> the VM, skipping this cluster
> 2014-03-10 11:09:27,939 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-39:job-104) Could not find suitable Deployment Destination
> for this VM under any clusters, returning.
> 2014-03-10 11:09:28,075 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-39:job-104) VM state transitted from :Starting to Stopped
> with event: OperationFailedvm's original host id: null new host id: null
> host id before state transition: null
> 2014-03-10 11:09:28,081 DEBUG [cloud.vm.UserVmManagerImpl]
> (Job-Executor-39:job-104) Destroying vm VM[User|vm1] as it failed to create
> 2014-03-10 11:09:28,228 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-39:job-104) VM state transitted from :Stopped to Error with
> event: OperationFailedToErrorvm's original host id: null new host id: null
> host id before state transition: null
> 2014-03-10 11:09:28,580 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:28,580 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:28,788 INFO [api.commands.DeployVMCmd]
> (Job-Executor-39:job-104)
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|vm1]Scope=interface com.cloud.dc.DataCenter; id=1
> 2014-03-10 11:09:28,788 WARN [cloud.api.ApiDispatcher]
> (Job-Executor-39:job-104) class com.cloud.api.ServerApiException : Unable
> to create a deployment for VM[User|vm1]
> 2014-03-10 11:09:28,788 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-39:job-104) Complete async job-104, jobStatus: 2, resultCode:
> 530, result: Error Code: 533 Error text: Unable to create a deployment for
> VM[User|vm1]
> 2014-03-10 11:09:30,057 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:30,057 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:31,582 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:31,583 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:32,779 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-9:null) ===START=== 192.168.0.50 -- GET
> command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
> 2014-03-10 11:09:32,795 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-9:null) Async job-104 completed
> 2014-03-10 11:09:32,806 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-9:null) ===END=== 192.168.0.50 -- GET
> command=queryAsyncJobResult&jobId=fa74b389-fd45-4eae-8027-019cea2abcb7&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936375
> 2014-03-10 11:09:32,819 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-2:null) ===START=== 192.168.0.50 -- GET
> command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
> 2014-03-10 11:09:32,827 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-2:null) THE WHERE CLAUSE IS:user_vm.id = ?
> 2014-03-10 11:09:32,866 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-2:null) ===END=== 192.168.0.50 -- GET
> command=listVirtualMachines&id=29273813-ed66-4106-97fb-4b80356fd243&response=json&sessionkey=uazZwh3tFJL7FmrJVclZug8CMPo%3D&_=1394420936410
> 2014-03-10 11:09:33,083 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:33,083 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:34,567 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:34,567 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:34,768 DEBUG [cloud.server.StatsCollector]
> (StatsCollector-3:null) VmStatsCollector is running...
> 2014-03-10 11:09:36,059 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:4,
> nodeIP:169.254.0.1
> 2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 169.254.0.1
> 2014-03-10 11:09:36,060 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 4 is detected inactive by
> timestamp but is pingable
> 2014-03-10 11:09:36,969 DEBUG
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
> is ready to launch secondary storage VM
> 2014-03-10 11:09:37,126 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Zone 1 is ready to launch console proxy