cloudstack-users-cn mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From tanthalas <tanthalas...@hotmail.com>
Subject Re: 回复: Re: 系统虚拟机无法创建成功
Date Mon, 02 Dec 2013 06:33:54 GMT

这log,看着太费劲了,没有找到确切的原因,分析大概是你在安装配置过程中还有些错误。
建议把KVM节点重装一下,重新加入吧。

刘宇超  Richard Liu




发件人: houqd2012@163.com 
发送时间: 2013-12-02  11:11:09 
收件人: users-cn 
抄送: 
主题: 回复: Re: 系统虚拟机无法创建成功 
 
各位:
        之前的确是因为nfs存储共享的权限问题,修改之后在kvm宿主机端可以正常挂载,而且目录权限也是正确的,但是现在系统虚拟机仍然是创建、删除、创建、删除。。。恳请各位帮忙分析替下。
        kvm宿主机上/var/log/cloud/agent/agent.log中的日志为:        
2013-12-02 11:05:13,313 WARN  [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null)
Exception 
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Storage volume
not found: no storage vol with matching name 'dd324d10-c822-4c1b-a3d5-bfb0b84e323c'
at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getVolume(LibvirtStorageAdaptor.java:90)
at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getPhysicalDisk(LibvirtStorageAdaptor.java:404)
at com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:113)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:2888)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2808)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1035)
at com.cloud.agent.Agent.processRequest(Agent.java:518)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
at com.cloud.utils.nio.Task.run(Task.java:83)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
2013-12-02 11:05:13,314 WARN  [cloud.agent.Agent] (agentRequest-Handler-5:null) Caught: 
java.lang.NullPointerException
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:3922)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2709)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2834)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1035)
at com.cloud.agent.Agent.processRequest(Agent.java:518)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
at com.cloud.utils.nio.Task.run(Task.java:83)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
                    一直是这两段交互。
        管理端/var/log/cloud/management/management-server.log中的日志为:       
            
