Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 7EA7010EC4 for ; Wed, 4 Dec 2013 12:41:21 +0000 (UTC) Received: (qmail 79530 invoked by uid 500); 4 Dec 2013 12:40:57 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 79488 invoked by uid 500); 4 Dec 2013 12:40:54 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 79429 invoked by uid 500); 4 Dec 2013 12:40:39 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 79341 invoked by uid 99); 4 Dec 2013 12:40:35 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 04 Dec 2013 12:40:35 +0000 Date: Wed, 4 Dec 2013 12:40:35 +0000 (UTC) From: "Sanjeev N (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (CLOUDSTACK-5365) [Hyper-V] VR's control IP is not accessible from mgmt server, which results in VR start up failure MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 Sanjeev N created CLOUDSTACK-5365: ------------------------------------- Summary: [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 defa= ult.) Components: Hypervisor Controller, Management Server Affects Versions: 4.3.0 Environment: Build with commit 2d90ee469a047e8b42dd81f3723240f18b5= 91d5e from 4.3 Zone: Advanced Storage: Local for system vms ,cifs for guest and cifs for secondary Hypervisor: Hyperv Reporter: Sanjeev N Priority: Blocker Fix For: 4.3.0 [Hyper-V] VR's control IP is not accessible from mgmt server, which results= in VR start up failure Steps to Reproduce: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 1.Bring up CS in advanced zone with at-least one hyper-v host in the cluste= r 2.Register one cent os template 3.Try to deploy guest vm with the above template in an isolated network Expected Result: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D VR and guest vm should come up in the isolated network successfully Actual Result: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D VR failed to come up hence the guest vm deployment failed Observations: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D Initially VR booted up and configured with guest,control and public IP addr= esses on eth0,eth1,eth2 inerfaces respectively.=20 As part of VR bring up process, mgmt server tried to ping/check the templa= te version on VR using its control IP to confirm the VR boot up. However mg= mt server failed to communicate with VRs control IP address. So it is stopp= ing the VR.=20 In another 4.3 setup I have added vmware cluster and tried the above scenar= io. There mgmt server was able to communicate with VR on control ip address= and VR came up successfully. Log snippet from agent log: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 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=3DdomP name=3Dr-8-VM eth2ip=3D10.147.48.23 eth= 2mask=3D255.255.255.0 gateway=3D10.147.48.1 eth0ip=3D10.1.1.1 eth0mask=3D25= 5.255.255.0 domain=3Dcs2cloud.internal dhcprange=3D10.1.1.1 eth1ip=3D10.147= .40.238 eth1mask=3D255.255.254.0 type=3Drouter disable_rp_filter=3Dtrue dns= 1=3D10.140.50.6 dns2=3D", "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-HypervResou= rce", "id": 2, "poolType": "Filesystem", "host": "10.147.40.14", "path": "C:\\Users\\Public\\Documents\\Hyper-V\\Virtual H= ard Disks", "port": 0, "url": "Filesystem://10.147.40.14/C:\\Users\\Public\\Docu= ments\\Hyper-V\\Virtual Hard Disks/?ROLE=3DPrimary&STOREUUID=3D20de3206-358= 5-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-4EA= E2A2F2B21) 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-4F3= 0-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=3D00: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 ED= 52939F-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 (GU= ID 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-4= EAE2A2F2B21) 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, E= lapsed=3D00: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] (Dire= ctAgent-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] (Dire= ctAgent-15:ctx-3c4633d8) Use router's private IP for SSH control. IP : 10.1= 47.40.232 2013-12-04 12:24:03,681 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-a4279= 4db) =3D=3D=3DSTART=3D=3D=3D 10.146.0.134 -- GET command=3DqueryAsyncJobR= esult&jobId=3D90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=3Djson&sessionk= ey=3DuSpuIkackMpvWLrjIHS842Q1v4o%3D&_=3D1386158175162 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-a4279= 4db ctx-e6c815dc) =3D=3D=3DEND=3D=3D=3D 10.146.0.134 -- GET command=3Dque= ryAsyncJobResult&jobId=3D90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=3Djs= on&sessionkey=3DuSpuIkackMpvWLrjIHS842Q1v4o%3D&_=3D1386158175162 2013-12-04 12:25:03,008 ERROR [c.c.h.h.r.HypervDirectConnectResource] (Dire= ctAgent-15:ctx-3c4633d8) GetDomRVersionCmd failed due to java.net.SocketTim= eoutException: 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(Dir= ectAgentAttache.java:216) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.r= un(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.ja= va:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:33= 4) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFuture= Task.access$101(ScheduledThreadPoolExecutor.java:165) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFuture= Task.run(ScheduledThreadPoolExecutor.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.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 fa= lse 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-3c4633d= 8) Seq 1-1576731025: Processing: { Ans: , MgmtId: 7332683579487, via: 1, V= er: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":8,"name"= :"r-8-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"min= Ram":134217728,"maxRam":134217728,"arch":"i686","os":"Debian GNU/Linux 5.0 = (32-bit)","bootArgs":" template=3DdomP name=3Dr-8-VM eth2ip=3D10.147.48.23 = eth2mask=3D255.255.255.0 gateway=3D10.147.48.1 eth0ip=3D10.1.1.1 eth0mask= =3D255.255.255.0 domain=3Dcs2cloud.internal dhcprange=3D10.1.1.1 eth1ip=3D1= 0.147.40.232 eth1mask=3D255.255.254.0 type=3Drouter disable_rp_filter=3Dtru= e dns1=3D10.140.50.6 dns2=3D","rebootOnCrash":false,"enableHA":true,"limitC= puUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"33c76dca072011= e6","params":{},"uuid":"33b6472e-67cd-4aee-8556-b22d6e57d44b","disks":[{"da= ta":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9c48b406-b4= 24-4b77-ae37-37248b454d0f","volumeType":"ROOT","dataStore":{"org.apache.clo= udstack.storage.to.PrimaryDataStoreTO":{"uuid":"20de3206-3585-3bb0-b536-a96= b665df206-HypervResource","id":2,"poolType":"Filesystem","host":"10.147.40.= 14","path":"C:\\Users\\Public\\Documents\\Hyper-V\\Virtual Hard Disks","por= t":0,"url":"Filesystem://10.147.40.14/C:\\Users\\Public\\Documents\\Hyper-V= \\Virtual Hard Disks/?ROLE=3DPrimary&STOREUUID=3D20de3206-3585-3bb0-b536-a9= 6b665df206-HypervResource"}},"name":"ROOT-8","size":2101252608,"volumeId":8= ,"vmName":"r-8-VM","accountId":2,"id":8,"deviceId":0,"hypervisorType":"Hype= rv"}},"diskSeq":0,"type":"ROOT","_details":{"managed":"false","storagePort"= :"0","storageHost":"10.147.40.14","volumeSize":"2101252608"}}],"nics":[{"de= viceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"645d73f8-ea2b-432= 9-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":"","b= roadcastType":"Vlan","type":"Public","broadcastUri":"vlan://48","isolationU= ri":"vlan://48","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateM= bps":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","gat= eway":"10.147.40.1","mac":"02:00:60:3e:00:01","broadcastType":"Native","typ= e":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"c= om.cloud.agent.api.check.CheckSshAnswer":{"result":true,"wait":0}},{"com.cl= oud.agent.api.GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersi= onCmd 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-4fc0c5a= f ctx-2d3a7128) Seq 1-1576731025: Received: { Ans: , MgmtId: 7332683579487= , via: 1, Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer, GetDomRVersion= Answer } } 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/scrip= ts version of router r-8-VM due to: GetDomRVersionCmd failed due to java.ne= t.SocketTimeoutException: The kexTimeout (60000 ms) expired. 2013-12-04 12:25:03,064 INFO [c.c.v.VirtualMachineManagerImpl] (Job-Execut= or-2:ctx-4fc0c5af ctx-2d3a7128) The guru did not like the answers so stoppi= ng VM[DomainRouter|r-8-VM] 2013-12-04 12:25:03,070 DEBUG [c.c.a.t.Request] (Job-Executor-2:ctx-4fc0c5a= f ctx-2d3a7128) Seq 1-1576731041: Sending { Cmd , MgmtId: 7332683579487, v= ia: 1(10.147.40.14), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCom= mand":{"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-4fc0c5a= f ctx-2d3a7128) Seq 1-1576731041: Executing: { Cmd , MgmtId: 7332683579487= , via: 1(10.147.40.14), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.Stop= Command":{"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] (Dire= ctAgent-229:ctx-3ff22557) POST request tohttp://10.147.40.14:8250/api/Hyper= vResource/com.cloud.agent.api.StopCommand with contents{"isProxy":false,"ex= ecuteInSequence":false,"vmName":"r-8-VM","contextMap":{},"wait":0} 2013-12-04 12:25:03,071 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (Dire= ctAgent-229:ctx-3ff22557) Sending cmd to http://10.147.40.14:8250/api/Hyper= vResource/com.cloud.agent.api.StopCommand cmd data:{"isProxy":false,"execut= eInSequence":false,"vmName":"r-8-VM","contextMap":{},"wait":0} 2013-12-04 12:25:03,683 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-a5bd= a5fe) =3D=3D=3DSTART=3D=3D=3D 10.146.0.134 -- GET command=3DqueryAsyncJob= Result&jobId=3D90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=3Djson&session= key=3DuSpuIkackMpvWLrjIHS842Q1v4o%3D&_=3D1386158235163 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-a5bd= a5fe ctx-c422cb8d) =3D=3D=3DEND=3D=3D=3D 10.146.0.134 -- GET command=3Dqu= eryAsyncJobResult&jobId=3D90dbfeed-f357-47b9-9067-9c4ad34a1d33&response=3Dj= son&sessionkey=3DuSpuIkackMpvWLrjIHS842Q1v4o%3D&_=3D1386158235163 2013-12-04 12:25:05,243 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (Dire= ctAgent-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] (Dire= ctAgent-229:ctx-3ff22557) executeRequest received response [{"com.cloud.age= nt.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-3ff225= 57) 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-4fc0c5a= f 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-Execut= or-2:ctx-4fc0c5af ctx-2d3a7128) Failed to start instance VM[DomainRouter|r-= 8-VM] -- This message was sent by Atlassian JIRA (v6.1#6144)