Hi Anshul
On Fri, Sep 18, 2015 at 8:02 AM, Anshul Gangwar
<anshul.gang...@citrix.com> wrote:
> Attach some Hyper-V agent log. They will give better idea on what is
> happening on host.
>
Thanks for the feedback. Attached is the paste of the windows event
manager error we're seeing that relates to the agent.
I'm not sure if this is the correct log but I can't find any other
logs written by the hyper-v agent (is there a way to set this up?)
On the controller side, I see an agent directory, but it is empty ...
How to enable agent logging on the controller side?
> Regards,
> Anshul
>
>> On 17-Sep-2015, at 3:27 PM, Traiano Welcome <trai...@gmail.com> wrote:
>>
>> Hi All
>>
>> I am trying to configure a zone based on a hyper-v cluster (ms windows
>> 2012 hyper-v cluster of two nodes, using SMBv3).
>>
>> The zone configuration completes successfully, including adding
>> primary and secondary SMBv3 storage and adding hyper-v cluster node.
>> However, I see that CloudStack is continuously building the system
>> VMs, and destroying them in an endless loop, without ever running them
>> successfully
>>
>> What I'm seeing in the hyper-v management console:
>>
>> -The Cloudstack controller is successfully is launching and
>> destroying the system vms:
>> - System VMs are created and destroyed continuously (Console Proxy nd
>> Secondary Storage VM) (confirmed by the cloudstack manager logs)
>> - System VMs appear as stopped in the CloudStack web interface, and
>> periodically vanish.
>>
>> Looking through the logs the VM build process fails with this message:
>>
>> ---
>> .
>> .
>>
>> 2015-09-17 04:45:07,888 INFO [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-57:ctx-fb0c16f6 job-126/job-7169 ctx-d0465230)
>> (logid:d11afe7a) Unable to start VM on Host[-94-Routing] due to
>> com.cloud.agent.api.StartCommand fail on exceptionObject reference not
>> set to an instance of an object.
>> .
>> .
>> .
>> ---
>>
>> Details of my setup:
>>
>> 1. Hyper-V Version: Hypervisor version 6.2
>> 2. CloudStack version/distribution: 4.5
>> 3. Hyper-V Host configuration: CPU sockets = 2, RAM = 160GiB, Dual
>> 10Gibps NIC (teamed)
>> 4. Primary and Secondary Primary Storage Details: SMBv3 on a Windows 2012
>> node
>> 5. Zone Network Details: Basic.
>> 6. The CloudStack controller is successfully managing VMs running on
>> XenServer 6.2.
>>
>> Attached is a log dump (addresses sanitized) of the whole vm build cycle.
>>
>> Has anyone seen this kind of issue before when integrating Hyper-V
>> with CloudStack ?
>> Is there a set of additional things I could try to troubleshoot this,
>> or configurations I could try?
>>
>> Here are the basic troubleshooting tests I'v etried:
>>
>> - Seeding the hyper-v image to secondary storage: success
>> - Mounting the secondary and primary storage from the Windows 2012
>> storage node to the CloudStck controller VM: success
>> - Browsing to the agent port via https from the controller to the
>> Hyper-V nodes: success
>> - Creating VMs manually on the Hyper-V nodes: success
>>
>> I'm not seeing any network communications, physical hardware or
>> hyper-v clusters. I suppose that the fact system VMs are being
>> created on Hyper-V means that essentially CloudStack is communicating
>> with hyper-V., and controlling it correctly ... The only question is
>> why the System VM deployment fails.
>>
>> I suspect physical network addressing configuration, but I'm not sure
>> how to confirm this ...
>>
>> Many thanks in advance for any assistance!
>> Traiano
>>
>>
>> P.S: Some key debug messages in the logs (leading up to the system vms
>> being destroyed):
>>
>>
>> -- <sample from /var/log/cloudstack/management/management-server.log> ---
>>
>> 2015-09-17 04:45:05,382 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
>> (secstorage-1:ctx-bb312d18) (logid:49567518) New secondary storage vm
>> created, zone: lol-hq-zone, secStorageVm: s-2412-VM, public IP: null,
>> private IP: null
>> .
>> .
>> 2015-09-17 04:45:07,709 DEBUG [c.c.a.m.AgentManagerImpl]
>> (AgentManager-Handler-5:null) (logid:) SeqA 83-346478: Sending Seq
>> 83-346478: { Ans: , MgmtId: 117586639591181, via: 83, Ver: v1,
>> Flags:100010,
>> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}]
>> }
>> .
>> .
>> 2015-09-17 04:45:07,692 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
>> (DirectAgent-293:ctx-de6632d6) (logid:138757fe) Sending cmd to
>> https://xx.yy.zz.223:8250/api/HypervResource/com.cloud.agent.api.StartCommand
>> cmd
>> data:{"vm":{"id":2412,"name":"s-2412VM","type":"SecondaryStorageVm","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"Debian
>> GNU/Linux 7(64-bit)","bootArgs":" template=domP type=secstorage
>> host=172.16.116.219 port=8250 name=s-2412-VM zone=9 pod=9
>> guid=s-2412","enableHA":false,"limitCpuUse":false,"enableDynamicallyScale
>> Vm":false,","params":{},"uuid":"cfe1f3c6-6b1d-4984-8752-67d33a9cbb26","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"e069cb94-8f38-4cf6-b39b-459230c2e18a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"4281fa3a-eb9f-3556-82a6-34fc2b8bbc8b","id":14,"poolType":"SMB","host":"xx.yy.zz.221","path":"/Primary","port":445,"url":"SMB://xx.yy.zz.221/Primary/?ROLE=Primary&STOREUUID=4281fa3a-eb9f-3556-82a6-34fc2b8bbc8b"}},"name":"ROOT-2412","size":0,"path":"e069cb94-8f38-4cf6-b39b-459230c2e18a","volumeId":2246,"vmName":"s-2412-VM","accountId":1,"format":"VHD","provisioningType":"THIN","id":2246,"deviceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"e069cb94-8f38-4cf6-b39b-459230c2e18a","type":"ROOT
>> ","_details":{"managed":"false","storagePort":"445","storageHost":"xx.yy.zz.221","volumeSize":"0"}}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"pxeDisable":true,"nicUuid":"2ea5
>> f5f1-8500-4794-91fc-2816ebb171a7","uuid":"a4a46926-8caf-4bee-b1a0-70529c3ecac6","ip":"aa.bb.cc.137","netmask":"255.255.255.0","gateway":"aa.bb.cc.10","mac":"06:86:a6:00:00:0c","dns1":"172.16.
>> 100.180","dns2":"mm.nn.oo.171","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSecurityGroupEnabled":false,"name":"Virtual
>> Switch"}, "deviceId":0,"networkRateMbps":-1
>> ,"defaultNic":false,"pxeDisable":true,"nicUuid":"df1eb057-f81a-493e-a2ea-a643238ed6f8","uuid":"e548abca-23da-4568-96e4-3a6aa709566b","ip":"169.254.3.60","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:03:3c","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"f1cdfa32-09ad-4431-97c6-1b237e1e4575","uuid":"d149dd9f-ac98-411d-9fb0-e587852a9df1","ip":"xx.yy.zz.162","netmask":"255.255.255.0","gateway":"xx.yy.zz.10","mac":"06:7f:b0:00:00:3d","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtual
>> Switch"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"143c7431-49f3-466b-a754-da131
>> d2d61ce","uuid":"25fc42d5-31fe-4ed1-ae66-0ca9d617bfa7","ip":"xx.yy.zz.159","netmask":"255.255.255.0","gateway":"xx.yy.zz.10","mac":"06:ab:8a:00:00:3a","broadcastType":"Native","type":"Storage","i
>> SecurityGroupEnabled":false,"name":"Virtual
>> Switch"}]},"hostIp":"xx.yy.zz.223","executeInSequence":false,"secondaryStorage":"cifs://xx.yy.zz.221/Secondary?user=username&domain=AHEM","contextMap":{"job":"job-58/job-7170","logid":"138757fe"},"wait":0}
>> .
>> .
>> 2015-09-17 04:45:07,844 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
>> (DirectAgent-295:ctx-f5578a04) (logid:d11afe7a) executeRequest
>> received response [{"com.cloud.agent.api.StartAnswer":{"vm":{"
>> id":1241,"name":"v-1241-VM","type":"ConsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
>> GNU/Linux 7(64-bit)","bootArgs":" tem
>> plate\u003ddomP type\u003dconsoleproxy host\u003d172.16.116.219
>> port\u003d8250 name\u003dv-1241-VM zone\u003d9 pod\u003d9
>> guid\u003dProxy.1241 proxy_vm\u003d1241 disable_rp_filter\u003dtrue
>> vmpas
>> sword\u003dtCUAMd6x eth2ip\u003daa.bb.cc.138
>> eth2mask\u003d255.255.255.0 gateway\u003daa.bb.cc.10
>> eth0ip\u003d169.254.2.35 eth0mask\u003d255.255.0.0
>> eth1ip\u003dxx.yy.zz.163 eth1mask\u003d255
>> .255.255.0 mgmtcidr\u003d172.16.116.0/23 localgw\u003dxx.yy.zz.10
>> internaldns1\u003dxx.yy.zz.180 internaldns2\u003dmm.nn.oo.171
>> dns1\u003dxx.yy.zz.180 dns2\u003dmm.nn.oo.171","enableHA":fal
>> se,"limitCpuUse":false,"enableDynamicallyScaleVm":false,,"params":{},"uuid":"b6119681-e6da-4617-a2dd-504e5f82fe4a","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0c3
>> d902f-8840-41d7-8c87-df860ea6ffcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"587027e4-e766-30fa-8972-d8ed9515170b","id":13,"poolType":"SMB","
>> host":"xx.yy.zz.223","path":"/primary","port":445,"url":"SMB://xx.yy.zz.223/primary/?ROLE\u003dPrimary\u0026STOREUUID\u003d587027e4-e766-30fa-8972-d8ed9515170b"}},"name":"ROOT-1241","size":0,"pat
>> h":"0c3d902f-8840-41d7-8c87-df860ea6ffcd","volumeId":1075,"vmName":"v-1241-VM","accountId":1,"format":"VHD","provisioningType":"THIN","id":1075,"deviceId":0,"hypervisorType":"Hyperv"}},"diskSeq":
>> 0,"path":"0c3d902f-8840-41d7-8c87-df860ea6ffcd","type":"ROOT","_details":{"managed":"false","storagePort":"445","storageHost":"xx.yy.zz.223","volumeSize":"0"}}],"nics":[{"deviceId":2,"networkRate
>> Mbps":-1,"defaultNic":true,"pxeDisable":true,"nicUuid":"42a9765e-b84f-4199-9446-145df4bc68de","uuid":"a4a46926-8caf-4bee-b1a0-70529c3ecac6","ip":"aa.bb.cc.138","netmask":"255.255.255.0","gatewa
>> y":"aa.bb.cc.10","mac":"06:4d:90:00:00:0d","dns1":"xx.yy.zz.180","dns2":"mm.nn.oo.171","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSecurityGroupEnabled":false
>> ,"name":"Virtual
>> Switch"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"1cba88d1-5867-4073-a2fd-c8139a8a5a1a","uuid":"e548abca-23da-4568-96e4-3a6aa709566b","ip":"169.254.2.35","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:02:23","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"bb80257d-1578-4643-95b7-63a72f80703a","uuid":"d149dd9f-ac98-411d-9fb0-e587852a9df1","ip":"xx.yy.zz.163","netmask":"255.255.255.0","gateway":"xx.yy.zz.10","mac":"06:0c:48:00:00:3e","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtual
>> Switch"}]},"result":false,"details":"com.cloud.agent.api.StartCommand
>> fail on exceptionObject reference not set to an instance of an
>> object.","contextMap":{},"wait":0}}]
>> .
>> .
>> .
>> 2015-09-17 04:45:07,844 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
>> (DirectAgent-295:ctx-f5578a04) (logid:d11afe7a) executeRequest
>> received response [{"com.cloud.agent.api.StartAnswer":{"vm":{"
>> id":1241,"name":"v-1241-VM","type":"ConsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
>> GNU/Linux 7(64-bit)","bootArgs":"
>> template\u003ddomP type\u003dconsoleproxy host\u003d172.16.116.219
>> port\u003d8250 name\u003dv-1241-VM zone\u003d9 pod\u003d9
>> guid\u003dProxy.1241 proxy_vm\u003d1241 disable_rp_filter\u003dtrue
>> vmpassword\u003dtCUAMd6x eth2ip\u003daa.bb.cc.138
>> eth2mask\u003d255.255.255.0 gateway\u003daa.bb.cc.10
>> eth0ip\u003d169.254.2.35 eth0mask\u003d255.255.0.0
>> eth1ip\u003dxx.yy.zz.163 eth1mask\u003d255.255.255.0
>> mgmtcidr\u003d172.16.116.0/23 localgw\u003dxx.yy.zz.10
>> internaldns1\u003dxx.yy.zz.180 internaldns2\u003dmm.nn.oo.171
>> dns1\u003dxx.yy.zz.180
>> dns2\u003dmm.nn.oo.171","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,,"params":{},"uuid":"b6119681-e6da-4617-a2dd-504e5f82fe4a","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0c3d902f-8840-41d7-8c87-df860ea6ffcd","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"587027e4-e766-30fa-8972-d8ed9515170b","id":13,"poolType":"SMB","host":"xx.yy.zz.223","path":"/primary","port":445,"url":"SMB://xx.yy.zz.223/primary/?ROLE\u003dPrimary\u0026STOREUUID\u003d587027e4-e766-30fa-8972-d8ed9515170b"}},"name":"ROOT-1241","size":0,"path":"0c3d902f-8840-41d7-8c87-df860ea6ffcd","volumeId":1075,"vmName":"v-124VM","accountId":1,"format":"VHD","provisioningType":"THIN","id":1075,"deviceId":0,"hypervisorType":"Hyperv"}},"diskSeq":
>> 0,"path":"0c3d902f-8840-41d7-8c87-df860ea6ffcd","type":"ROOT","_details":{"managed":"false","storagePort":"445","storageHost":"xx.yy.zz.223","volumeSize":"0"}}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"pxeDisable":true,"nicUuid":"42a9765e-b84f-4199-9446-145df4bc68de","uuid":"a4a46926-8caf-4bee-b1a0-70529c3ecac6","ip":"aa.bb.cc.138","netmask":"255.255.255.0","gateway":"aa.bb.cc.10","mac":"06:4d:90:00:00:0d","dns1":"xx.yy.zz.180","dns2":"mm.nn.oo.171","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSecurityGroupEnabled":false,"name":"Virtual
>> Switch"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"1cba88d1-5867-4073-a2fd-c8139a8a5a1a","uuid":"e548abca-23da-4568-96e4-3a6aa709566b","ip":"169.254.2.35","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:02:23","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"bb80257d-1578-4643-95b7-63a72f80703a","uuid":"d149dd9f-ac98-411d-9fb0-e587852a9df1","ip":"xx.yy.zz.163","netmask":"255.255.255.0","gateway":"xx.yy.zz.10","mac":"06:0c:48:00:00:3e","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtual
>> Switch"}]},"result":false,"details":"com.cloud.agent.api.StartCommand
>> fail on exceptionObject reference not set to an instance of an
>> object.","contextMap":{},"wait":0}}]
>> .
>> .
>> .
>> 2015-09-17 04:45:07,888 INFO [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-57:ctx-fb0c16f6 job-126/job-7169 ctx-d0465230)
>> (logid:d11afe7a) Unable to start VM on Host[-94-Routing] due to
>> com.cloud.agent.api.StartCommand fail on exceptionObject reference not
>> set to an instance of an object.
>> --- <end of sample> ---
>
- System
- Provider
[ Name] CloudStack Hyper-V Agent
- EventID 0
[ Qualifiers] 0
Level 2
Task 0
Keywords 0x80000000000000
- TimeCreated
[ SystemTime] 2015-09-18T07:53:38.000000000Z
EventRecordID 368928
Channel Application
Computer KWTPRDBHVNODE2.mha.local
Security
- EventData
2015-09-18 10:53:38,115 [10] ERROR HypervResource.HypervResourceController
[c8f0f531-ad19-462e-8c7b-49c875b01bf1] - com.cloud.agent.api.StartCommand fail
on exceptionObject reference not set to an instance of an object.
System.NullReferenceException: Object reference not set to an instance of an
object. at HypervResource.WmiCallsV2.DeployVirtualMachine(Object jsonObj,
String systemVmIso) at CallSite.Target(Closure , CallSite , IWmiCallsV2 ,
Object , String ) at
HypervResource.HypervResourceController.StartCommand(Object cmd)