2013-12-02 11:07:43,007 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning
up NICS
2013-12-02 11:07:43,008 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Cleaning
network for vm: 2206
2013-12-02 11:07:43,012 INFO  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Found a stopped console proxy, bring it up to running pool. proxy vm id : 2
2013-12-02 11:07:43,025 DEBUG [network.guru.DirectNetworkGuru] (secstorage-1:null) Deallocate
network: networkId: 204, ip: null
2013-12-02 11:07:43,026 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM
state transitted from :Stopped to Starting with event: StartRequestedvm's original host id:
null new host id: null host id before state transition: null
2013-12-02 11:07:43,026 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully
transitioned to start state for VM[ConsoleProxy|v-2-VM] reservation id = 8c7b1a03-842a-46c7-bedc-63f275cdd83a
2013-12-02 11:07:43,033 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed
nic id=8820
2013-12-02 11:07:43,033 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Trying
to deploy VM, vm has dcId: 1 and podId: 1
2013-12-02 11:07:43,033 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deploy
avoids pods: null, clusters: null, hosts: null
2013-12-02 11:07:43,038 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Root
volume is ready, need to place VM in volume's cluster
2013-12-02 11:07:43,039 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Vol[2|vm=2|ROOT]
is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId:
1
2013-12-02 11:07:43,047 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) DeploymentPlanner
allocation algorithm: random
2013-12-02 11:07:43,048 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Trying
to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested
ram: 1073741824
2013-12-02 11:07:43,048 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Is ROOT
volume READY (pool already allocated)?: Yes
2013-12-02 11:07:43,048 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching
resources only under specified Cluster: 1
2013-12-02 11:07:43,049 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed
nic id=8821
2013-12-02 11:07:43,063 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Checking
resources in Cluster: 1 under Pod: 1
2013-12-02 11:07:43,063 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Calling
HostAllocators to find suitable hosts
2013-12-02 11:07:43,063 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator)
Looking for hosts in dc: 1  pod:1  cluster:1
2013-12-02 11:07:43,065 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed
nic id=8822
2013-12-02 11:07:43,067 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator)
FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
2013-12-02 11:07:43,074 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator)
Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
2013-12-02 11:07:43,075 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator)
Looking for speed=500Mhz, Ram=1024
2013-12-02 11:07:43,078 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator)
Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: 1073741824
, cpuOverprovisioningFactor: 1.0
2013-12-02 11:07:43,081 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Removed
nic id=8823
2013-12-02 11:07:43,081 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Cleaning
storage for vm: 2206
2013-12-02 11:07:43,083 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator)
Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-12-02 11:07:43,083 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator)
Free CPU: 64000 , Requested CPU: 500
2013-12-02 11:07:43,083 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator)
Free RAM: 270832836608 , Requested RAM: 1073741824
2013-12-02 11:07:43,083 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator)
Host has enough CPU and RAM available
2013-12-02 11:07:43,083 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator)
STATS: Can alloc CPU from host: 1, used: 0, reserved: 0, actual total: 64000, total with overprovisioning:
64000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-12-02 11:07:43,083 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator)
STATS: Can alloc MEM from host: 1, used: 0, reserved: 0, total: 270832836608; requested mem:
1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-12-02 11:07:43,083 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator)
Found a suitable host, adding to list: 1
2013-12-02 11:07:43,083 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator)
Host Allocator returning 1 suitable hosts
2013-12-02 11:07:43,085 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Checking
suitable pools for volume (Id, Type): (2,ROOT)
2013-12-02 11:07:43,085 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Volume
is in READY state and has pool already allocated, checking if pool can be reused, poolId:
200
2013-12-02 11:07:43,087 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Planner
need not allocate a pool for this volume since its READY
2013-12-02 11:07:43,087 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Trying
to find a potenial host and associated storage pools from the suitable host/pool lists for
this VM
2013-12-02 11:07:43,087 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Checking
if host: 1 can access any suitable storage pool for volume: ROOT
2013-12-02 11:07:43,089 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Host: 1
can access pool: 200
2013-12-02 11:07:43,089 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Found a
potential host id: 1 name: kvmhost.vsdevel.corp.landhightech.com and associated storage pools
for this VM
2013-12-02 11:07:43,091 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Expunging
Vol[2206|vm=2206|ROOT]
2013-12-02 11:07:43,091 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Returning
Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2013-12-02 11:07:43,091 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deployment
found  - P0=VM[ConsoleProxy|v-2-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2013-12-02 11:07:43,097 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM
state transitted from :Starting to Starting with event: OperationRetryvm's original host id:
null new host id: 1 host id before state transition: null
2013-12-02 11:07:43,097 DEBUG [cloud.storage.StorageManagerImpl] (secstorage-1:null) Marking
volume that was never created as destroyed: Vol[2206|vm=2206|ROOT]
2013-12-02 11:07:43,107 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Expunged
VM[SecondaryStorageVm|s-2206-VM]
2013-12-02 11:07:43,111 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Hosts's
actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-12-02 11:07:43,111 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) We
are allocating VM, increasing the used capacity of this host:1
2013-12-02 11:07:43,111 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Current
Used CPU: 0 , Free CPU:64000 ,Requested CPU: 500
2013-12-02 11:07:43,111 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Current
Used RAM: 0 , Free RAM:270832836608 ,Requested RAM: 1073741824
2013-12-02 11:07:43,111 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) CPU
STATS after allocation: for host: 1, old used: 0, old reserved: 0, actual total: 64000, total
with overprovisioning: 64000; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2013-12-02 11:07:43,111 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) RAM
STATS after allocation: for host: 1, old used: 0, old reserved: 0, total: 270832836608; new
used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2013-12-02 11:07:43,114 INFO  [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
Primary secondary storage is not even started, wait until next turn
2013-12-02 11:07:43,117 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) VM
is being created in podId: 1
2013-12-02 11:07:43,122 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Lock
is acquired for network id 204 as a part of network implement
2013-12-02 11:07:43,122 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network
id=204 is already implemented
2013-12-02 11:07:43,123 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Lock
is released for network id 204 as a part of network implement
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
JuniperSRX to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Netscaler to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
F5BigIP to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VirtualRouter to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Ovs to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
ExternalDhcpServer to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
BareMetal to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
SecurityGroupProvider to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
CiscoNexus1000vVSM to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VpcVirtualRouter to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,155 WARN  [network.element.VpcVirtualRouterElement] (consoleproxy-1:null)
Network Ntwk[204|Guest|6] is not associated with any VPC
2013-12-02 11:07:43,156 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
NiciraNvp to prepare for Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,166 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Lock
is acquired for network id 202 as a part of network implement
2013-12-02 11:07:43,166 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network
id=202 is already implemented
2013-12-02 11:07:43,167 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Lock
is released for network id 202 as a part of network implement
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
JuniperSRX to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Netscaler to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
F5BigIP to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VirtualRouter to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Ovs to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
ExternalDhcpServer to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
BareMetal to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,201 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
SecurityGroupProvider to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,202 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
CiscoNexus1000vVSM to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,202 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VpcVirtualRouter to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,202 WARN  [network.element.VpcVirtualRouterElement] (consoleproxy-1:null)
Network Ntwk[202|Control|3] is not associated with any VPC
2013-12-02 11:07:43,202 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
NiciraNvp to prepare for Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-169.254.2.79]
2013-12-02 11:07:43,205 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Lock
is acquired for network id 201 as a part of network implement
2013-12-02 11:07:43,205 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network
id=201 is already implemented
2013-12-02 11:07:43,206 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Lock
is released for network id 201 as a part of network implement
2013-12-02 11:07:43,233 DEBUG [network.guru.PodBasedNetworkGuru] (consoleproxy-1:null) Allocated
a nic NicProfile[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175-null for VM[ConsoleProxy|v-2-VM]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
JuniperSRX to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Netscaler to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
F5BigIP to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VirtualRouter to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Ovs to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
ExternalDhcpServer to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
BareMetal to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
SecurityGroupProvider to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
CiscoNexus1000vVSM to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VpcVirtualRouter to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,243 WARN  [network.element.VpcVirtualRouterElement] (consoleproxy-1:null)
Network Ntwk[201|Management|2] is not associated with any VPC
2013-12-02 11:07:43,244 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
NiciraNvp to prepare for Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.175]
2013-12-02 11:07:43,246 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Checking
if we need to prepare 1 volumes for VM[ConsoleProxy|v-2-VM]
2013-12-02 11:07:43,246 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) No
need to recreate the volume: Vol[2|vm=2|ROOT], since it already has a pool assigned: 200,
adding disk to VM
2013-12-02 11:07:43,254 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Boot Args for VM[ConsoleProxy|v-2-VM]:  template=domP type=consoleproxy host=192.168.1.165
port=8250 name=v-2-VM premium=true zone=1 pod=1 guid=Proxy.2 proxy_vm=2 disable_rp_filter=true
eth2ip=192.168.1.193 eth2mask=255.255.255.0 gateway=192.168.1.254 eth0ip=169.254.2.79 eth0mask=255.255.0.0
eth1ip=192.168.1.175 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
internaldns1=192.168.1.92 dns1=61.177.7.1
2013-12-02 11:07:43,277 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-432210010:
Sending  { Cmd , MgmtId: 52234685305, via: 1, Ver: v1, Flags: 100111, [{"StartCommand":{"vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"speed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy host=192.168.1.165 port=8250
name=v-2-VM premium=true zone=1 pod=1 guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=192.168.1.193
eth2mask=255.255.255.0 gateway=192.168.1.254 eth0ip=169.254.2.79 eth0mask=255.255.0.0 eth1ip=192.168.1.175
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254 internaldns1=192.168.1.92
dns1=61.177.7.1","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"db880981011a6b2d","params":{},"uuid":"0f51eaf6-1269-449d-bf55-87038851c236","disks":[{"id":2,"name":"ROOT-2","mountPoint":"/primary","path":"dd324d10-c822-4c1b-a3d5-bfb0b84e323c","size":0,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"3c812bf5-0e22-3263-b902-4a65532af2e3","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"badb94d8-94e6-471c-a59d-687cad6fe277","ip":"192.168.1.193","netmask":"255.255.255.0","gateway":"192.168.1.254","mac":"06:ae:3a:00:00:0d","dns1":"61.177.7.1","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"3b89dfe3-a5d4-4acf-98ce-13cc30d51a20","ip":"169.254.2.79","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:02:4f","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"a76f71f0-9895-4e8b-856f-ad87e62b8df4","ip":"192.168.1.175","netmask":"255.255.255.0","gateway":"192.168.1.254","mac":"06:57:24:00:00:09","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false}]},"wait":0}},{"check.CheckSshCommand":{"ip":"169.254.2.79","port":3922,"interval":6,"retries":100,"name":"v-2-VM","wait":0}}]
}
2013-12-02 11:07:43,321 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 routers. 
2013-12-02 11:07:43,384 DEBUG [agent.transport.Request] (AgentManager-Handler-8:null) Seq
1-432210010: Processing:  { Ans: , MgmtId: 52234685305, via: 1, Ver: v1, Flags: 110, [{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:3922)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2709)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2834)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1035)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat java.lang.Thread.run(Thread.java:701)\n","wait":0}},{"Answer":{"result":false,"details":"Stopped
by previous failure","wait":0}}] }
2013-12-02 11:07:43,384 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-8:null) Seq
1-432210010: No more commands found
2013-12-02 11:07:43,384 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-432210010:
Received:  { Ans: , MgmtId: 52234685305, via: 1, Ver: v1, Flags: 110, { Answer, Answer } }
2013-12-02 11:07:43,388 ERROR [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Failed
to start instance VM[ConsoleProxy|v-2-VM]
com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is of class com.cloud.agent.api.StartAnswer
at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:783)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
2013-12-02 11:07:43,392 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Cleaning
up resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state
2013-12-02 11:07:43,395 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-432210011:
Sending  { Cmd , MgmtId: 52234685305, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}]
}
2013-12-02 11:07:43,636 DEBUG [agent.transport.Request] (AgentManager-Handler-2:null) Seq
1-432210011: Processing:  { Ans: , MgmtId: 52234685305, via: 1, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}]
}
2013-12-02 11:07:43,636 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-2:null) Seq
1-432210011: No more commands found
2013-12-02 11:07:43,636 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-432210011:
Received:  { Ans: , MgmtId: 52234685305, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
JuniperSRX to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Netscaler to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
F5BigIP to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VirtualRouter to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Ovs to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
ExternalDhcpServer to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
BareMetal to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
SecurityGroupProvider to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,657 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
CiscoNexus1000vVSM to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,658 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VpcVirtualRouter to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,658 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
NiciraNvp to release Nic[5-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-192.168.1.193]
2013-12-02 11:07:43,671 DEBUG [network.guru.ControlNetworkGuru] (consoleproxy-1:null) Released
nic: NicProfile[6-2-null-null-null
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
JuniperSRX to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Netscaler to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
F5BigIP to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VirtualRouter to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Ovs to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
ExternalDhcpServer to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
BareMetal to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
SecurityGroupProvider to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
CiscoNexus1000vVSM to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VpcVirtualRouter to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,675 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
NiciraNvp to release Nic[6-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,684 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] (consoleproxy-1:null) Releasing
ip address for reservationId=8c7b1a03-842a-46c7-bedc-63f275cdd83a, instance=7
2013-12-02 11:07:43,686 DEBUG [network.guru.PodBasedNetworkGuru] (consoleproxy-1:null) Released
nic: NicProfile[7-2-null-null-null
2013-12-02 11:07:43,689 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
JuniperSRX to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,689 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Netscaler to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,689 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
F5BigIP to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,689 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VirtualRouter to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
Ovs to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
ExternalDhcpServer to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
BareMetal to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
SecurityGroupProvider to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
CiscoNexus1000vVSM to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
VpcVirtualRouter to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking
NiciraNvp to release Nic[7-2-8c7b1a03-842a-46c7-bedc-63f275cdd83a-null]
2013-12-02 11:07:43,690 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully
released network resources for the vm VM[ConsoleProxy|v-2-VM]
2013-12-02 11:07:43,690 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully
cleanued up resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state
2013-12-02 11:07:43,699 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM
state transitted from :Starting to Stopped with event: OperationFailedvm's original host id:
null new host id: null host id before state transition: 1
2013-12-02 11:07:43,705 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Hosts's
actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-12-02 11:07:43,705 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) release
cpu from host: 1, old used: 500,reserved: 0, actual total: 64000, total with overprovisioning:
64000; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-02 11:07:43,705 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) release
mem from host: 1, old used: 1073741824,reserved: 0, total: 270832836608; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-12-02 11:07:43,708 WARN  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Exception while trying to start console proxy
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable
to start instance due to Unable to get answer that is of class com.cloud.agent.api.StartAnswer
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is of
class com.cloud.agent.api.StartAnswer
at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:783)
... 19 more
2013-12-02 11:07:57,947 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector
is running...
houqd2012@163.com
发件人: tanthalas
发送时间: 2013-12-01 21:26
收件人: users-cn
主题: Re: 系统虚拟机无法创建成功
从libvirtd的log来看,有可能是存储有问题,比如权限之类的,建不了目录。
CloudStack的log,你要在exception这个关键字前面再看看有没有报错原因。
刘宇超  Richard Liu
发件人: houqd2012@163.com 
发送时间: 2013-11-30  23:04:12 
收件人: users-cn 
抄送: 
主题: 系统虚拟机无法创建成功 
各位:
         我的环境是CS4.0.1+kvm,区域可以创建成功,可是系统虚拟机一直无法创建成功,一直创建删除、创建删除。
         agent.log的日志为:
         
