你的系统VM的状态正常吗？另外计算节点的状态是up吗？
2014-04-03 19:25 GMT+08:00 cui6522123 <cui6522...@gmail.com>:
>
>
>
>
>
>
> 新创建虚拟机报错，生产环境，求大神协助解决，报错如下：
>
>
>
> -------------------------------------------------------------------------------------------------------
>
> 2014-04-03 19:22:09,696 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-19:job-452
> = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Lock is acquired for network id
> 204 as a part of router startup in
> Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
> : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(151|ROOT-->Pool(1))]
>
> 2014-04-03 19:22:09,701 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-19:job-452
> = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Lock is released for network id
> 204 as a part of router startup in
> Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
> : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(151|ROOT-->Pool(1))]
>
> 2014-04-03 19:22:09,713 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Service
> SecurityGroup is not supported in the network id=204
>
> 2014-04-03 19:22:09,732 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Service
> SecurityGroup is not supported in the network id=204
>
> 2014-04-03 19:22:09,737 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-19:job-452
> = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Applying dhcp entry in network
> Ntwk[204|Guest|15]
>
> 2014-04-03 19:22:09,769 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650693: Sending { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1, Flags:
> 100111,
> [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:5d:f6:00:59","vmIpAddress":"10.10.30.168","vmName":"jcui02","defaultRouter":"10.10.30.1","defaultDns":"10.10.30.1","duid":"00:03:00:01:02:00:5d:f6:00:59","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","router.name":"r-4-VM","router.ip":"169.254.1.159"},"wait":0}}]
> }
>
> 2014-04-03 19:22:09,769 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650693: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 100111,
> [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:5d:f6:00:59","vmIpAddress":"10.10.30.168","vmName":"jcui02","defaultRouter":"10.10.30.1","defaultDns":"10.10.30.1","duid":"00:03:00:01:02:00:5d:f6:00:59","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","router.name":"r-4-VM","router.ip":"169.254.1.159"},"wait":0}}]
> }
>
> 2014-04-03 19:22:09,770 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-26:null) Seq 1-947650693: Executing request
>
> 2014-04-03 19:22:10,715 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-26:null) Seq 1-947650693: Response Received:
>
> 2014-04-03 19:22:10,715 DEBUG [agent.transport.Request] (DirectAgent-26:null)
> Seq 1-947650693: Processing: { Ans: , MgmtId: 264018885718825, via: 1, Ver:
> v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
>
> 2014-04-03 19:22:10,715 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-26:null) Seq 1-947650693: No more commands found
>
> 2014-04-03 19:22:10,715 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650693: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 110, { Answer } }
>
> 2014-04-03 19:22:10,729 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Service
> SecurityGroup is not supported in the network id=204
>
> 2014-04-03 19:22:10,734 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-19:job-452
> = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Applying userdata and password
> entry in network Ntwk[204|Guest|15]
>
> 2014-04-03 19:22:10,763 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650694: Sending { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1, Flags:
> 100111,
> [{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.10.30.168","vmName":"jcui02","executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","router.ip":"169.254.1.159","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"10.10.30.168","vmName":"jcui02","executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","router.ip":"169.254.1.159","router.name":"r-4-VM"},"wait":0}}]
> }
>
> 2014-04-03 19:22:10,764 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650694: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 100111,
> [{"com.cloud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.10.30.168","vmName":"jcui02","executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","router.ip":"169.254.1.159","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"10.10.30.168","vmName":"jcui02","executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","router.ip":"169.254.1.159","router.name":"r-4-VM"},"wait":0}}]
> }
>
> 2014-04-03 19:22:10,765 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-201:null) Seq 1-947650694: Executing request
>
> 2014-04-03 19:22:11,518 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-9:null) SeqA 2-1090373: Processing Seq 2-1090373: { Cmd
> , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
>
> 2014-04-03 19:22:11,522 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-9:null) SeqA 2-1090373: Sending Seq 2-1090373: { Ans: ,
> MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>
> 2014-04-03 19:22:12,222 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-272:null) Seq 1-947650564: Executing request
>
> 2014-04-03 19:22:12,262 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-201:null) Seq 1-947650694: Response Received:
>
> 2014-04-03 19:22:12,263 DEBUG [agent.transport.Request]
> (DirectAgent-201:null) Seq 1-947650694: Processing: { Ans: , MgmtId:
> 264018885718825, via: 1, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}},{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}]
> }
>
> 2014-04-03 19:22:12,263 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-201:null) Seq 1-947650694: No more commands found
>
> 2014-04-03 19:22:12,263 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650694: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 110, { Answer, Answer } }
>
> 2014-04-03 19:22:12,265 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Service
> SecurityGroup is not supported in the network id=204
>
> 2014-04-03 19:22:12,268 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Checking
> if we need to prepare 1 volumes for VM[User|jcui02]
>
> 2014-04-03 19:22:12,280 DEBUG [storage.image.TemplateDataFactoryImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) template
> 216 is already in store:1, type:Image
>
> 2014-04-03 19:22:12,286 DEBUG [storage.datastore.PrimaryDataStoreImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Not
> found (templateId:216poolId:1) in template_spool_ref, persisting it
>
> 2014-04-03 19:22:12,292 DEBUG [storage.image.TemplateDataFactoryImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) template
> 216 is already in store:1, type:Primary
>
> 2014-04-03 19:22:12,294 DEBUG [storage.volume.VolumeServiceImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Found
> template 7b384b36-137d-4b87-9df9-9e597d7c07eb in storage pool 1 with
> VMTemplateStoragePool id: 27
>
> 2014-04-03 19:22:12,305 DEBUG [storage.volume.VolumeServiceImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Acquire
> lock on VMTemplateStoragePool 27 with timeout 3600 seconds
>
> 2014-04-03 19:22:12,307 INFO [storage.volume.VolumeServiceImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) lock is
> acquired for VMTemplateStoragePool 27
>
> 2014-04-03 19:22:12,313 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE
>
> 2014-04-03 19:22:12,332 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650695: Sending { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1, Flags:
> 100111,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/216/7b384b36-137d-4b87-9df9-9e597d7c07eb.vhd","uuid":"696c4228-11ac-4613-bbda-42eb88f6ba37","id":216,"format":"VHD","accountId":2,"hvm":true,"displayText":"Centos
>
> 6.3_64_pip_2014.04","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://121.121.121.121/export/secondary","_role":"Image"}},"name":"7b384b36-137d-4b87-9df9-9e597d7c07eb","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"uuid":"696c4228-11ac-4613-bbda-42eb88f6ba37","id":216,"format":"VHD","accountId":2,"hvm":true,"displayText":"Centos
>
> 6.3_64_pip_2014.04","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"18169edd-07f3-f8ea-bec2-1cf759c76d12","id":1,"poolType":"LVM","host":"58.45.1.99","path":"lvm","port":0}},"name":"7b384b36-137d-4b87-9df9-9e597d7c07eb","hypervisorType":"XenServer"}},"executeInSequence":true,"wait":10800}}]
> }
>
> 2014-04-03 19:22:12,332 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650695: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 100111,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/216/7b384b36-137d-4b87-9df9-9e597d7c07eb.vhd","uuid":"696c4228-11ac-4613-bbda-42eb88f6ba37","id":216,"format":"VHD","accountId":2,"hvm":true,"displayText":"Centos
>
> 6.3_64_pip_2014.04","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://58.45.1.98/export/secondary","_role":"Image"}},"name":"7b384b36-137d-4b87-9df9-9e597d7c07eb","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"uuid":"696c4228-11ac-4613-bbda-42eb88f6ba37","id":216,"format":"VHD","accountId":2,"hvm":true,"displayText":"Centos
>
> 6.3_64_pip_2014.04","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"18169edd-07f3-f8ea-bec2-1cf759c76d12","id":1,"poolType":"LVM","host":"58.45.1.99","path":"lvm","port":0}},"name":"7b384b36-137d-4b87-9df9-9e597d7c07eb","hypervisorType":"XenServer"}},"executeInSequence":true,"wait":10800}}]
> }
>
> 2014-04-03 19:22:12,333 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-244:null) Seq 1-947650695: Executing request
>
> 2014-04-03 19:22:12,357 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null)
> ===START=== 251.25.179.130 -- GET
> command=queryAsyncJobResult&jobId=0fbf7edc-00f9-486a-855f-4674a264e323&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524063197
>
> 2014-04-03 19:22:12,378 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null)
> ===END=== 251.25.179.130 -- GET
> command=queryAsyncJobResult&jobId=0fbf7edc-00f9-486a-855f-4674a264e323&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524063197
>
> 2014-04-03 19:22:12,808 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-272:null) Seq 1-947650564: Response Received:
>
> 2014-04-03 19:22:12,809 DEBUG [agent.transport.Request]
> (DirectAgent-272:null) Seq 1-947650564: Processing: { Ans: , MgmtId:
> 264018885718825, via: 1, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}]
> }
>
> 2014-04-03 19:22:14,757 WARN [xen.resource.XenServerStorageProcessor]
> (DirectAgent-244:null) destoryVDIbyNameLabel failed due to there are 0 VDIs
> with name cloud-06de0adc-22b8-475f-93d4-173426e13f48
>
> 2014-04-03 19:22:14,757 WARN [xen.resource.XenServerStorageProcessor]
> (DirectAgent-244:null) can not create vdi in sr
> 18169edd-07f3-f8ea-bec2-1cf759c76d12
>
> 2014-04-03 19:22:14,757 WARN [xen.resource.XenServerStorageProcessor]
> (DirectAgent-244:null) Catch Exception
> com.cloud.utils.exception.CloudRuntimeException for template + due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> 18169edd-07f3-f8ea-bec2-1cf759c76d12
>
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> 18169edd-07f3-f8ea-bec2-1cf759c76d12
>
> at
> com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copy_vhd_from_secondarystorage(XenServerStorageProcessor.java:792)
>
> at
> com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copyTemplateToPrimaryStorage(XenServerStorageProcessor.java:863)
>
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70)
>
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
>
> at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:621)
>
> at
> com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
>
> at
> com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:104)
>
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
>
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>
> at java.lang.Thread.run(Thread.java:662)
>
> 2014-04-03 19:22:14,759 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-244:null) Seq 1-947650695: Response Received:
>
> 2014-04-03 19:22:14,759 DEBUG [agent.transport.Request]
> (DirectAgent-244:null) Seq 1-947650695: Processing: { Ans: , MgmtId:
> 264018885718825, via: 1, Ver: v1, Flags: 110,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Catch
> Exception com.cloud.utils.exception.CloudRuntimeException for template + due
> to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> 18169edd-07f3-f8ea-bec2-1cf759c76d12","wait":0}}] }
>
> 2014-04-03 19:22:14,759 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-244:null) Seq 1-947650695: No more commands found
>
> 2014-04-03 19:22:14,759 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650695: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 110, { CopyCmdAnswer } }
>
> 2014-04-03 19:22:14,767 INFO [storage.volume.VolumeServiceImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> releasing lock for VMTemplateStoragePool 27
>
> 2014-04-03 19:22:14,768 WARN [utils.db.Merovingian2] (Job-Executor-19:job-452
> = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Was unable to find lock for the
> key template_spool_ref27 and thread id 1291754651
>
> 2014-04-03 19:22:14,768 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Unable
> to create Vol[151|vm=93|ROOT]:Catch Exception
> com.cloud.utils.exception.CloudRuntimeException for template + due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> 18169edd-07f3-f8ea-bec2-1cf759c76d12
>
> 2014-04-03 19:22:14,768 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Unable
> to contact resource.
>
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is
> unreachable: Unable to create Vol[151|vm=93|ROOT]:Catch Exception
> com.cloud.utils.exception.CloudRuntimeException for template + due to
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
> 18169edd-07f3-f8ea-bec2-1cf759c76d12
>
> at
> com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2544)
>
> at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2592)
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:889)
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
>
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
>
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
>
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>
> at
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
>
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>
> at java.lang.Thread.run(Thread.java:662)
>
> 2014-04-03 19:22:14,771 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Cleaning
> up resources for the vm VM[User|jcui02] in Starting state
>
> 2014-04-03 19:22:14,773 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650696: Sending { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1, Flags:
> 100111,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-93-VM","wait":0}}]
> }
>
> 2014-04-03 19:22:14,774 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650696: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 100111,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-93-VM","wait":0}}]
> }
>
> 2014-04-03 19:22:14,774 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-247:null) Seq 1-947650696: Executing request
>
> 2014-04-03 19:22:14,922 INFO [xen.resource.CitrixResourceBase]
> (DirectAgent-247:null) VM does not exist on
> XenServerbafae2c6-3d52-4ea9-a060-2eac3ee641ef
>
> 2014-04-03 19:22:14,923 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-247:null) Seq 1-947650696: Response Received:
>
> 2014-04-03 19:22:14,923 DEBUG [agent.transport.Request]
> (DirectAgent-247:null) Seq 1-947650696: Processing: { Ans: , MgmtId:
> 264018885718825, via: 1, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM
> does not exist","wait":0}}] }
>
> 2014-04-03 19:22:14,923 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-247:null) Seq 1-947650696: No more commands found
>
> 2014-04-03 19:22:14,923 DEBUG [agent.transport.Request]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Seq
> 1-947650696: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 110, { StopAnswer } }
>
> 2014-04-03 19:22:14,936 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Service
> SecurityGroup is not supported in the network id=204
>
> 2014-04-03 19:22:14,942 DEBUG [cloud.network.NetworkManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Changing
> active number of nics for network id=204 on -1
>
> 2014-04-03 19:22:14,949 DEBUG [cloud.network.NetworkManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Asking
> VirtualRouter to release
> Nic[98-93-47d80028-8f2e-40fc-baee-08ae56d7c2cd-10.10.30.168]
>
> 2014-04-03 19:22:14,949 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> Successfully released network resources for the vm VM[User|jcui02]
>
> 2014-04-03 19:22:14,949 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> Successfully cleanued up resources for the vm VM[User|jcui02] in Starting
> state
>
> 2014-04-03 19:22:14,963 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Deploy
> avoids pods: [], clusters: [], hosts: [1]
>
> 2014-04-03 19:22:14,965 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> DeploymentPlanner allocation algorithm:
> com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_6ad9090d@3d019bf1
>
> 2014-04-03 19:22:14,965 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Trying
> to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested
> cpu: 1000, requested ram: 2097152000
>
> 2014-04-03 19:22:14,965 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Is ROOT
> volume READY (pool already allocated)?: No
>
> 2014-04-03 19:22:14,965 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> DeploymentPlan has host_id specified, choosing this host and making no checks
> on this host: 1
>
> 2014-04-03 19:22:14,967 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) The
> specified host is in avoid set
>
> 2014-04-03 19:22:14,968 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Cannnot
> deploy to specified host, returning.
>
> 2014-04-03 19:22:14,975 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) VM state
> transitted from :Starting to Stopped with event: OperationFailedvm's original
> host id: null new host id: null host id before state transition: 1
>
> 2014-04-03 19:22:14,985 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Hosts's
> actual total CPU: 52800 and CPU after applying overprovisioning: 52800
>
> 2014-04-03 19:22:14,985 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Hosts's
> actual total RAM: 198546824448 and RAM after applying overprovisioning:
> 198546817024
>
> 2014-04-03 19:22:14,986 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) release
> cpu from host: 1, old used: 51300,reserved: 0, actual total: 52800, total
> with overprovisioning: 52800; new used: 50300,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
>
> 2014-04-03 19:22:14,986 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) release
> mem from host: 1, old used: 112625451008,reserved: 0, total: 198546817024;
> new used: 110528299008,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
>
> 2014-04-03 19:22:15,004 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) 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-04-03 19:22:15,004 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> Successfully transitioned to start state for VM[User|jcui02] reservation id =
> ee9d9c7c-de69-48bb-95cf-5a90e86cbead
>
> 2014-04-03 19:22:15,007 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Trying
> to deploy VM, vm has dcId: 1 and podId: 1
>
> 2014-04-03 19:22:15,007 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Deploy
> avoids pods: [], clusters: [], hosts: [1]
>
> 2014-04-03 19:22:15,022 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Deploy
> avoids pods: [], clusters: [], hosts: [1]
>
> 2014-04-03 19:22:15,023 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> DeploymentPlanner allocation algorithm:
> com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_6ad9090d@3d019bf1
>
> 2014-04-03 19:22:15,023 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Trying
> to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested
> cpu: 1000, requested ram: 2097152000
>
> 2014-04-03 19:22:15,023 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Is ROOT
> volume READY (pool already allocated)?: No
>
> 2014-04-03 19:22:15,023 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> Searching resources only under specified Pod: 1
>
> 2014-04-03 19:22:15,023 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Listing
> clusters in order of aggregate capacity, that have (atleast one host with)
> enough CPU and RAM capacity under this Pod: 1
>
> 2014-04-03 19:22:15,029 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Removing
> from the clusterId list these clusters from avoid set: []
>
> 2014-04-03 19:22:15,037 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Checking
> resources in Cluster: 1 under Pod: 1
>
> 2014-04-03 19:22:15,037 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
>
> 2014-04-03 19:22:15,044 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check for
> allocation: [Host[-1-Routing], Host[-4-Routing]]
>
> 2014-04-03 19:22:15,049 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Found 2 hosts for allocation after prioritization:
> [Host[-1-Routing], Host[-4-Routing]]
>
> 2014-04-03 19:22:15,049 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=2000
>
> 2014-04-03 19:22:15,049 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Host name: xen-99, hostId: 1 is in avoid set,
> skipping this and trying other available hosts
>
> 2014-04-03 19:22:15,057 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Checking if host: 4 has enough capacity for
> requested CPU: 1000 and requested RAM: 2097152000 ,
> cpuOverprovisioningFactor: 1.0
>
> 2014-04-03 19:22:15,062 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Hosts's actual total CPU: 52800 and CPU after
> applying overprovisioning: 52800
>
> 2014-04-03 19:22:15,062 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Free CPU: 800 , Requested CPU: 1000
>
> 2014-04-03 19:22:15,062 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Free RAM: 76912001024 , Requested RAM: 2097152000
>
> 2014-04-03 19:22:15,062 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) STATS: Failed to alloc resource from host: 4
> reservedCpu: 0, used cpu: 52000, requested cpu: 1000, actual total cpu:
> 52800, total cpu with overprovisioning: 52800, reservedMem: 0, used Mem:
> 121634816000, requested mem: 2097152000, total Mem:198546817024
> ,considerReservedCapacity?: true
>
> 2014-04-03 19:22:15,062 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Host does not have enough CPU available, cannot
> allocate to this host.
>
> 2014-04-03 19:22:15,062 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Not using host 4; numCpusGood: true; cpuFreqGood:
> true, host has capacity?false
>
> 2014-04-03 19:22:15,062 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]
> FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
>
> 2014-04-03 19:22:15,062 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) No
> suitable hosts found
>
> 2014-04-03 19:22:15,062 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) No
> suitable hosts found under this Cluster: 1
>
> 2014-04-03 19:22:15,067 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Could
> not find suitable Deployment Destination for this VM under any clusters,
> returning.
>
> 2014-04-03 19:22:15,067 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> Searching resources only under specified Pod: 1
>
> 2014-04-03 19:22:15,067 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Listing
> clusters in order of aggregate capacity, that have (atleast one host with)
> enough CPU and RAM capacity under this Pod: 1
>
> 2014-04-03 19:22:15,072 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Removing
> from the clusterId list these clusters from avoid set: [1]
>
> 2014-04-03 19:22:15,073 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) No
> clusters found after removing disabled clusters and clusters in avoid list,
> returning.
>
> 2014-04-03 19:22:15,080 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) 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-04-03 19:22:15,097 DEBUG [cloud.vm.UserVmManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> Destroying vm VM[User|jcui02] as it failed to create on Host with Id:null
>
> 2014-04-03 19:22:15,106 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) 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-04-03 19:22:15,116 WARN [apache.cloudstack.alerts]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null //
> message:: Failed to deploy Vm with Id: 93, on Host with Id: null
>
> 2014-04-03 19:22:15,120 ERROR [cloud.alert.AlertManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Problem
> sending email alert
>
> java.lang.NullPointerException
>
> at javax.mail.internet.InternetAddress.formatAddress(InternetAddress.java:259)
>
> at javax.mail.internet.InternetAddress.toString(InternetAddress.java:238)
>
> at javax.mail.internet.MimeMessage.setHeader(MimeMessage.java:1533)
>
> at javax.mail.internet.MimeMessage.setSender(MimeMessage.java:361)
>
> at
> com.cloud.alert.AlertManagerImpl$EmailAlert.sendAlert(AlertManagerImpl.java:856)
>
> at com.cloud.alert.AlertManagerImpl.sendAlert(AlertManagerImpl.java:261)
>
> at
> com.cloud.vm.UserVmManagerImpl.updateVmStateForFailedVmCreation(UserVmManagerImpl.java:1732)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2969)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
>
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>
> at
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
>
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>
> at java.lang.Thread.run(Thread.java:662)
>
> 2014-04-03 19:22:15,144 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-58:null) Ping from 4
>
> 2014-04-03 19:22:15,150 INFO [user.vm.DeployVMCmd] (Job-Executor-19:job-452 =
> [ 0fbf7edc-00f9-486a-855f-4674a264e323 ])
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|jcui02]Scope=interface com.cloud.dc.DataCenter; id=1
>
> 2014-04-03 19:22:15,150 INFO [user.vm.DeployVMCmd] (Job-Executor-19:job-452 =
> [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Unable to create a deployment for
> VM[User|jcui02]
>
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|jcui02]Scope=interface com.cloud.dc.DataCenter; id=1
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
>
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
>
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
>
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
>
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>
> at
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
>
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>
> at java.lang.Thread.run(Thread.java:662)
>
> 2014-04-03 19:22:15,153 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-19:job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ]) Complete
> async job-452 = [ 0fbf7edc-00f9-486a-855f-4674a264e323 ], jobStatus: 2,
> resultCode: 530, result: Error Code: 533 Error text: Unable to create a
> deployment for VM[User|jcui02]
>
> 2014-04-03 19:22:15,360 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null)
> ===START=== 251.25.179.130 -- GET
> command=queryAsyncJobResult&jobId=0fbf7edc-00f9-486a-855f-4674a264e323&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524066197
>
> 2014-04-03 19:22:15,377 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-23:null) Async job-452 = [
> 0fbf7edc-00f9-486a-855f-4674a264e323 ] completed
>
> 2014-04-03 19:22:15,384 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null)
> ===END=== 251.25.179.130 -- GET
> command=queryAsyncJobResult&jobId=0fbf7edc-00f9-486a-855f-4674a264e323&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524066197
>
> 2014-04-03 19:22:15,468 DEBUG [cloud.api.ApiServlet] (catalina-exec-12:null)
> ===START=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=5c026edf-5e16-4447-83c9-f46d4960c6ac&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524066307
>
> 2014-04-03 19:22:15,496 DEBUG [cloud.api.ApiServlet] (catalina-exec-12:null)
> ===END=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=5c026edf-5e16-4447-83c9-f46d4960c6ac&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524066307
>
> 2014-04-03 19:22:15,619 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-332:null) Seq 4-1716453478: Response Received:
>
> 2014-04-03 19:22:15,620 DEBUG [agent.transport.Request]
> (StatsCollector-2:null) Seq 4-1716453478: Received: { Ans: , MgmtId:
> 264018885718825, via: 4, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
>
> 2014-04-03 19:22:16,427 INFO [cloud.user.AccountManagerImpl]
> (AccountChecker-1:null) Found 0 removed accounts to cleanup
>
> 2014-04-03 19:22:16,429 INFO [cloud.user.AccountManagerImpl]
> (AccountChecker-1:null) Found 0 disabled accounts to cleanup
>
> 2014-04-03 19:22:16,430 INFO [cloud.user.AccountManagerImpl]
> (AccountChecker-1:null) Found 0 inactive domains to cleanup
>
> 2014-04-03 19:22:16,432 INFO [cloud.user.AccountManagerImpl]
> (AccountChecker-1:null) Found 0 disabled projects to cleanup
>
> 2014-04-03 19:22:16,519 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-10:null) SeqA 2-1090374: Processing Seq 2-1090374: {
> Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
>
> 2014-04-03 19:22:16,522 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-10:null) SeqA 2-1090374: Sending Seq 2-1090374: { Ans:
> , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>
> 2014-04-03 19:22:19,886 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null)
> ===START=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=905deb2e-ee6e-4235-bc82-8c096e40b7dc&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524070744
>
> 2014-04-03 19:22:19,915 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null)
> ===END=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=905deb2e-ee6e-4235-bc82-8c096e40b7dc&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524070744
>
> 2014-04-03 19:22:21,521 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-11:null) SeqA 2-1090375: Processing Seq 2-1090375: {
> Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
>
> 2014-04-03 19:22:21,525 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-11:null) SeqA 2-1090375: Sending Seq 2-1090375: { Ans:
> , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>
> 2014-04-03 19:22:22,597 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null)
> ===START=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=5c026edf-5e16-4447-83c9-f46d4960c6ac&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524073432
>
> 2014-04-03 19:22:22,625 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null)
> ===END=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=5c026edf-5e16-4447-83c9-f46d4960c6ac&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524073432
>
> 2014-04-03 19:22:22,705 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null)
> ===START=== 251.25.179.130 -- GET
> command=listOsTypes&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524073557
>
> 2014-04-03 19:22:22,978 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null)
> ===END=== 251.25.179.130 -- GET
> command=listOsTypes&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524073557
>
> 2014-04-03 19:22:24,091 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
> ===START=== 251.25.179.130 -- GET
> command=listZones&id=4f8a1206-3712-4ad6-832e-f9bf430da511&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524074947
>
> 2014-04-03 19:22:24,106 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
> ===END=== 251.25.179.130 -- GET
> command=listZones&id=4f8a1206-3712-4ad6-832e-f9bf430da511&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524074947
>
> 2014-04-03 19:22:24,179 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null)
> ===START=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=5c026edf-5e16-4447-83c9-f46d4960c6ac&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524075025
>
> 2014-04-03 19:22:24,207 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null)
> ===END=== 251.25.179.130 -- GET
> command=listVirtualMachines&id=5c026edf-5e16-4447-83c9-f46d4960c6ac&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524075025
>
> 2014-04-03 19:22:24,290 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null)
> ===START=== 251.25.179.130 -- GET
> command=listOsTypes&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&_=1396524075135
>
> 2014-04-03 19:22:24,347 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null)
> ===START=== 251.25.179.130 -- GET
> command=listTags&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&resourceId=5c026edf-5e16-4447-83c9-f46d4960c6ac&resourceType=UserVm&listAll=true&_=1396524075150
>
> 2014-04-03 19:22:24,361 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null)
> ===END=== 251.25.179.130 -- GET
> command=listTags&response=json&sessionkey=ISeEUBjpKbtRSQtTfMZfpMhgVBI%3D&resourceId=5c026edf-5e16-4447-83c9-f46d4960c6ac&resourceType=UserVm&listAll=true&_=1396524075150
>
> 2014-04-03 19:22:24,508 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
> (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
>
> ------------------------------------------------------------------------------------------------------------
>
>
>
> cui6522123
>
>
>
> ---
> 此电子邮件没有病毒和恶意软件，因为 avast! 防病毒保护处于活动状态。
> http://www.avast.com
--
白清杰 (Born Bai)
北京开源愿景信息技术有限公司
Mail: linux...@gmail.com
