You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Abhinav Roy (JIRA)" <ji...@apache.org> on 2013/12/13 11:35:10 UTC

[jira] [Commented] (CLOUDSTACK-5365) [Hyper-V] VR's control IP is not accessible from mgmt server, which results in VR start up failure

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-5365?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13847369#comment-13847369 ] 

Abhinav Roy commented on CLOUDSTACK-5365:
-----------------------------------------

Hi,

Even i am observing the same issue on my setup 


2013-12-13 15:03:21,879 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) POST response is[{"com.cloud.agent.api.StartAnswer":{"result":true,"details":null,"vm":{"id":15,"name":"r-15-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-15-VM eth2ip=10.102.196.206 eth2mask=255.255.255.0 gateway=10.102.196.1 eth0ip=10.1.1.1 eth0mask=255.255.255.0 domain=cs2cloud.internal dhcprange=10.1.1.1 eth1ip=10.102.195.19 eth1mask=255.255.252.0 type=router disable_rp_filter=true dns1=10.140.50.5","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"154ebf23e6245b22","params":{},"uuid":"baf29258-811d-4c40-bcdf-00cf9dd34d84","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"61917f42-08bd-4ed2-8da3-1ead1ea06d41","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ce50406b-9038-37ba-9b72-6228d5eb0858","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.19","path":"/HYPERV-SMB/abhinav-hyperv-ps1?user=abhinav&password=freebsd@123&domain=BLR","port":445,"url":"NetworkFilesystem://10.102.192.19//HYPERV-SMB/abhinav-hyperv-ps1?user=abhinav&password=freebsd@123&domain=BLR/?ROLE=Primary&STOREUUID=ce50406b-9038-37ba-9b72-6228d5eb0858"}},"name":"ROOT-15","size":2626564608,"volumeId":15,"vmName":"r-15-VM","accountId":2,"id":15,"deviceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"type":"ROOT","_details":{"managed":"false","storagePort":"445","storageHost":"10.102.192.19","volumeSize":"2626564608"}}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"d3570ce8-8d36-4d29-b456-754ddb6e3ec9","ip":"10.102.196.206","netmask":"255.255.255.0","gateway":"10.102.196.1","mac":"06:76:5c:00:00:1c","dns1":"10.140.50.5","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://100","isolationUri":"vlan://100","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"34596cad-7639-4c33-90b7-77fd15552809","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:34:fe:00:02","dns1":"10.140.50.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://696","isolationUri":"vlan://696","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"a26185c9-01ed-4ff8-bd74-fba05b694cc0","ip":"10.102.195.19","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"02:00:59:9c:00:01","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false}]},"contextMap":{}}}]
2013-12-13 15:03:21,881 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) executeRequest received response [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":15,"name":"r-15-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\u003ddomP name\u003dr-15-VM eth2ip\u003d10.102.196.206 eth2mask\u003d255.255.255.0 gateway\u003d10.102.196.1 eth0ip\u003d10.1.1.1 eth0mask\u003d255.255.255.0 domain\u003dcs2cloud.internal dhcprange\u003d10.1.1.1 eth1ip\u003d10.102.195.19 eth1mask\u003d255.255.252.0 type\u003drouter disable_rp_filter\u003dtrue dns1\u003d10.140.50.5","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"154ebf23e6245b22","params":{},"uuid":"baf29258-811d-4c40-bcdf-00cf9dd34d84","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"61917f42-08bd-4ed2-8da3-1ead1ea06d41","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ce50406b-9038-37ba-9b72-6228d5eb0858","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.19","path":"/HYPERV-SMB/abhinav-hyperv-ps1?user\u003dabhinav\u0026password\u003dfreebsd@123\u0026domain\u003dBLR","port":445,"url":"NetworkFilesystem://10.102.192.19//HYPERV-SMB/abhinav-hyperv-ps1?user\u003dabhinav\u0026password\u003dfreebsd@123\u0026domain\u003dBLR/?ROLE\u003dPrimary\u0026STOREUUID\u003dce50406b-9038-37ba-9b72-6228d5eb0858"}},"name":"ROOT-15","size":2626564608,"volumeId":15,"vmName":"r-15-VM","accountId":2,"id":15,"deviceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"type":"ROOT","_details":{"managed":"false","storagePort":"445","storageHost":"10.102.192.19","volumeSize":"2626564608"}}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"d3570ce8-8d36-4d29-b456-754ddb6e3ec9","ip":"10.102.196.206","netmask":"255.255.255.0","gateway":"10.102.196.1","mac":"06:76:5c:00:00:1c","dns1":"10.140.50.5","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://100","isolationUri":"vlan://100","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"34596cad-7639-4c33-90b7-77fd15552809","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:34:fe:00:02","dns1":"10.140.50.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://696","isolationUri":"vlan://696","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"a26185c9-01ed-4ff8-bd74-fba05b694cc0","ip":"10.102.195.19","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"02:00:59:9c:00:01","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"contextMap":{},"wait":0}}]
2013-12-13 15:03:21,881 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Ping command port, 10.102.195.19:3922
2013-12-13 15:03:21,881 INFO  [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Trying to connect to 10.102.195.19
2013-12-13 15:03:21,882 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Ping command port succeeded for vm r-15-VM
2013-12-13 15:03:21,882 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Execute network usage setup command on r-15-VM
2013-12-13 15:03:22,194 ERROR [c.c.u.s.SshHelper] (DirectAgent-44:ctx-10c74c4e) Failed to authentication SSH user root on host 10.102.195.19
2013-12-13 15:03:22,197 ERROR [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Unable to execute NetworkUsage command on DomR (10.102.195.19), domR may not be ready yet. failure due to java.lang.Exception: Failed to authentication SSH user root on host 10.102.195.19
2013-12-13 15:03:22,197 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Executing resource GetDomRVersionCmd: {"accessDetails":{"router.ip":"10.102.195.19","router.name":"r-15-VM"},"contextMap":{},"wait":0}
2013-12-13 15:03:22,197 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Run command on domR 10.102.195.19, /opt/cloud/bin/get_template_version.sh
2013-12-13 15:03:22,197 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) Use router's private IP for SSH control. IP : 10.102.195.19
2013-12-13 15:03:22,250 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 2-284: Processing Seq 2-284:  { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":13,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
2013-12-13 15:03:22,253 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 2-284: Sending Seq 2-284:  { Ans: , MgmtId: 280320865129348, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-12-13 15:03:22,411 ERROR [c.c.u.s.SshHelper] (DirectAgent-44:ctx-10c74c4e) Failed to authentication SSH user root on host 10.102.195.19
2013-12-13 15:03:22,412 ERROR [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-44:ctx-10c74c4e) GetDomRVersionCmd failed due to java.lang.Exception: Failed to authentication SSH user root on host 10.102.195.19
java.lang.Exception: Failed to authentication SSH user root on host 10.102.195.19
        at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:144)
        at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
        at com.cloud.hypervisor.hyperv.resource.HypervDirectConnectResource.execute(HypervDirectConnectResource.java:1435)
        at com.cloud.hypervisor.hyperv.resource.HypervDirectConnectResource.executeRequest(HypervDirectConnectResource.java:391)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-12-13 15:03:22,416 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-44:ctx-10c74c4e) Seq 1-306184271: Cancelling because one of the answers is false and it is stop on error.
2013-12-13 15:03:22,416 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-44:ctx-10c74c4e) Seq 1-306184271: Response Received:
2013-12-13 15:03:22,418 DEBUG [c.c.a.t.Request] (DirectAgent-44:ctx-10c74c4e) Seq 1-306184271: Processing:  { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":15,"name":"r-15-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-15-VM eth2ip=10.102.196.206 eth2mask=255.255.255.0 gateway=10.102.196.1 eth0ip=10.1.1.1 eth0mask=255.255.255.0 domain=cs2cloud.internal dhcprange=10.1.1.1 eth1ip=10.102.195.19 eth1mask=255.255.252.0 type=router disable_rp_filter=true dns1=10.140.50.5","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"154ebf23e6245b22","params":{},"uuid":"baf29258-811d-4c40-bcdf-00cf9dd34d84","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"61917f42-08bd-4ed2-8da3-1ead1ea06d41","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ce50406b-9038-37ba-9b72-6228d5eb0858","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.19","path":"/HYPERV-SMB/abhinav-hyperv-ps1?user=abhinav&password=freebsd@123&domain=BLR","port":445,"url":"NetworkFilesystem://10.102.192.19//HYPERV-SMB/abhinav-hyperv-ps1?user=abhinav&password=freebsd@123&domain=BLR/?ROLE=Primary&STOREUUID=ce50406b-9038-37ba-9b72-6228d5eb0858"}},"name":"ROOT-15","size":2626564608,"volumeId":15,"vmName":"r-15-VM","accountId":2,"id":15,"deviceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"type":"ROOT","_details":{"managed":"false","storagePort":"445","storageHost":"10.102.192.19","volumeSize":"2626564608"}}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"d3570ce8-8d36-4d29-b456-754ddb6e3ec9","ip":"10.102.196.206","netmask":"255.255.255.0","gateway":"10.102.196.1","mac":"06:76:5c:00:00:1c","dns1":"10.140.50.5","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://100","isolationUri":"vlan://100","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"34596cad-7639-4c33-90b7-77fd15552809","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:34:fe:00:02","dns1":"10.140.50.5","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://696","isolationUri":"vlan://696","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"a26185c9-01ed-4ff8-bd74-fba05b694cc0","ip":"10.102.195.19","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"02:00:59:9c: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.lang.Exception: Failed to authentication SSH user root on host 10.102.195.19","wait":0}}] }
2013-12-13 15:03:22,418 DEBUG [c.c.a.t.Request] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Seq 1-306184271: Received:  { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer, GetDomRVersionAnswer } }
2013-12-13 15:03:22,427 WARN  [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Unable to get the template/scripts version of router r-15-VM due to: GetDomRVersionCmd failed due to java.lang.Exception: Failed to authentication SSH user root on host 10.102.195.19
2013-12-13 15:03:22,427 INFO  [c.c.v.VirtualMachineManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) The guru did not like the answers so stopping VM[DomainRouter|r-15-VM]
2013-12-13 15:03:22,431 DEBUG [c.c.a.t.Request] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Seq 1-306184281: Sending  { Cmd , MgmtId: 280320865129348, via: 1(10.102.192.9), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","wait":0}}] }
2013-12-13 15:03:22,431 DEBUG [c.c.a.t.Request] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Seq 1-306184281: Executing:  { Cmd , MgmtId: 280320865129348, via: 1(10.102.192.9), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","wait":0}}] }
2013-12-13 15:03:22,431 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-22:ctx-94dd5f2e) Seq 1-306184281: Executing request
2013-12-13 15:03:22,431 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-22:ctx-94dd5f2e) POST request tohttp://10.102.192.9:8250/api/HypervResource/com.cloud.agent.api.StopCommand with contents{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","contextMap":{},"wait":0}
2013-12-13 15:03:22,431 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-22:ctx-94dd5f2e) Sending cmd to http://10.102.192.9:8250/api/HypervResource/com.cloud.agent.api.StopCommand cmd data:{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","contextMap":{},"wait":0}
2013-12-13 15:03:22,927 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-bf199202) ===START===  10.144.7.10 -- GET  command=queryAsyncJobResult&jobId=a4140db4-c197-4678-a042-1915b13a29a9&response=json&sessionkey=gG8A1x%2FEbF0XgDyPwWA6vln3S5Q%3D&_=1386927507533
2013-12-13 15:03:22,940 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-bf199202 ctx-a8013811) ===END===  10.144.7.10 -- GET  command=queryAsyncJobResult&jobId=a4140db4-c197-4678-a042-1915b13a29a9&response=json&sessionkey=gG8A1x%2FEbF0XgDyPwWA6vln3S5Q%3D&_=1386927507533
2013-12-13 15:03:24,628 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-22:ctx-94dd5f2e) POST response is[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"contextMap":{}}}]
2013-12-13 15:03:24,629 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-22:ctx-94dd5f2e) executeRequest received response [{"com.cloud.agent.api.StopAnswer":{"result":true,"contextMap":{},"wait":0}}]
2013-12-13 15:03:24,629 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-22:ctx-94dd5f2e) Seq 1-306184281: Response Received:
2013-12-13 15:03:24,629 DEBUG [c.c.a.t.Request] (DirectAgent-22:ctx-94dd5f2e) Seq 1-306184281: Processing:  { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2013-12-13 15:03:24,629 DEBUG [c.c.a.t.Request] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Seq 1-306184281: Received:  { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1, Flags: 10, { StopAnswer } }
2013-12-13 15:03:24,629 ERROR [c.c.v.VirtualMachineManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Failed to start instance VM[DomainRouter|r-15-VM]
com.cloud.utils.exception.ExecutionException: Unable to start VM[DomainRouter|r-15-VM] due to error in finalizeStart, not retrying
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:979)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:707)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2667)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1767)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1867)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1845)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy240.deployVirtualRouterInGuestNetwork(Unknown Source)
        at com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:188)
        at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetworkElementsAndResources(NetworkOrchestrator.java:1053)
        at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:960)
        at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1221)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:900)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:707)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:553)
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:228)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3559)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3140)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3126)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy171.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
        at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
        at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
        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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:521)
        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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-12-13 15:03:24,640 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Cleaning up resources for the vm VM[DomainRouter|r-15-VM] in Starting state
