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 "Wwei@landhightech.com" <Ww...@landhightech.com> on 2014/11/10 02:13:43 UTC
cloudstack+hyper-v不能启动ssvm，错误：未将对象引用设置到对象的实例
大家好：
我使用的环境是CloudStack4.4.0 + hyper-v, AgentShell.exe 是自己编译的，在配置CloudStack过程中，二级存储虚拟机一直无法启动，在hyper-v管理
服务器上看到系统虚拟机创建了又被删除了，一直这样循环；日志的错误提示如下：
请大家帮忙看看，谢谢啦。
2014-11-10 08:33:20,538 DEBUG [c.c.a.t.Request] (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq 10-909445649752131411: Received: { Ans: , MgmtId: 52231492654, via: 10, Ver: v1, Flags: 10, { StartAnswer } }
2014-11-10 08:33:20,542 INFO [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Unable to start VM on Host[-10-Routing] due to com.cloud.agent.api.StartCommand fail on exception未将对象引用设置到对象的实例。
2014-11-10 08:33:20,545 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Cleaning up resources for the vm VM[SecondaryStorageVm|s-432-VM] in Starting state
2014-11-10 08:33:20,550 DEBUG [c.c.a.t.Request] (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq 10-909445649752131413: Sending { Cmd , MgmtId: 52231492654, via: 10(192.168.1.80), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","wait":0}}] }
2014-11-10 08:33:20,550 DEBUG [c.c.a.t.Request] (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq 10-909445649752131413: Executing: { Cmd , MgmtId: 52231492654, via: 10(192.168.1.80), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","wait":0}}] }
2014-11-10 08:33:20,551 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-193:ctx-83dc4a29) Seq 10-909445649752131413: Executing request
2014-11-10 08:33:20,551 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-193:ctx-83dc4a29) POST request to https://192.168.1.80:8250/api/HypervResource/com.cloud.agent.api.StopCommand with contents {"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","contextMap":{},"wait":0}
2014-11-10 08:33:20,557 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-193:ctx-83dc4a29) Sending cmd to https://192.168.1.80:8250/api/HypervResource/com.cloud.agent.api.StopCommand cmd data:{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","contextMap":{},"wait":0}
2014-11-10 08:33:21,673 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-137:ctx-8b01638f) POST response is [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"contextMap":{}}}]
2014-11-10 08:33:21,674 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-137:ctx-8b01638f) executeRequest received response [Lcom.cloud.agent.api.Answer;@2301dfff
2014-11-10 08:33:21,674 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-137:ctx-8b01638f) Seq 10-909445649752131412: Response Received:
2014-11-10 08:33:21,675 DEBUG [c.c.a.t.Request] (DirectAgent-137:ctx-8b01638f) Seq 10-909445649752131412: Processing: { Ans: , MgmtId: 52231492654, via: 10, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-11-10 08:33:21,675 DEBUG [c.c.a.t.Request] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Seq 10-909445649752131412: Received: { Ans: , MgmtId: 52231492654, via: 10, Ver: v1, Flags: 10, { StopAnswer } }
2014-11-10 08:33:21,692 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Asking VirtualRouter to release NicProfile[1653-421-c45920d8-198a-46f1-a359-74bcfe82f8c6-192.168.1.227-vlan://untagged
2014-11-10 08:33:21,695 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Asking SecurityGroupProvider to release NicProfile[1653-421-c45920d8-198a-46f1-a359-74bcfe82f8c6-192.168.1.227-vlan://untagged
2014-11-10 08:33:21,699 DEBUG [c.c.n.g.ControlNetworkGuru] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Released nic: NicProfile[1654-421-null-null-null
2014-11-10 08:33:21,707 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Releasing ip address for reservationId=c45920d8-198a-46f1-a359-74bcfe82f8c6, instance=1655
2014-11-10 08:33:21,708 DEBUG [c.c.n.g.PodBasedNetworkGuru] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Released nic: NicProfile[1655-421-null-null-null
2014-11-10 08:33:21,712 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Successfully released network resources for the vm VM[ConsoleProxy|v-421-VM]
2014-11-10 08:33:21,712 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-421-VM] in Starting state
2014-11-10 08:33:21,715 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Root volume is ready, need to place VM in volume's cluster
2014-11-10 08:33:21,715 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Vol[421|vm=421|ROOT] is READY, changing deployment plan to use this pool's dcId: 8 , podId: 8 , and clusterId: 17
2014-11-10 08:33:21,718 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Deploy avoids pods: null, clusters: null, hosts: [10]
2014-11-10 08:33:21,719 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@6ae903b2
2014-11-10 08:33:21,720 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Trying to allocate a host and storage pools from dc:8, pod:8,cluster:17, requested cpu: 500, requested ram: 1073741824
2014-11-10 08:33:21,720 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Is ROOT volume READY (pool already allocated)?: Yes
2014-11-10 08:33:21,720 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Searching resources only under specified Cluster: 17
2014-11-10 08:33:21,728 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Checking resources in Cluster: 17 under Pod: 8
2014-11-10 08:33:21,728 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89 FirstFitRoutingAllocator) Looking for hosts in dc: 8 pod:8 cluster:17
2014-11-10 08:33:21,732 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-10-Routing]]
2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-10-Routing]]
2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89 FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89 FirstFitRoutingAllocator) Host name: 192.168.1.80, hostId: 10 is in avoid set, skipping this and trying other available hosts
2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89 FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2014-11-10 08:33:21,738 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No suitable hosts found
2014-11-10 08:33:21,738 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No suitable hosts found under this Cluster: 17
2014-11-10 08:33:21,740 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2014-11-10 08:33:21,740 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Searching resources only under specified Cluster: 17
2014-11-10 08:33:21,742 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) The specified cluster is in avoid set, returning.
2014-11-10 08:33:21,745 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Deploy avoids pods: null, clusters: [17], hosts: [10]
2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@6ae903b2
2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Trying to allocate a host and storage pools from dc:8, pod:8,cluster:null, requested cpu: 500, requested ram: 1073741824
2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Is ROOT volume READY (pool already allocated)?: No
2014-11-10 08:33:21,747 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Searching resources only under specified Pod: 8
2014-11-10 08:33:21,747 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 8
2014-11-10 08:33:21,751 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Removing from the clusterId list these clusters from avoid set: [17]
2014-11-10 08:33:21,753 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2014-11-10 08:33:21,763 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 10
2014-11-10 08:33:21,771 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Hosts's actual total CPU: 32000 and CPU after applying overprovisioning: 32000
2014-11-10 08:33:21,771 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Hosts's actual total RAM: 137357664256 and RAM after applying overprovisioning: 137357664256
2014-11-10 08:33:21,772 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) release cpu from host: 10, old used: 1000,reserved: 0, actual total: 32000, total with overprovisioning: 32000; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-11-10 08:33:21,772 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) release mem from host: 10, old used: 1610612736,reserved: 0, total: 137357664256; new used: 536870912,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-11-10 08:33:21,774 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-421-VM]Scope=interface com.cloud.dc.DataCenter; id=8
2014-11-10 08:33:21,775 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Rethrow exception com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-421-VM]Scope=interface com.cloud.dc.DataCenter; id=8
2014-11-10 08:33:21,775 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 421, job origin: 1362
2014-11-10 08:33:21,775 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319) Unable to complete AsyncJobVO {id:2319, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAABpXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 52231492654, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Nov 10 08:33:16 CST 2014}, job origin:1362
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-421-VM]Scope=interface com.cloud.dc.DataCenter; id=8
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:946)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5190)
at sun.reflect.GeneratedMethodAccessor553.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Wwei@landhightech.com
Re: Re: cloudstack+hyper-v不能启动ssvm，错误：未将对象引用设置到对象的实例
Posted by "Wwei@landhightech.com" <Ww...@landhightech.com>.
非常感谢您的答复，错误日志如下：
2014-11-10 08:24:50,875 [12] DEBUG HypervResource.WmiCallsV2 [b6643564-3a0e-48fc-a5b2-bb3ed19becfc] - Going ahead with create VM s-428-VM, 1 vcpus, 512MB RAM
2014-11-10 08:24:50,797 [12] DEBUG HypervResource.HypervResourceController [b6643564-3a0e-48fc-a5b2-bb3ed19becfc] - 10
2014-11-10 08:24:50,890 [5] INFO HypervResource.WmiCallsV2 [5a0dae8c-fece-4009-8d75-8fc284044a85] - Created disk \\HYPER-V\root\virtualization\v2:Msvm_StorageAllocationSettingData.InstanceID="Microsoft:95D1B8FB-22A8-4E51-9F88-10C3E0513FF6\\83F8638B-8DCA-4152-9EDA-2CA8B33039B4\\0\\0\\L" for VM v-421-VM (GUID 95D1B8FB-22A8-4E51-9F88-10C3E0513FF6), image \\192.168.1.80\Secondary\8e5c6336-2522-4b84-9050-fde33a60d4d6.vhd
2014-11-10 08:24:50,890 [5] ERROR HypervResource.HypervResourceController [5a0dae8c-fece-4009-8d75-8fc284044a85] - com.cloud.agent.api.StartCommand fail on exception未将对象引用设置到对象的实例。
System.NullReferenceException: 未将对象引用设置到对象的实例。
在 HypervResource.WmiCallsV2.DeployVirtualMachine(Object jsonObj, String systemVmIso)
在 HypervResource.HypervResourceController.StartCommand(Object cmd)
2014-11-10 08:24:50,890 [5] INFO HypervResource.HypervResourceController [5a0dae8c-fece-4009-8d75-8fc284044a85] - {
"com.cloud.agent.api.StartAnswer": {
"result": false,
"details": "com.cloud.agent.api.StartCommand fail on exception未将对象引用设置到对象的实例。",
"vm": {
"id": 421,
"name": "v-421-VM",
"type": "ConsoleProxy",
"cpus": 1,
"minSpeed": 500,
"maxSpeed": 500,
"minRam": 1073741824,
"maxRam": 1073741824,
"arch": "x86_64",
"os": "Debian GNU/Linux 5.0 (64-bit)",
"bootArgs": " template=domP type=consoleproxy host=192.168.1.137 port=8250 name=v-421-VM zone=8 pod=8 guid=Proxy.421 proxy_vm=421 disable_rp_filter=true eth2ip=192.168.1.227 eth2mask=255.255.255.0 gateway=192.168.1.254 eth0ip=169.254.0.174 eth0mask=255.255.0.0 eth1ip=192.168.1.220 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254 internaldns1=8.8.8.8 internaldns2=8.8.4.4 dns1=8.8.8.8 dns2=8.8.4.4",
"rebootOnCrash": false,
"enableHA": false,
"limitCpuUse": false,
"enableDynamicallyScaleVm": false,
"vncPassword": "334f66fcb49eb9e8",
"params": {},
"uuid": "527099cf-4bf6-4767-a9df-d17ffc1059e6",
"disks": [
{
"data": {
"org.apache.cloudstack.storage.to.VolumeObjectTO": {
"uuid": "8e5c6336-2522-4b84-9050-fde33a60d4d6",
"volumeType": "ROOT",
"dataStore": {
"org.apache.cloudstack.storage.to.PrimaryDataStoreTO": {
"uuid": "3783198b-40c0-3ae2-8bca-21886bce4221",
"id": 10,
"poolType": "SMB",
"host": "192.168.1.80",
"path": "/Secondary?user=Administrator&domain=vsdevel",
"port": 445,
"url": "SMB://192.168.1.80/Secondary?user=Administrator&domain=vsdevel/?ROLE=Primary&STOREUUID=3783198b-40c0-3ae2-8bca-21886bce4221"
}
},
"name": "ROOT-421",
"size": 0,
"path": "8e5c6336-2522-4b84-9050-fde33a60d4d6",
"volumeId": 421,
"vmName": "v-421-VM",
"accountId": 1,
"format": "VHD",
"id": 421,
"deviceId": 0,
"hypervisorType": "Hyperv"
}
},
"diskSeq": 0,
"path": "8e5c6336-2522-4b84-9050-fde33a60d4d6",
"type": "ROOT",
"_details": {
"managed": "false",
"storagePort": "445",
"storageHost": "192.168.1.80",
"volumeSize": "0"
}
}
],
"nics": [
{
"deviceId": 2,
"networkRateMbps": -1,
"defaultNic": true,
"uuid": "3d01b47c-48dd-4dd5-b9fc-0b3af22780a7",
"ip": "192.168.1.227",
"netmask": "255.255.255.0",
"gateway": "192.168.1.254",
"mac": "06:0c:38:00:00:11",
"dns1": "8.8.8.8",
"dns2": "8.8.4.4",
"broadcastType": "Native",
"type": "Guest",
"broadcastUri": "vlan://untagged",
"isSecurityGroupEnabled": true
},
{
"deviceId": 0,
"networkRateMbps": -1,
"defaultNic": false,
"uuid": "e710638a-fd0e-483f-a38d-61b28d528526",
"ip": "169.254.0.174",
"netmask": "255.255.0.0",
"gateway": "169.254.0.1",
"mac": "0e:00:a9:fe:00:ae",
"broadcastType": "LinkLocal",
"type": "Control",
"isSecurityGroupEnabled": false
},
{
"deviceId": 1,
"networkRateMbps": -1,
"defaultNic": false,
"uuid": "dfe6e00b-b36c-4cf2-b855-bdd1f62d9394",
"ip": "192.168.1.220",
"netmask": "255.255.255.0",
"gateway": "192.168.1.254",
"mac": "06:6c:ec:00:00:0a",
"broadcastType": "Native",
"type": "Management",
"isSecurityGroupEnabled": false
}
]
},
"contextMap": {}
}
}
2014-11-10 08:24:50,968 [12] DEBUG HypervResource.WmiCallsV2 [b6643564-3a0e-48fc-a5b2-bb3ed19becfc] - Created VM s-428-VM
2014-11-10 08:24:50,999 [5] INFO HypervResource.HypervResourceController [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - com.cloud.agent.api.StopCommand{
"isProxy": false,
"executeInSequence": false,
"checkBeforeCleanup": false,
"vmName": "v-421-VM",
"contextMap": {},
"wait": 0
}
2014-11-10 08:24:50,999 [5] DEBUG HypervResource.WmiCallsV2 [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - Got request to destroy vm v-421-VM
2014-11-10 08:24:51,015 [5] INFO HypervResource.WmiCallsV2 [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - Shutting down of system failed; may be shutdown integration services are missing
2014-11-10 08:24:51,031 [5] DEBUG HypervResource.WmiCallsV2 [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - Remove VM v-421-VM (GUID 95D1B8FB-22A8-4E51-9F88-10C3E0513FF6)
2014-11-10 08:24:51,031 [5] INFO HypervResource.WmiCallsV2 [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - Changing state of v-421-VM (GUID 95D1B8FB-22A8-4E51-9F88-10C3E0513FF6) to Disabled
2014-11-10 08:24:51,046 [5] INFO HypervResource.WmiCallsV2 [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - RequestStateChange returned 32775, which means vm in wrong state for requested state change. Treating as if requested state was reached
2014-11-10 08:24:51,046 [5] INFO HypervResource.WmiCallsV2 [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - Successfully changed vm state of v-421-VM (GUID 95D1B8FB-22A8-4E51-9F88-10C3E0513FF6 to requested state 3
2014-11-10 08:24:51,046 [5] DEBUG HypervResource.WmiCallsV2 [7597c6df-7c8b-4f97-b7d0-7924bb7841fd] - Remove associated switch ports for VM v-421-VM (GUID 95D1B8FB-22A8-4E51-9F88-10C3E0513FF6)
Wwei@landhightech.com
发件人： Darren Tang
发送时间： 2014-11-10 11:35
收件人： users-cn@cloudstack.apache.org
主题： Re: cloudstack+hyper-v不能启动ssvm，错误：未将对象引用设置到对象的实例
麻烦提供下hyper-v宿主机 日志查看器中的信息。
运行输入： eventvwr 在左侧 windows日志，应用程序日志中，查看级别为错误的日志，吧报错贴上来。
2014-11-10 9:13 GMT+08:00 Wwei@landhightech.com <Ww...@landhightech.com>:
>
> 大家好：
> 我使用的环境是CloudStack4.4.0 + hyper-v, AgentShell.exe
> 是自己编译的，在配置CloudStack过程中，二级存储虚拟机一直无法启动，在hyper-v管理
> 服务器上看到系统虚拟机创建了又被删除了，一直这样循环；日志的错误提示如下：
> 请大家帮忙看看，谢谢啦。
>
>
>
>
> 2014-11-10 08:33:20,538 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq
> 10-909445649752131411: Received: { Ans: , MgmtId: 52231492654, via: 10,
> Ver: v1, Flags: 10, { StartAnswer } }
> 2014-11-10 08:33:20,542 INFO [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Unable
> to start VM on Host[-10-Routing] due to com.cloud.agent.api.StartCommand
> fail on exception未将对象引用设置到对象的实例。
> 2014-11-10 08:33:20,545 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Cleaning
> up resources for the vm VM[SecondaryStorageVm|s-432-VM] in Starting state
> 2014-11-10 08:33:20,550 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq
> 10-909445649752131413: Sending { Cmd , MgmtId: 52231492654, via:
> 10(192.168.1.80), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","wait":0}}]
> }
> 2014-11-10 08:33:20,550 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq
> 10-909445649752131413: Executing: { Cmd , MgmtId: 52231492654, via:
> 10(192.168.1.80), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","wait":0}}]
> }
> 2014-11-10 08:33:20,551 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-193:ctx-83dc4a29) Seq 10-909445649752131413: Executing request
> 2014-11-10 08:33:20,551 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-193:ctx-83dc4a29) POST request to
> https://192.168.1.80:8250/api/HypervResource/com.cloud.agent.api.StopCommand
> with contents
> {"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","contextMap":{},"wait":0}
> 2014-11-10 08:33:20,557 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-193:ctx-83dc4a29) Sending cmd to
> https://192.168.1.80:8250/api/HypervResource/com.cloud.agent.api.StopCommand
> cmd
> data:{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","contextMap":{},"wait":0}
> 2014-11-10 08:33:21,673 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-137:ctx-8b01638f) POST response is
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"contextMap":{}}}]
> 2014-11-10 08:33:21,674 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-137:ctx-8b01638f) executeRequest received response
> [Lcom.cloud.agent.api.Answer;@2301dfff
> 2014-11-10 08:33:21,674 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-137:ctx-8b01638f) Seq 10-909445649752131412: Response Received:
> 2014-11-10 08:33:21,675 DEBUG [c.c.a.t.Request]
> (DirectAgent-137:ctx-8b01638f) Seq 10-909445649752131412: Processing: {
> Ans: , MgmtId: 52231492654, via: 10, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
> 2014-11-10 08:33:21,675 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Seq
> 10-909445649752131412: Received: { Ans: , MgmtId: 52231492654, via: 10,
> Ver: v1, Flags: 10, { StopAnswer } }
> 2014-11-10 08:33:21,692 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Asking
> VirtualRouter to release
> NicProfile[1653-421-c45920d8-198a-46f1-a359-74bcfe82f8c6-192.168.1.227-vlan://untagged
> 2014-11-10 08:33:21,695 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Asking
> SecurityGroupProvider to release
> NicProfile[1653-421-c45920d8-198a-46f1-a359-74bcfe82f8c6-192.168.1.227-vlan://untagged
> 2014-11-10 08:33:21,699 DEBUG [c.c.n.g.ControlNetworkGuru]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Released
> nic: NicProfile[1654-421-null-null-null
> 2014-11-10 08:33:21,707 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Releasing ip address for
> reservationId=c45920d8-198a-46f1-a359-74bcfe82f8c6, instance=1655
> 2014-11-10 08:33:21,708 DEBUG [c.c.n.g.PodBasedNetworkGuru]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Released
> nic: NicProfile[1655-421-null-null-null
> 2014-11-10 08:33:21,712 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Successfully released network resources for the vm VM[ConsoleProxy|v-421-VM]
> 2014-11-10 08:33:21,712 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Successfully cleanued up resources for the vm VM[ConsoleProxy|v-421-VM] in
> Starting state
> 2014-11-10 08:33:21,715 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Root
> volume is ready, need to place VM in volume's cluster
> 2014-11-10 08:33:21,715 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Vol[421|vm=421|ROOT] is READY, changing deployment plan to use this pool's
> dcId: 8 , podId: 8 , and clusterId: 17
> 2014-11-10 08:33:21,718 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Deploy
> avoids pods: null, clusters: null, hosts: [10]
> 2014-11-10 08:33:21,719 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> DeploymentPlanner allocation algorithm:
> com.cloud.deploy.FirstFitPlanner@6ae903b2
> 2014-11-10 08:33:21,720 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Trying
> to allocate a host and storage pools from dc:8, pod:8,cluster:17, requested
> cpu: 500, requested ram: 1073741824
> 2014-11-10 08:33:21,720 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Is ROOT
> volume READY (pool already allocated)?: Yes
> 2014-11-10 08:33:21,720 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Searching resources only under specified Cluster: 17
> 2014-11-10 08:33:21,728 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Checking
> resources in Cluster: 17 under Pod: 8
> 2014-11-10 08:33:21,728 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Looking for hosts in dc: 8 pod:8 cluster:17
> 2014-11-10 08:33:21,732 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for
> allocation: [Host[-10-Routing]]
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Found 1 hosts for allocation after
> prioritization: [Host[-10-Routing]]
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Host name: 192.168.1.80, hostId: 10 is in avoid
> set, skipping this and trying other available hosts
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
> 2014-11-10 08:33:21,738 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No
> suitable hosts found
> 2014-11-10 08:33:21,738 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No
> suitable hosts found under this Cluster: 17
> 2014-11-10 08:33:21,740 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Could
> not find suitable Deployment Destination for this VM under any clusters,
> returning.
> 2014-11-10 08:33:21,740 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Searching resources only under specified Cluster: 17
> 2014-11-10 08:33:21,742 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) The
> specified cluster is in avoid set, returning.
> 2014-11-10 08:33:21,745 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Deploy
> avoids pods: null, clusters: [17], hosts: [10]
> 2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> DeploymentPlanner allocation algorithm:
> com.cloud.deploy.FirstFitPlanner@6ae903b2
> 2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Trying
> to allocate a host and storage pools from dc:8, pod:8,cluster:null,
> requested cpu: 500, requested ram: 1073741824
> 2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Is ROOT
> volume READY (pool already allocated)?: No
> 2014-11-10 08:33:21,747 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Searching resources only under specified Pod: 8
> 2014-11-10 08:33:21,747 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Listing
> clusters in order of aggregate capacity, that have (atleast one host with)
> enough CPU and RAM capacity under this Pod: 8
> 2014-11-10 08:33:21,751 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Removing
> from the clusterId list these clusters from avoid set: [17]
> 2014-11-10 08:33:21,753 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No
> clusters found after removing disabled clusters and clusters in avoid list,
> returning.
> 2014-11-10 08:33:21,763 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) VM state
> transitted from :Starting to Stopped with event: OperationFailedvm's
> original host id: null new host id: null host id before state transition: 10
> 2014-11-10 08:33:21,771 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Hosts's
> actual total CPU: 32000 and CPU after applying overprovisioning: 32000
> 2014-11-10 08:33:21,771 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Hosts's
> actual total RAM: 137357664256 and RAM after applying overprovisioning:
> 137357664256
> 2014-11-10 08:33:21,772 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) release
> cpu from host: 10, old used: 1000,reserved: 0, actual total: 32000, total
> with overprovisioning: 32000; new used: 500,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
> 2014-11-10 08:33:21,772 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) release
> mem from host: 10, old used: 1610612736,reserved: 0, total: 137357664256;
> new used: 536870912,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
> 2014-11-10 08:33:21,774 ERROR [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Invocation exception, caused by:
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[ConsoleProxy|v-421-VM]Scope=interface
> com.cloud.dc.DataCenter; id=8
> 2014-11-10 08:33:21,775 INFO [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Rethrow
> exception com.cloud.exception.InsufficientServerCapacityException: Unable
> to create a deployment for VM[ConsoleProxy|v-421-VM]Scope=interface
> com.cloud.dc.DataCenter; id=8
> 2014-11-10 08:33:21,775 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319) Done with run of VM
> work job: com.cloud.vm.VmWorkStart for VM 421, job origin: 1362
> 2014-11-10 08:33:21,775 ERROR [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319) Unable to complete
> AsyncJobVO {id:2319, userId: 1, accountId: 1, instanceType: null,
> instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
> rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAABpXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 52231492654, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: Mon Nov 10 08:33:16 CST 2014}, job origin:1362
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM[ConsoleProxy|v-421-VM]Scope=interface
> com.cloud.dc.DataCenter; id=8
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:946)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5190)
> at sun.reflect.GeneratedMethodAccessor553.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>
>
> Wwei@landhightech.com
>
Re: cloudstack+hyper-v不能启动ssvm，错误：未将对象引用设置到对象的实例
Posted by Darren Tang <da...@gmail.com>.
麻烦提供下hyper-v宿主机 日志查看器中的信息。
运行输入： eventvwr 在左侧 windows日志，应用程序日志中，查看级别为错误的日志，吧报错贴上来。
2014-11-10 9:13 GMT+08:00 Wwei@landhightech.com <Ww...@landhightech.com>:
>
> 大家好：
> 我使用的环境是CloudStack4.4.0 + hyper-v, AgentShell.exe
> 是自己编译的，在配置CloudStack过程中，二级存储虚拟机一直无法启动，在hyper-v管理
> 服务器上看到系统虚拟机创建了又被删除了，一直这样循环；日志的错误提示如下：
> 请大家帮忙看看，谢谢啦。
>
>
>
>
> 2014-11-10 08:33:20,538 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq
> 10-909445649752131411: Received: { Ans: , MgmtId: 52231492654, via: 10,
> Ver: v1, Flags: 10, { StartAnswer } }
> 2014-11-10 08:33:20,542 INFO [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Unable
> to start VM on Host[-10-Routing] due to com.cloud.agent.api.StartCommand
> fail on exception未将对象引用设置到对象的实例。
> 2014-11-10 08:33:20,545 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Cleaning
> up resources for the vm VM[SecondaryStorageVm|s-432-VM] in Starting state
> 2014-11-10 08:33:20,550 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq
> 10-909445649752131413: Sending { Cmd , MgmtId: 52231492654, via:
> 10(192.168.1.80), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","wait":0}}]
> }
> 2014-11-10 08:33:20,550 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-59:ctx-a3f5f22b job-1363/job-2320 ctx-cd7c5bea) Seq
> 10-909445649752131413: Executing: { Cmd , MgmtId: 52231492654, via:
> 10(192.168.1.80), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","wait":0}}]
> }
> 2014-11-10 08:33:20,551 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-193:ctx-83dc4a29) Seq 10-909445649752131413: Executing request
> 2014-11-10 08:33:20,551 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-193:ctx-83dc4a29) POST request to
> https://192.168.1.80:8250/api/HypervResource/com.cloud.agent.api.StopCommand
> with contents
> {"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","contextMap":{},"wait":0}
> 2014-11-10 08:33:20,557 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-193:ctx-83dc4a29) Sending cmd to
> https://192.168.1.80:8250/api/HypervResource/com.cloud.agent.api.StopCommand
> cmd
> data:{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"s-432-VM","contextMap":{},"wait":0}
> 2014-11-10 08:33:21,673 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-137:ctx-8b01638f) POST response is
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"contextMap":{}}}]
> 2014-11-10 08:33:21,674 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
> (DirectAgent-137:ctx-8b01638f) executeRequest received response
> [Lcom.cloud.agent.api.Answer;@2301dfff
> 2014-11-10 08:33:21,674 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-137:ctx-8b01638f) Seq 10-909445649752131412: Response Received:
> 2014-11-10 08:33:21,675 DEBUG [c.c.a.t.Request]
> (DirectAgent-137:ctx-8b01638f) Seq 10-909445649752131412: Processing: {
> Ans: , MgmtId: 52231492654, via: 10, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
> 2014-11-10 08:33:21,675 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Seq
> 10-909445649752131412: Received: { Ans: , MgmtId: 52231492654, via: 10,
> Ver: v1, Flags: 10, { StopAnswer } }
> 2014-11-10 08:33:21,692 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Asking
> VirtualRouter to release
> NicProfile[1653-421-c45920d8-198a-46f1-a359-74bcfe82f8c6-192.168.1.227-vlan://untagged
> 2014-11-10 08:33:21,695 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Asking
> SecurityGroupProvider to release
> NicProfile[1653-421-c45920d8-198a-46f1-a359-74bcfe82f8c6-192.168.1.227-vlan://untagged
> 2014-11-10 08:33:21,699 DEBUG [c.c.n.g.ControlNetworkGuru]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Released
> nic: NicProfile[1654-421-null-null-null
> 2014-11-10 08:33:21,707 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Releasing ip address for
> reservationId=c45920d8-198a-46f1-a359-74bcfe82f8c6, instance=1655
> 2014-11-10 08:33:21,708 DEBUG [c.c.n.g.PodBasedNetworkGuru]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Released
> nic: NicProfile[1655-421-null-null-null
> 2014-11-10 08:33:21,712 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Successfully released network resources for the vm VM[ConsoleProxy|v-421-VM]
> 2014-11-10 08:33:21,712 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Successfully cleanued up resources for the vm VM[ConsoleProxy|v-421-VM] in
> Starting state
> 2014-11-10 08:33:21,715 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Root
> volume is ready, need to place VM in volume's cluster
> 2014-11-10 08:33:21,715 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Vol[421|vm=421|ROOT] is READY, changing deployment plan to use this pool's
> dcId: 8 , podId: 8 , and clusterId: 17
> 2014-11-10 08:33:21,718 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Deploy
> avoids pods: null, clusters: null, hosts: [10]
> 2014-11-10 08:33:21,719 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> DeploymentPlanner allocation algorithm:
> com.cloud.deploy.FirstFitPlanner@6ae903b2
> 2014-11-10 08:33:21,720 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Trying
> to allocate a host and storage pools from dc:8, pod:8,cluster:17, requested
> cpu: 500, requested ram: 1073741824
> 2014-11-10 08:33:21,720 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Is ROOT
> volume READY (pool already allocated)?: Yes
> 2014-11-10 08:33:21,720 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Searching resources only under specified Cluster: 17
> 2014-11-10 08:33:21,728 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Checking
> resources in Cluster: 17 under Pod: 8
> 2014-11-10 08:33:21,728 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Looking for hosts in dc: 8 pod:8 cluster:17
> 2014-11-10 08:33:21,732 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for
> allocation: [Host[-10-Routing]]
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Found 1 hosts for allocation after
> prioritization: [Host[-10-Routing]]
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Host name: 192.168.1.80, hostId: 10 is in avoid
> set, skipping this and trying other available hosts
> 2014-11-10 08:33:21,738 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89
> FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
> 2014-11-10 08:33:21,738 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No
> suitable hosts found
> 2014-11-10 08:33:21,738 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No
> suitable hosts found under this Cluster: 17
> 2014-11-10 08:33:21,740 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Could
> not find suitable Deployment Destination for this VM under any clusters,
> returning.
> 2014-11-10 08:33:21,740 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Searching resources only under specified Cluster: 17
> 2014-11-10 08:33:21,742 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) The
> specified cluster is in avoid set, returning.
> 2014-11-10 08:33:21,745 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Deploy
> avoids pods: null, clusters: [17], hosts: [10]
> 2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> DeploymentPlanner allocation algorithm:
> com.cloud.deploy.FirstFitPlanner@6ae903b2
> 2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Trying
> to allocate a host and storage pools from dc:8, pod:8,cluster:null,
> requested cpu: 500, requested ram: 1073741824
> 2014-11-10 08:33:21,746 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Is ROOT
> volume READY (pool already allocated)?: No
> 2014-11-10 08:33:21,747 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Searching resources only under specified Pod: 8
> 2014-11-10 08:33:21,747 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Listing
> clusters in order of aggregate capacity, that have (atleast one host with)
> enough CPU and RAM capacity under this Pod: 8
> 2014-11-10 08:33:21,751 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Removing
> from the clusterId list these clusters from avoid set: [17]
> 2014-11-10 08:33:21,753 DEBUG [c.c.d.FirstFitPlanner]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) No
> clusters found after removing disabled clusters and clusters in avoid list,
> returning.
> 2014-11-10 08:33:21,763 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) VM state
> transitted from :Starting to Stopped with event: OperationFailedvm's
> original host id: null new host id: null host id before state transition: 10
> 2014-11-10 08:33:21,771 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Hosts's
> actual total CPU: 32000 and CPU after applying overprovisioning: 32000
> 2014-11-10 08:33:21,771 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Hosts's
> actual total RAM: 137357664256 and RAM after applying overprovisioning:
> 137357664256
> 2014-11-10 08:33:21,772 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) release
> cpu from host: 10, old used: 1000,reserved: 0, actual total: 32000, total
> with overprovisioning: 32000; new used: 500,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
> 2014-11-10 08:33:21,772 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) release
> mem from host: 10, old used: 1610612736,reserved: 0, total: 137357664256;
> new used: 536870912,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
> 2014-11-10 08:33:21,774 ERROR [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89)
> Invocation exception, caused by:
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[ConsoleProxy|v-421-VM]Scope=interface
> com.cloud.dc.DataCenter; id=8
> 2014-11-10 08:33:21,775 INFO [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319 ctx-aa767b89) Rethrow
> exception com.cloud.exception.InsufficientServerCapacityException: Unable
> to create a deployment for VM[ConsoleProxy|v-421-VM]Scope=interface
> com.cloud.dc.DataCenter; id=8
> 2014-11-10 08:33:21,775 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319) Done with run of VM
> work job: com.cloud.vm.VmWorkStart for VM 421, job origin: 1362
> 2014-11-10 08:33:21,775 ERROR [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-58:ctx-3a4c1a3f job-1362/job-2319) Unable to complete
> AsyncJobVO {id:2319, userId: 1, accountId: 1, instanceType: null,
> instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
> rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAABpXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 52231492654, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: Mon Nov 10 08:33:16 CST 2014}, job origin:1362
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM[ConsoleProxy|v-421-VM]Scope=interface
> com.cloud.dc.DataCenter; id=8
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:946)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5190)
> at sun.reflect.GeneratedMethodAccessor553.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>
>
> Wwei@landhightech.com
>