[ https://issues.apache.org/jira/browse/CLOUDSTACK-5365?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sanjeev N closed CLOUDSTACK-5365. --------------------------------- Verified with latest build from 4.3 with commit 197ef921f7b3c80998359f376fe045b13558633c. Now route to management server cidr is present on the VR. > [Hyper-V] VR's control IP is not accessible from mgmt server, which results > in VR start up failure > -------------------------------------------------------------------------------------------------- > > Key: CLOUDSTACK-5365 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5365 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Hypervisor Controller, Management Server > Affects Versions: 4.3.0 > Environment: Build with commit > 2d90ee469a047e8b42dd81f3723240f18b591d5e from 4.3 > Zone: Advanced > Storage: Local for system vms ,cifs for guest and cifs for secondary > Hypervisor: Hyperv > Reporter: Sanjeev N > Assignee: Rajesh Battala > Priority: Blocker > Labels: hyper-V, > Fix For: 4.3.0 > > Attachments: cloud.dmp, cloudstack-agent.rar, management-server.rar > > > [Hyper-V] VR's control IP is not accessible from mgmt server, which results > in VR start up failure > Steps to Reproduce: > ================ > 1.Bring up CS in advanced zone with at-least one hyper-v host in the cluster > 2.Register one cent os template > 3.Try to deploy guest vm with the above template in an isolated network > Expected Result: > ============== > VR and guest vm should come up in the isolated network successfully > Actual Result: > =========== > VR failed to come up hence the guest vm deployment failed > Observations: > ============ > Initially VR booted up and configured with guest,control and public IP > addresses on eth0,eth1,eth2 inerfaces respectively. > As part of VR bring up process, mgmt server tried to ping/check the template > version on VR using its control IP to confirm the VR boot up. However mgmt > server failed to communicate with VRs control IP address. So it is stopping > the VR. > In another 4.3 setup I have added vmware cluster and tried the above > scenario. There mgmt server was able to communicate with VR on control ip > address and VR came up successfully. > Log snippet from agent log: > ====================== > 2013-12-04 04:14:54,275 [14] INFO HypervResource.WmiCallsV2 > [fcfffec6-3b06-4bda-b22c-afa6c2014803] - Started VM r-8-VM > 2013-12-04 04:14:54,275 [14] INFO HypervResource.HypervResourceController > [fcfffec6-3b06-4bda-b22c-afa6c2014803] - { > "com.cloud.agent.api.StartAnswer": { > "result": true, > "details": null, > "vm": { > "id": 8, > "name": "r-8-VM", > "type": "DomainRouter", > "cpus": 1, > "minSpeed": 500, > "maxSpeed": 500, > "minRam": 134217728, > "maxRam": 134217728, > "arch": "i686", > "os": "Debian GNU/Linux 5.0 (32-bit)", > "bootArgs": " template=domP name=r-8-VM eth2ip=10.147.48.23 > eth2mask=255.255.255.0 gateway=10.147.48.1 eth0ip=10.1.1.1 > eth0mask=255.255.255.0 domain=cs2cloud.internal dhcprange=10.1.1.1 > eth1ip=10.147.40.238 eth1mask=255.255.254.0 type=router > disable_rp_filter=true dns1=10.140.50.6 dns2=", > "rebootOnCrash": false, > "enableHA": true, > "limitCpuUse": false, > "enableDynamicallyScaleVm": false, > "vncPassword": "33c76dca072011e6", > "params": {}, > "uuid": "33b6472e-67cd-4aee-8556-b22d6e57d44b", > "disks": [ > { > "data": { > "org.apache.cloudstack.storage.to.VolumeObjectTO": { > "uuid": "9c48b406-b424-4b77-ae37-37248b454d0f", > "volumeType": "ROOT", > "dataStore": { > "org.apache.cloudstack.storage.to.PrimaryDataStoreTO": { > "uuid": > "20de3206-3585-3bb0-b536-a96b665df206-HypervResource", > "id": 2, > "poolType": "Filesystem", > "host": "10.147.40.14", > "path": "C:\\Users\\Public\\Documents\\Hyper-V\\Virtual > Hard Disks", > "port": 0, > "url": > "Filesystem://10.147.40.14/C:\\Users\\Public\\Documents\\Hyper-V\\Virtual > Hard > Disks/?ROLE=Primary&STOREUUID=20de3206-3585-3bb0-b536-a96b665df206-HypervResource" > } > }, > "name": "ROOT-8", > "size": 2101252608, > "volumeId": 8, > "vmName": "r-8-VM", > "accountId": 2, > "id": 8, > "deviceId": 0, > "hypervisorType": "Hyperv" > } > }, > "diskSeq": 0, > "type": "ROOT", > "_details": { > "managed": "false", > "storagePort": "0", > "storageHost": "10.147.40.14", > "volumeSize": "2101252608" > } > } > ], > "nics": [ > { > "deviceId": 2, > "networkRateMbps": 200, > "defaultNic": true, > "uuid": "645d73f8-ea2b-4329-9946-140c12059805", > "ip": "10.147.48.23", > "netmask": "255.255.255.0", > "gateway": "10.147.48.1", > "mac": "06:7d:94:00:00:0d", > "dns1": "10.140.50.6", > "dns2": "", > "broadcastType": "Vlan", > "type": "Public", > "broadcastUri": "vlan://48", > "isolationUri": "vlan://48", > "isSecurityGroupEnabled": false > }, > { > "deviceId": 0, > "networkRateMbps": 200, > "defaultNic": false, > "uuid": "223b14fa-88b5-4ed0-a804-d428d98205e0", > "ip": "10.1.1.1", > "netmask": "255.255.255.0", > "mac": "02:00:10:99:00:02", > "dns1": "10.140.50.6", > "dns2": "", > "broadcastType": "Vlan", > "type": "Guest", > "broadcastUri": "vlan://994", > "isolationUri": "vlan://994", > "isSecurityGroupEnabled": false > }, > { > "deviceId": 1, > "networkRateMbps": -1, > "defaultNic": false, > "uuid": "80c827a3-4b5e-41eb-97f1-c829d2eff69a", > "ip": "10.147.40.238", > "netmask": "255.255.254.0", > "gateway": "10.147.40.1", > "mac": "02:00:6c:37:00:02", > "broadcastType": "Native", > "type": "Control", > "isSecurityGroupEnabled": false > } > ] > }, > "contextMap": {} > } > } > 2013-12-04 04:16:54,359 [28] DEBUG HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - Got request to destroy vm r-8-VM > 2013-12-04 04:16:54,370 [28] DEBUG HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - Stop VM r-8-VM (GUID > ED52939F-C0A0-4F30-954C-4EAE2A2F2B21) > 2013-12-04 04:16:54,370 [28] INFO HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - Changing state of r-8-VM (GUID > ED52939F-C0A0-4F30-954C-4EAE2A2F2B21) to Disabled > 2013-12-04 04:16:54,420 [28] INFO HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - In progress... 0% completed. > 2013-12-04 04:16:55,428 [28] DEBUG HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - WMI job succeeded: Turning Off > Virtual Machine, Elapsed=00:00:00.1168150 > 2013-12-04 04:16:55,428 [28] INFO HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - Successfully changed vm state of > r-8-VM (GUID ED52939F-C0A0-4F30-954C-4EAE2A2F2B21 to requested state 3 > 2013-12-04 04:16:55,429 [28] DEBUG HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - Remove associated switch ports for > VM r-8-VM (GUID ED52939F-C0A0-4F30-954C-4EAE2A2F2B21) > 2013-12-04 04:16:55,452 [28] DEBUG HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - Delete VM r-8-VM (GUID > ED52939F-C0A0-4F30-954C-4EAE2A2F2B21) > 2013-12-04 04:16:55,498 [28] INFO HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - In progress... 0% completed. > 2013-12-04 04:16:56,505 [28] DEBUG HypervResource.WmiCallsV2 > [60be431f-50c8-4b52-a490-aba947e0f9a7] - WMI job succeeded: Destroying > Virtual Machine, Elapsed=00:00:00.0334240 > 2013-12-04 04:16:56,512 [28] INFO HypervResource.HypervResourceController > [60be431f-50c8-4b52-a490-aba947e0f9a7] - { > "com.cloud.agent.api.StopAnswer": { > "result": true, > "details": null, > "vm": null, > "contextMap": {} > } > } > 2013-12-04 04:16:56,540 [27] INFO HypervResource.HypervResourceController > [d0d8d414-b428-4d2d-8ccb-377792569698] - com.cloud.agent.api.StopCommand{ > "isProxy": false, > "executeInSequence": false, > "vmName": "r-8-VM", > "contextMap": {}, > "wait": 0 > } > 2013-12-04 04:16:56,541 [27] DEBUG HypervResource.WmiCallsV2 > [d0d8d414-b428-4d2d-8ccb-377792569698] - Got request to destroy vm r-8-VM > 2013-12-04 04:16:56,548 [27] DEBUG HypervResource.WmiCallsV2 > [d0d8d414-b428-4d2d-8ccb-377792569698] - VM r-8-VM already destroyed (or > never existed) > 2013-12-04 04:16:56,549 [27] INFO HypervResource.HypervResourceController > [d0d8d414-b428-4d2d-8ccb-377792569698] - { > "com.cloud.agent.api.StopAnswer": { > "result": true, > "details": null, > "vm": null, > "contextMap": {} > } > } > Log snippet from mgmt server log file: > 2013-12-04 12:24:03,005 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-15:ctx-3c4633d8) Run command on domR 10.147.40.232, > /opt/cloud/bin/get_template_version.sh > 2013-12-04 12:24:03,005 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-15:ctx-3c4633d8) Use router's private IP for SSH control. IP : > 10.147.40.232 > 2013-12-04 12:24:03,681 DEBUG [c.c.a.ApiServlet] > (catalina-exec-2:ctx-a42794db) ===START=== 10.146.0.134 -- GET > command=queryAsyncJobResult&jobId=90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=json&sessionkey=uSpuIkackMpvWLrjIHS842Q1v4o%3D&_=1386158175162 > 2013-12-04 12:24:03,744 DEBUG [c.c.s.StatsCollector] > (StatsCollector-3:ctx-c350b288) VmStatsCollector is running... > 2013-12-04 12:24:03,797 DEBUG [c.c.a.ApiServlet] > (catalina-exec-2:ctx-a42794db ctx-e6c815dc) ===END=== 10.146.0.134 -- GET > command=queryAsyncJobResult&jobId=90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=json&sessionkey=uSpuIkackMpvWLrjIHS842Q1v4o%3D&_=1386158175162 > 2013-12-04 12:25:03,008 ERROR [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-15:ctx-3c4633d8) GetDomRVersionCmd failed due to > java.net.SocketTimeoutException: The kexTimeout (60000 ms) expired. > java.net.SocketTimeoutException: The kexTimeout (60000 ms) expired. > at com.trilead.ssh2.Connection.connect(Connection.java:785) > at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:132) > at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37) > at > com.cloud.hypervisor.hyperv.resource.HypervDirectConnectResource.execute(HypervDirectConnectResource.java:1408) > at > com.cloud.hypervisor.hyperv.resource.HypervDirectConnectResource.executeRequest(HypervDirectConnectResource.java:377) > at > com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216) > at > org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53) > at > org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46) > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266) > 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:679) > 2013-12-04 12:25:03,016 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-15:ctx-3c4633d8) Seq 1-1576731025: Cancelling because one of the > answers is false and it is stop on error. > 2013-12-04 12:25:03,016 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-15:ctx-3c4633d8) Seq 1-1576731025: Response Received: > 2013-12-04 12:25:03,018 DEBUG [c.c.a.t.Request] (DirectAgent-15:ctx-3c4633d8) > Seq 1-1576731025: Processing: { Ans: , MgmtId: 7332683579487, via: 1, Ver: > v1, Flags: 10, > [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":8,"name":"r-8-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"i686","os":"Debian > GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-8-VM > eth2ip=10.147.48.23 eth2mask=255.255.255.0 gateway=10.147.48.1 > eth0ip=10.1.1.1 eth0mask=255.255.255.0 domain=cs2cloud.internal > dhcprange=10.1.1.1 eth1ip=10.147.40.232 eth1mask=255.255.254.0 type=router > disable_rp_filter=true dns1=10.140.50.6 > dns2=","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"33c76dca072011e6","params":{},"uuid":"33b6472e-67cd-4aee-8556-b22d6e57d44b","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9c48b406-b424-4b77-ae37-37248b454d0f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"20de3206-3585-3bb0-b536-a96b665df206-HypervResource","id":2,"poolType":"Filesystem","host":"10.147.40.14","path":"C:\\Users\\Public\\Documents\\Hyper-V\\Virtual > Hard > Disks","port":0,"url":"Filesystem://10.147.40.14/C:\\Users\\Public\\Documents\\Hyper-V\\Virtual > Hard > Disks/?ROLE=Primary&STOREUUID=20de3206-3585-3bb0-b536-a96b665df206-HypervResource"}},"name":"ROOT-8","size":2101252608,"volumeId":8,"vmName":"r-8-VM","accountId":2,"id":8,"deviceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"type":"ROOT","_details":{"managed":"false","storagePort":"0","storageHost":"10.147.40.14","volumeSize":"2101252608"}}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"645d73f8-ea2b-4329-9946-140c12059805","ip":"10.147.48.23","netmask":"255.255.255.0","gateway":"10.147.48.1","mac":"06:7d:94:00:00:0d","dns1":"10.140.50.6","dns2":"","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://48","isolationUri":"vlan://48","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"223b14fa-88b5-4ed0-a804-d428d98205e0","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:10:99:00:02","dns1":"10.140.50.6","dns2":"","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://993","isolationUri":"vlan://993","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"80c827a3-4b5e-41eb-97f1-c829d2eff69a","ip":"10.147.40.232","netmask":"255.255.254.0","gateway":"10.147.40.1","mac":"02:00:60:3e:00:01","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"com.cloud.agent.api.check.CheckSshAnswer":{"result":true,"wait":0}},{"com.cloud.agent.api.GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersionCmd > failed due to java.net.SocketTimeoutException: The kexTimeout (60000 ms) > expired.","wait":0}}] } > 2013-12-04 12:25:03,019 DEBUG [c.c.a.t.Request] (Job-Executor-2:ctx-4fc0c5af > ctx-2d3a7128) Seq 1-1576731025: Received: { Ans: , MgmtId: 7332683579487, > via: 1, Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer, > GetDomRVersionAnswer } } > 2013-12-04 12:25:03,064 WARN [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (Job-Executor-2:ctx-4fc0c5af ctx-2d3a7128) Unable to get the template/scripts > version of router r-8-VM due to: GetDomRVersionCmd failed due to > java.net.SocketTimeoutException: The kexTimeout (60000 ms) expired. > 2013-12-04 12:25:03,064 INFO [c.c.v.VirtualMachineManagerImpl] > (Job-Executor-2:ctx-4fc0c5af ctx-2d3a7128) The guru did not like the answers > so stopping VM[DomainRouter|r-8-VM] > 2013-12-04 12:25:03,070 DEBUG [c.c.a.t.Request] (Job-Executor-2:ctx-4fc0c5af > ctx-2d3a7128) Seq 1-1576731041: Sending { Cmd , MgmtId: 7332683579487, via: > 1(10.147.40.14), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-8-VM","wait":0}}] > } > 2013-12-04 12:25:03,070 DEBUG [c.c.a.t.Request] (Job-Executor-2:ctx-4fc0c5af > ctx-2d3a7128) Seq 1-1576731041: Executing: { Cmd , MgmtId: 7332683579487, > via: 1(10.147.40.14), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-8-VM","wait":0}}] > } > 2013-12-04 12:25:03,070 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-229:ctx-3ff22557) Seq 1-1576731041: Executing request > 2013-12-04 12:25:03,071 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-229:ctx-3ff22557) POST request > tohttp://10.147.40.14:8250/api/HypervResource/com.cloud.agent.api.StopCommand > with > contents{"isProxy":false,"executeInSequence":false,"vmName":"r-8-VM","contextMap":{},"wait":0} > 2013-12-04 12:25:03,071 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-229:ctx-3ff22557) Sending cmd to > http://10.147.40.14:8250/api/HypervResource/com.cloud.agent.api.StopCommand > cmd > data:{"isProxy":false,"executeInSequence":false,"vmName":"r-8-VM","contextMap":{},"wait":0} > 2013-12-04 12:25:03,683 DEBUG [c.c.a.ApiServlet] > (catalina-exec-11:ctx-a5bda5fe) ===START=== 10.146.0.134 -- GET > command=queryAsyncJobResult&jobId=90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=json&sessionkey=uSpuIkackMpvWLrjIHS842Q1v4o%3D&_=1386158235163 > 2013-12-04 12:25:03,749 DEBUG [c.c.s.StatsCollector] > (StatsCollector-3:ctx-53e2498d) VmStatsCollector is running... > 2013-12-04 12:25:03,812 DEBUG [c.c.a.ApiServlet] > (catalina-exec-11:ctx-a5bda5fe ctx-c422cb8d) ===END=== 10.146.0.134 -- GET > command=queryAsyncJobResult&jobId=90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=json&sessionkey=uSpuIkackMpvWLrjIHS842Q1v4o%3D&_=1386158235163 > 2013-12-04 12:25:05,243 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-229:ctx-3ff22557) POST response > is[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"contextMap":{}}}] > 2013-12-04 12:25:05,244 DEBUG [c.c.h.h.r.HypervDirectConnectResource] > (DirectAgent-229:ctx-3ff22557) executeRequest received response > [{"com.cloud.agent.api.StopAnswer":{"result":true,"contextMap":{},"wait":0}}] > 2013-12-04 12:25:05,244 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-229:ctx-3ff22557) Seq 1-1576731041: Response Received: > 2013-12-04 12:25:05,244 DEBUG [c.c.a.t.Request] > (DirectAgent-229:ctx-3ff22557) Seq 1-1576731041: Processing: { Ans: , > MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] } > 2013-12-04 12:25:05,244 DEBUG [c.c.a.t.Request] (Job-Executor-2:ctx-4fc0c5af > ctx-2d3a7128) Seq 1-1576731041: Received: { Ans: , MgmtId: 7332683579487, > via: 1, Ver: v1, Flags: 10, { StopAnswer } } > 2013-12-04 12:25:05,245 ERROR [c.c.v.VirtualMachineManagerImpl] > (Job-Executor-2:ctx-4fc0c5af ctx-2d3a7128) Failed to start instance > VM[DomainRouter|r-8-VM] -- This message was sent by Atlassian JIRA (v6.1.4#6159)