2013-11-30 23:01:08,723 WARN  [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null)
Exception 
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Storage volume
not found: no storage vol with matching name 'dd324d10-c822-4c1b-a3d5-bfb0b84e323c'
at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getVolume(LibvirtStorageAdaptor.java:90)
at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getPhysicalDisk(LibvirtStorageAdaptor.java:404)
at com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:113)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:2888)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2808)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1035)
at com.cloud.agent.Agent.processRequest(Agent.java:518)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
at com.cloud.utils.nio.Task.run(Task.java:83)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
2013-11-30 23:01:08,724 WARN  [cloud.agent.Agent] (agentRequest-Handler-1:null) Caught: 
java.lang.NullPointerException
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:3922)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2709)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2834)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1035)
at com.cloud.agent.Agent.processRequest(Agent.java:518)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
at com.cloud.utils.nio.Task.run(Task.java:83)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
libvirtd.log 中的错误日志:
2013-11-30 14:45:28.379+0000: 22402: error : virFileOpenForceOwnerMode:807 : cannot chown
'/mnt/3c812bf5-0e22-3263-b902-4a65532af2e3/s-28-VM-patchdisk' to (0, 0): Invalid argument
2013-11-30 14:45:28.379+0000: 22402: error : virStorageBackendCreateRaw:412 : cannot create
path '/mnt/3c812bf5-0e22-3263-b902-4a65532af2e3/s-28-VM-patchdisk': Invalid argument
2013-11-30 14:45:28.494+0000: 22400: error : virStorageBackendVolOpenCheckMode:1049 : cannot
open volume '/mnt/3c812bf5-0e22-3263-b902-4a65532af2e3/45052b17-61e9-4387-af47-9c4a756755a5':
No such file or directory
2013-11-30 14:50:01.984+0000: 22403: error : virStorageBackendFileSystemRefresh:823 : cannot
open path '/mnt/3c812bf5-0e22-3263-b902-4a65532af2e3': No such file or directory
2013-11-30 14:50:48.322+0000: 22400: error : virCommandWait:2272 : internal error Child process
(/bin/mount 192.168.1.165:/primary /mnt/3c812bf5-0e22-3263-b902-4a65532af2e3) unexpected exit
status 1: mount.nfs: mount point /mnt/3c812bf5-0e22-3263-b902-4a65532af2e3 does not exist
2013-11-30 14:50:48.322+0000: 22400: error : virStorageBackendFileSystemRefresh:823 : cannot
open path '/mnt/3c812bf5-0e22-3263-b902-4a65532af2e3': No such file or directory
2013-11-30 14:50:48.400+0000: 22402: error : virCommandWait:2272 : internal error Child process
(/bin/mount 192.168.1.165:/primary /mnt/3c812bf5-0e22-3263-b902-4a65532af2e3) unexpected exit
status 1: mount.nfs: mount point /mnt/3c812bf5-0e22-3263-b902-4a65532af2e3 does not exist
2013-11-30 14:50:48.400+0000: 22402: error : virStorageBackendFileSystemRefresh:823 : cannot
open path '/mnt/3c812bf5-0e22-3263-b902-4a65532af2e3': No such file or directory
houqd2012@163.com
Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message