2013-12-13 15:03:24,642 DEBUG [c.c.a.t.Request] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Seq 1-306184282: Sending  { Cmd , MgmtId: 280320865129348, via: 1(10.102.192.9), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","wait":0}}] }
2013-12-13 15:03:24,642 DEBUG [c.c.a.t.Request] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Seq 1-306184282: Executing:  { Cmd , MgmtId: 280320865129348, via: 1(10.102.192.9), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","wait":0}}] }
2013-12-13 15:03:24,642 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-49:ctx-d108143d) Seq 1-306184282: Executing request
2013-12-13 15:03:24,642 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-49:ctx-d108143d) POST request tohttp://10.102.192.9:8250/api/HypervResource/com.cloud.agent.api.StopCommand with contents{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","contextMap":{},"wait":0}
2013-12-13 15:03:24,642 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-49:ctx-d108143d) Sending cmd to http://10.102.192.9:8250/api/HypervResource/com.cloud.agent.api.StopCommand cmd data:{"isProxy":false,"executeInSequence":false,"vmName":"r-15-VM","contextMap":{},"wait":0}
2013-12-13 15:03:24,658 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-49:ctx-d108143d) POST response is[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"contextMap":{}}}]
2013-12-13 15:03:24,659 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-49:ctx-d108143d) executeRequest received response [{"com.cloud.agent.api.StopAnswer":{"result":true,"contextMap":{},"wait":0}}]
2013-12-13 15:03:24,659 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-49:ctx-d108143d) Seq 1-306184282: Response Received:
2013-12-13 15:03:24,659 DEBUG [c.c.a.t.Request] (DirectAgent-49:ctx-d108143d) Seq 1-306184282: Processing:  { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2013-12-13 15:03:24,659 DEBUG [c.c.a.t.Request] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Seq 1-306184282: Received:  { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1, Flags: 10, { StopAnswer } }
2013-12-13 15:03:24,669 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Successfully updated user statistics as a part of domR VM[DomainRouter|r-15-VM] reboot/stop
2013-12-13 15:03:24,682 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Service SecurityGroup is not supported in the network id=204
2013-12-13 15:03:24,690 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Asking VirtualRouter to release NicProfile[52-15-3104ebcc-2d81-404e-b9fb-065a212c842a-10.1.1.1-null
2013-12-13 15:03:24,693 DEBUG [c.c.n.g.ControlNetworkGuru] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Released nic: NicProfile[53-15-null-null-null
2013-12-13 15:03:24,718 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Successfully released network resources for the vm VM[DomainRouter|r-15-VM]
2013-12-13 15:03:24,718 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Successfully cleanued up resources for the vm VM[DomainRouter|r-15-VM] in Starting state
2013-12-13 15:03:24,726 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) 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-13 15:03:24,733 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Hosts's actual total CPU: 9576 and CPU after applying overprovisioning: 9576
2013-12-13 15:03:24,733 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Hosts's actual total RAM: 17166323712 and RAM after applying overprovisioning: 17166323712
2013-12-13 15:03:24,733 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) release cpu from host: 1, old used: 2000,reserved: 0, actual total: 9576, total with overprovisioning: 9576; new used: 1500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-13 15:03:24,733 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) release mem from host: 1, old used: 2013265920,reserved: 0, total: 17166323712; new used: 1879048192,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-12-13 15:03:24,737 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Cleaning up because we're unable to implement the network Ntwk[204|Guest|8]
2013-12-13 15:03:24,742 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Lock is acquired for network Ntwk[204|Guest|8] as a part of network shutdown
2013-12-13 15:03:24,746 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Releasing 0 port forwarding rules for network id=204 as a part of shutdownNetworkRules
2013-12-13 15:03:24,747 DEBUG [c.c.n.f.FirewallManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) There are no rules to forward to the network elements
2013-12-13 15:03:24,748 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Releasing 0 static nat rules for network id=204 as a part of shutdownNetworkRules
2013-12-13 15:03:24,748 DEBUG [c.c.n.f.FirewallManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) There are no rules to forward to the network elements
2013-12-13 15:03:24,749 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Revoking 0 Public load balancing rules for network id=204
2013-12-13 15:03:24,749 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) There are no Load Balancing Rules to forward to the network elements
2013-12-13 15:03:24,750 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Revoking 0 Internal load balancing rules for network id=204
2013-12-13 15:03:24,751 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) There are no Load Balancing Rules to forward to the network elements
2013-12-13 15:03:24,751 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Releasing 0 firewall ingress rules for network id=204 as a part of shutdownNetworkRules
2013-12-13 15:03:24,752 DEBUG [c.c.n.f.FirewallManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) There are no rules to forward to the network elements
2013-12-13 15:03:24,752 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Releasing 0 firewall egress rules for network id=204 as a part of shutdownNetworkRules
2013-12-13 15:03:24,756 DEBUG [c.c.n.f.FirewallManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) applying default firewall egress rules
2013-12-13 15:03:24,770 DEBUG [c.c.n.f.FirewallManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) There are no rules to forward to the network elements
2013-12-13 15:03:24,772 DEBUG [c.c.n.r.RulesManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Found 0 static nat rules to apply for network id 204
2013-12-13 15:03:24,801 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Router r-15-VM is in Stopped, so not sending apply ip association commands to the backend
2013-12-13 15:03:24,810 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Sending network shutdown to VirtualRouter
2013-12-13 15:03:24,813 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Stopping router VM[DomainRouter|r-15-VM]
2013-12-13 15:03:24,816 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) VM is already stopped: VM[DomainRouter|r-15-VM]
2013-12-13 15:03:24,818 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Network id=204 is shutdown successfully, cleaning up corresponding resources now.
2013-12-13 15:03:24,820 DEBUG [c.c.n.g.GuestNetworkGuru] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Releasing vnet for the network id=204
2013-12-13 15:03:24,827 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Lock is released for network Ntwk[204|Guest|8] as a part of network shutdown
2013-12-13 15:03:24,828 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Lock is released for network id 204 as a part of network implement
2013-12-13 15:03:24,828 INFO  [c.c.v.VirtualMachineManagerImpl] (Job-Executor-3:ctx-c3106a9b ctx-9286f0a4) Unable to contact resource.
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to start VM[DomainRouter|r-15-VM] due to error in finalizeStart, not retrying
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1012)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:707)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2667)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1767)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1867)
        at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1845)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy240.deployVirtualRouterInGuestNetwork(Unknown Source)
        at com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:188)
        at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetworkElementsAndResources(NetworkOrchestrator.java:1053)
        at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:960)
        at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1221)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:900)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:707)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:553)
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:228)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3559)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3140)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3126)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy171.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
        at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
        at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
        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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:521)
        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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
Caused by: com.cloud.utils.exception.ExecutionException: Unable to start VM[DomainRouter|r-15-VM] due to error in finalizeStart, not retrying
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:979)
        ... 61 more



Setup Details :

MS : 10.102.192.125 < root : freebsd >
Host : 10.102.192.9 < BLR\abhinav : freebsd@123>



> [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)